From 455782b964df5ea96101085d55298f52fe425bc7 Mon Sep 17 00:00:00 2001 From: Zahari Dichev Date: Wed, 26 Jun 2019 01:12:52 +0300 Subject: [PATCH] trace: Allow setting event parents explicitly (#1109) ## Motivation As mentioned in tokio-rs/tracing#1100 it makes sense to be able to set the parents of events explicitly. ## Solution For that to happen the Parent type is extracted from span.rs and a `parent` field is added to Event. Additionally the appropriate macros arms are added with corresponding tests as described in tokio-rs/tracing#1100 Closes tokio-rs/tracing#1100 Signed-off-by: Zahari Dichev --- tokio-trace/Cargo.toml | 2 +- tokio-trace/src/macros.rs | 521 ++++++++++++++++++++- tokio-trace/tests/macros.rs | 274 +++++++++++ tokio-trace/tokio-trace-core/src/event.rs | 65 ++- tokio-trace/tokio-trace-core/src/lib.rs | 1 + tokio-trace/tokio-trace-core/src/parent.rs | 11 + tokio-trace/tokio-trace-core/src/span.rs | 11 +- 7 files changed, 871 insertions(+), 14 deletions(-) create mode 100644 tokio-trace/tokio-trace-core/src/parent.rs diff --git a/tokio-trace/Cargo.toml b/tokio-trace/Cargo.toml index 6b5612fdf..de7175477 100644 --- a/tokio-trace/Cargo.toml +++ b/tokio-trace/Cargo.toml @@ -22,7 +22,7 @@ categories = ["development-tools::debugging", "asynchronous"] keywords = ["logging", "tracing"] [dependencies] -tokio-trace-core = { version = "0.2", path = "tokio-trace-core" } +tokio-trace-core = { path = "./tokio-trace-core" } log = { version = "0.4", optional = true } cfg-if = "0.1.7" diff --git a/tokio-trace/src/macros.rs b/tokio-trace/src/macros.rs index 449142801..81af1dafc 100644 --- a/tokio-trace/src/macros.rs +++ b/tokio-trace/src/macros.rs @@ -845,6 +845,37 @@ macro_rules! error_span { /// ``` #[macro_export(local_inner_macros)] macro_rules! event { + (target: $target:expr, $lvl:expr, parent: $parent:expr, { $($fields:tt)* } )=> ({ + { + __tokio_trace_log!( + target: $target, + $lvl, + $($fields)* + ); + + if $lvl <= $crate::level_filters::STATIC_MAX_LEVEL { + #[allow(unused_imports)] + use $crate::{callsite, dispatcher, Event, field::{Value, ValueSet}}; + use $crate::callsite::Callsite; + let callsite = callsite! { + name: __tokio_trace_concat!( + "event ", + __tokio_trace_file!(), + ":", + __tokio_trace_line!() + ), + kind: $crate::metadata::Kind::EVENT, + target: $target, + level: $lvl, + fields: $($fields)* + }; + if is_enabled!(callsite) { + let meta = callsite.metadata(); + Event::dispatch(meta, &valueset!(meta.fields(), $($fields)*) ); + } + } + } + }); (target: $target:expr, $lvl:expr, { $($fields:tt)* } )=> ({ { __tokio_trace_log!( @@ -876,6 +907,14 @@ macro_rules! event { } } }); + (target: $target:expr, $lvl:expr, parent: $parent:expr, { $($fields:tt)* }, $($arg:tt)+ ) => ({ + event!( + target: $target, + $lvl, + parent: $parent, + { message = __tokio_trace_format_args!($($arg)+), $($fields)* } + ) + }); (target: $target:expr, $lvl:expr, { $($fields:tt)* }, $($arg:tt)+ ) => ({ event!( target: $target, @@ -883,16 +922,23 @@ macro_rules! event { { message = __tokio_trace_format_args!($($arg)+), $($fields)* } ) }); + (target: $target:expr, $lvl:expr, parent: $parent:expr, $($k:ident).+ = $($fields:tt)* ) => ( + event!(target: $target, $lvl, parent: $parent, { $($k).+ = $($fields)* }) + ); (target: $target:expr, $lvl:expr, $($k:ident).+ = $($fields:tt)* ) => ( event!(target: $target, $lvl, { $($k).+ = $($fields)* }) ); + (target: $target:expr, $lvl:expr, parent: $parent:expr, $($arg:tt)+ ) => ( + event!(target: $target, $lvl, parent: $parent, { }, $($arg)+) + ); (target: $target:expr, $lvl:expr, $($arg:tt)+ ) => ( event!(target: $target, $lvl, { }, $($arg)+) ); - ( $lvl:expr, { $($fields:tt)* }, $($arg:tt)+ ) => ( + ( $lvl:expr, parent: $parent:expr, { $($fields:tt)* }, $($arg:tt)+ ) => ( event!( target: __tokio_trace_module_path!(), $lvl, + parent: $parent, { message = __tokio_trace_format_args!($($arg)+), $($fields)* } ) ); @@ -903,6 +949,29 @@ macro_rules! event { { message = __tokio_trace_format_args!($($arg)+), $($fields)* } ) ); + ( $lvl:expr, parent: $parent:expr, { $($fields:tt)* }, $($arg:tt)+ ) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + parent: $parent, + { message = __tokio_trace_format_args!($($arg)+), $($fields)* } + ) + ); + ( $lvl:expr, { $($fields:tt)* }, $($arg:tt)+ ) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + { message = __tokio_trace_format_args!($($arg)+), $($fields)* } + ) + ); + ( $lvl:expr, parent: $parent:expr, $($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + parent: $parent, + { $($k).+ = $($field)*} + ) + ); ($lvl:expr, $($k:ident).+ = $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), @@ -910,6 +979,14 @@ macro_rules! event { { $($k).+ = $($field)*} ) ); + ($lvl:expr, parent: $parent:expr, ?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + parent: $parent, + { ?$($k).+ = $($field)*} + ) + ); ($lvl:expr, ?$($k:ident).+ = $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), @@ -917,6 +994,14 @@ macro_rules! event { { ?$($k).+ = $($field)*} ) ); + ($lvl:expr, parent: $parent:expr, %$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + parent: $parent, + { %$($k).+ = $($field)*} + ) + ); ($lvl:expr, %$($k:ident).+ = $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), @@ -924,6 +1009,14 @@ macro_rules! event { { %$($k).+ = $($field)*} ) ); + ($lvl:expr, parent: $parent:expr, $($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + parent: $parent, + { $($k).+, $($field)*} + ) + ); ($lvl:expr, $($k:ident).+, $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), @@ -931,6 +1024,14 @@ macro_rules! event { { $($k).+, $($field)*} ) ); + ($lvl:expr, parent: $parent:expr, ?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + parent: $parent, + { ?$($k).+, $($field)*} + ) + ); ($lvl:expr, ?$($k:ident).+, $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), @@ -938,6 +1039,14 @@ macro_rules! event { { ?$($k).+, $($field)*} ) ); + ($lvl:expr, parent: $parent:expr, %$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + parent: $parent, + { %$($k).+, $($field)*} + ) + ); ($lvl:expr, %$($k:ident).+, $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), @@ -945,6 +1054,9 @@ macro_rules! event { { %$($k).+, $($field)*} ) ); + ( $lvl:expr, parent: $parent:expr, $($arg:tt)+ ) => ( + event!(target: __tokio_trace_module_path!(), $lvl, parent: $parent, { }, $($arg)+) + ); ( $lvl:expr, $($arg:tt)+ ) => ( event!(target: __tokio_trace_module_path!(), $lvl, { }, $($arg)+) ); @@ -986,6 +1098,87 @@ macro_rules! event { /// ``` #[macro_export(local_inner_macros)] macro_rules! trace { + (target: $target:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => ( + event!(target: $target, $crate::Level::TRACE, parent: $parent, { $($field)* }, $($arg)*) + ); + (target: $target:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::TRACE, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::TRACE, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::TRACE, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, $($arg:tt)+ ) => ( + event!(target: $target, $crate::Level::TRACE, parent: $parent, {}, $($arg)+) + ); + (parent: $parent:expr, { $($field:tt)+ }, $($arg:tt)+ ) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + parent: $parent, + { $($field)+ }, + $($arg)+ + ) + ); + (parent: $parent:expr, $($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + parent: $parent, + { $($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + parent: $parent, + { ?$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + parent: $parent, + { %$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, $($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + parent: $parent, + { $($k).+, $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + parent: $parent, + { ?$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + parent: $parent, + { %$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, $($arg:tt)+) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + parent: $parent, + {}, + $($arg)+ + ) + ); (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( event!(target: $target, $crate::Level::TRACE, { $($field)* }, $($arg)*) ); @@ -1084,6 +1277,87 @@ macro_rules! trace { /// ``` #[macro_export(local_inner_macros)] macro_rules! debug { + (target: $target:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, { $($field)* }, $($arg)*) + ); + (target: $target:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, $($arg:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, {}, $($arg)+) + ); + (parent: $parent:expr, { $($field:tt)+ }, $($arg:tt)+ ) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { $($field)+ }, + $($arg)+ + ) + ); + (parent: $parent:expr, $($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { $($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { ?$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { %$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, $($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { $($k).+, $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { ?$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { %$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, $($arg:tt)+) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + {}, + $($arg)+ + ) + ); (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( event!(target: $target, $crate::Level::DEBUG, { $($field)* }, $($arg)*) ); @@ -1189,6 +1463,87 @@ macro_rules! debug { /// ``` #[macro_export(local_inner_macros)] macro_rules! info { + (target: $target:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, { $($field)* }, $($arg)*) + ); + (target: $target:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, $($arg:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, parent: $parent, {}, $($arg)+) + ); + (parent: $parent:expr, { $($field:tt)+ }, $($arg:tt)+ ) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { $($field)+ }, + $($arg)+ + ) + ); + (parent: $parent:expr, $($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { $($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { ?$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { %$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, $($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { $($k).+, $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { ?$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + { %$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, $($arg:tt)+) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + parent: $parent, + {}, + $($arg)+ + ) + ); (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( event!(target: $target, $crate::Level::INFO, { $($field)* }, $($arg)*) ); @@ -1291,7 +1646,88 @@ macro_rules! info { /// ``` #[macro_export(local_inner_macros)] macro_rules! warn { - (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( + (target: $target:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => ( + event!(target: $target, $crate::Level::WARN, parent: $parent, { $($field)* }, $($arg)*) + ); + (target: $target:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::WARN, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::WARN, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::WARN, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, $($arg:tt)+ ) => ( + event!(target: $target, $crate::Level::WARN, parent: $parent, {}, $($arg)+) + ); + (parent: $parent:expr, { $($field:tt)+ }, $($arg:tt)+ ) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + parent: $parent, + { $($field)+ }, + $($arg)+ + ) + ); + (parent: $parent:expr, $($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + parent: $parent, + { $($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + parent: $parent, + { ?$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + parent: $parent, + { %$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, $($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + parent: $parent, + { $($k).+, $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + parent: $parent, + { ?$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + parent: $parent, + { %$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, $($arg:tt)+) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + parent: $parent, + {}, + $($arg)+ + ) + ); + (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( event!(target: $target, $crate::Level::WARN, { $($field)* }, $($arg)*) ); (target: $target:expr, $($k:ident).+ $($field:tt)+ ) => ( @@ -1388,6 +1824,87 @@ macro_rules! warn { /// ``` #[macro_export(local_inner_macros)] macro_rules! error { + (target: $target:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => ( + event!(target: $target, $crate::Level::ERROR, parent: $parent, { $($field)* }, $($arg)*) + ); + (target: $target:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::ERROR, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::ERROR, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::ERROR, parent: $parent, { $($k).+ $($field)+ }) + ); + (target: $target:expr, parent: $parent:expr, $($arg:tt)+ ) => ( + event!(target: $target, $crate::Level::ERROR, parent: $parent, {}, $($arg)+) + ); + (parent: $parent:expr, { $($field:tt)+ }, $($arg:tt)+ ) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + parent: $parent, + { $($field)+ }, + $($arg)+ + ) + ); + (parent: $parent:expr, $($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + parent: $parent, + { $($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + parent: $parent, + { ?$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + parent: $parent, + { %$($k).+ = $($field)*} + ) + ); + (parent: $parent:expr, $($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + parent: $parent, + { $($k).+, $($field)*} + ) + ); + (parent: $parent:expr, ?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + parent: $parent, + { ?$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, %$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + parent: $parent, + { %$($k).+, $($field)*} + ) + ); + (parent: $parent:expr, $($arg:tt)+) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + parent: $parent, + {}, + $($arg)+ + ) + ); (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( event!(target: $target, $crate::Level::ERROR, { $($field)* }, $($arg)*) ); diff --git a/tokio-trace/tests/macros.rs b/tokio-trace/tests/macros.rs index 886319800..bbbebb51b 100644 --- a/tokio-trace/tests/macros.rs +++ b/tokio-trace/tests/macros.rs @@ -394,6 +394,280 @@ fn error() { error!(target: "foo_events", { foo = 2, bar.baz = 78, }, "quux"); } +#[test] +fn event_root() { + event!(Level::DEBUG, parent: None, foo = ?3, bar.baz = %2, quux = false); + event!( + Level::DEBUG, + parent: None, + foo = 3, + bar.baz = 2, + quux = false + ); + event!(Level::DEBUG, parent: None, foo = 3, bar.baz = 3,); + event!(Level::DEBUG, parent: None, "foo"); + event!(Level::DEBUG, parent: None, "foo: {}", 3); + event!(Level::DEBUG, parent: None, { foo = 3, bar.baz = 80 }, "quux"); + event!(Level::DEBUG, parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(Level::DEBUG, parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(Level::DEBUG, parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + event!(target: "foo_events", Level::DEBUG, parent: None, foo = 3, bar.baz = 2, quux = false); + event!(target: "foo_events", Level::DEBUG, parent: None, foo = 3, bar.baz = 3,); + event!(target: "foo_events", Level::DEBUG, parent: None, "foo"); + event!(target: "foo_events", Level::DEBUG, parent: None, "foo: {}", 3); + event!(target: "foo_events", Level::DEBUG, parent: None, { foo = 3, bar.baz = 80 }, "quux"); + event!(target: "foo_events", Level::DEBUG, parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(target: "foo_events", Level::DEBUG, parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(target: "foo_events", Level::DEBUG, parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn trace_root() { + trace!(parent: None, foo = ?3, bar.baz = %2, quux = false); + trace!(parent: None, foo = 3, bar.baz = 2, quux = false); + trace!(parent: None, foo = 3, bar.baz = 3,); + trace!(parent: None, "foo"); + trace!(parent: None, "foo: {}", 3); + trace!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + trace!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + trace!(parent:None, { foo = ?2, bar.baz = %78 }, "quux"); + trace!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + trace!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + trace!(target: "foo_events", parent: None, "foo"); + trace!(target: "foo_events", parent: None, "foo: {}", 3); + trace!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + trace!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn debug_root() { + debug!(parent: None, foo = ?3, bar.baz = %2, quux = false); + debug!(parent: None, foo = 3, bar.baz = 2, quux = false); + debug!(parent: None, foo = 3, bar.baz = 3,); + debug!(parent: None, "foo"); + debug!(parent: None, "foo: {}", 3); + debug!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + debug!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + debug!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + debug!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + debug!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + debug!(target: "foo_events", parent: None, "foo"); + debug!(target: "foo_events", parent: None, "foo: {}", 3); + debug!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + debug!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn info_root() { + info!(parent: None, foo = ?3, bar.baz = %2, quux = false); + info!(parent: None, foo = 3, bar.baz = 2, quux = false); + info!(parent: None, foo = 3, bar.baz = 3,); + info!(parent: None, "foo"); + info!(parent: None, "foo: {}", 3); + info!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + info!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + info!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + info!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + info!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + info!(target: "foo_events", parent: None, "foo"); + info!(target: "foo_events", parent: None, "foo: {}", 3); + info!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + info!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn warn_root() { + warn!(parent: None, foo = ?3, bar.baz = %2, quux = false); + warn!(parent: None, foo = 3, bar.baz = 2, quux = false); + warn!(parent: None, foo = 3, bar.baz = 3,); + warn!(parent: None, "foo"); + warn!(parent: None, "foo: {}", 3); + warn!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + warn!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + warn!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + warn!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + warn!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + warn!(target: "foo_events", parent: None, "foo"); + warn!(target: "foo_events", parent: None, "foo: {}", 3); + warn!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + warn!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn error_root() { + error!(parent: None, foo = ?3, bar.baz = %2, quux = false); + error!(parent: None, foo = 3, bar.baz = 2, quux = false); + error!(parent: None, foo = 3, bar.baz = 3,); + error!(parent: None, "foo"); + error!(parent: None, "foo: {}", 3); + error!(parent: None, { foo = 3, bar.baz = 80 }, "quux"); + error!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(parent: None, { foo = 2, bar.baz = 78 }, "quux"); + error!(parent: None, { foo = ?2, bar.baz = %78 }, "quux"); + error!(target: "foo_events", parent: None, foo = 3, bar.baz = 2, quux = false); + error!(target: "foo_events", parent: None, foo = 3, bar.baz = 3,); + error!(target: "foo_events", parent: None, "foo"); + error!(target: "foo_events", parent: None, "foo: {}", 3); + error!(target: "foo_events", parent: None, { foo = 3, bar.baz = 80 }, "quux"); + error!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(target: "foo_events", parent: None, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(target: "foo_events", parent: None, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn event_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + event!(Level::DEBUG, parent: &p, foo = ?3, bar.baz = %2, quux = false); + event!(Level::DEBUG, parent: &p, foo = 3, bar.baz = 2, quux = false); + event!(Level::DEBUG, parent: &p, foo = 3, bar.baz = 3,); + event!(Level::DEBUG, parent: &p, "foo"); + event!(Level::DEBUG, parent: &p, "foo: {}", 3); + event!(Level::DEBUG, parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + event!(Level::DEBUG, parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(Level::DEBUG, parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(Level::DEBUG, parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + event!(target: "foo_events", Level::DEBUG, parent: &p, foo = 3, bar.baz = 2, quux = false); + event!(target: "foo_events", Level::DEBUG, parent: &p, foo = 3, bar.baz = 3,); + event!(target: "foo_events", Level::DEBUG, parent: &p, "foo"); + event!(target: "foo_events", Level::DEBUG, parent: &p, "foo: {}", 3); + event!(target: "foo_events", Level::DEBUG, parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + event!(target: "foo_events", Level::DEBUG, parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + event!(target: "foo_events", Level::DEBUG, parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + event!(target: "foo_events", Level::DEBUG, parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn trace_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + trace!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + trace!(parent: &p, foo = 3, bar.baz = 2, quux = false); + trace!(parent: &p, foo = 3, bar.baz = 3,); + trace!(parent: &p, "foo"); + trace!(parent: &p, "foo: {}", 3); + trace!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + trace!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + trace!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + trace!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + trace!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + trace!(target: "foo_events", parent: &p, "foo"); + trace!(target: "foo_events", parent: &p, "foo: {}", 3); + trace!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + trace!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + trace!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + trace!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn debug_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + debug!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + debug!(parent: &p, foo = 3, bar.baz = 2, quux = false); + debug!(parent: &p, foo = 3, bar.baz = 3,); + debug!(parent: &p, "foo"); + debug!(parent: &p, "foo: {}", 3); + debug!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + debug!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + debug!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + debug!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + debug!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + debug!(target: "foo_events", parent: &p, "foo"); + debug!(target: "foo_events", parent: &p, "foo: {}", 3); + debug!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + debug!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + debug!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + debug!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn info_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + info!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + info!(parent: &p, foo = 3, bar.baz = 2, quux = false); + info!(parent: &p, foo = 3, bar.baz = 3,); + info!(parent: &p, "foo"); + info!(parent: &p, "foo: {}", 3); + info!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + info!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + info!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + info!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + info!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + info!(target: "foo_events", parent: &p, "foo"); + info!(target: "foo_events", parent: &p, "foo: {}", 3); + info!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + info!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + info!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + info!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn warn_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + warn!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + warn!(parent: &p, foo = 3, bar.baz = 2, quux = false); + warn!(parent: &p, foo = 3, bar.baz = 3,); + warn!(parent: &p, "foo"); + warn!(parent: &p, "foo: {}", 3); + warn!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + warn!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + warn!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + warn!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + warn!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + warn!(target: "foo_events", parent: &p, "foo"); + warn!(target: "foo_events", parent: &p, "foo: {}", 3); + warn!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + warn!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + warn!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + warn!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + +#[test] +fn error_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + error!(parent: &p, foo = ?3, bar.baz = %2, quux = false); + error!(parent: &p, foo = 3, bar.baz = 2, quux = false); + error!(parent: &p, foo = 3, bar.baz = 3,); + error!(parent: &p, "foo"); + error!(parent: &p, "foo: {}", 3); + error!(parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + error!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(parent: &p, { foo = 2, bar.baz = 78 }, "quux"); + error!(parent: &p, { foo = ?2, bar.baz = %78 }, "quux"); + error!(target: "foo_events", parent: &p, foo = 3, bar.baz = 2, quux = false); + error!(target: "foo_events", parent: &p, foo = 3, bar.baz = 3,); + error!(target: "foo_events", parent: &p, "foo"); + error!(target: "foo_events", parent: &p, "foo: {}", 3); + error!(target: "foo_events", parent: &p, { foo = 3, bar.baz = 80 }, "quux"); + error!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}", true); + error!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); + error!(target: "foo_events", parent: &p, { foo = 2, bar.baz = 78, }, "quux"); +} + #[test] fn field_shorthand_only() { #[derive(Debug)] diff --git a/tokio-trace/tokio-trace-core/src/event.rs b/tokio-trace/tokio-trace-core/src/event.rs index 34c78c860..3e2ff29aa 100644 --- a/tokio-trace/tokio-trace-core/src/event.rs +++ b/tokio-trace/tokio-trace-core/src/event.rs @@ -1,4 +1,6 @@ //! Events represent single points in time during the execution of a program. +use parent::Parent; +use span::Id; use {field, Metadata}; /// `Event`s represent single points in time where something occurred during the @@ -21,6 +23,7 @@ use {field, Metadata}; pub struct Event<'a> { fields: &'a field::ValueSet<'a>, metadata: &'a Metadata<'a>, + parent: Parent, } impl<'a> Event<'a> { @@ -28,7 +31,34 @@ impl<'a> Event<'a> { /// and observes it with the current subscriber. #[inline] pub fn dispatch(metadata: &'a Metadata<'a>, fields: &'a field::ValueSet) { - let event = Event { metadata, fields }; + let event = Event { + metadata, + fields, + parent: Parent::Current, + }; + ::dispatcher::get_default(|current| { + current.event(&event); + }); + } + + /// Constructs a new `Event` with the specified metadata and set of values, + /// and observes it with the current subscriber and an explicit parent. + #[inline] + pub fn child_of( + parent: impl Into>, + metadata: &'a Metadata<'a>, + fields: &'a field::ValueSet, + ) { + let parent = match parent.into() { + Some(p) => Parent::Explicit(p), + None => Parent::Root, + }; + + let event = Event { + metadata, + fields, + parent, + }; ::dispatcher::get_default(|current| { current.event(&event); }); @@ -53,4 +83,37 @@ impl<'a> Event<'a> { pub fn metadata(&self) -> &Metadata { self.metadata } + + /// Returns true if the new event shoold be a root. + pub fn is_root(&self) -> bool { + match self.parent { + Parent::Root => true, + _ => false, + } + } + + /// Returns true if the new event's parent should be determined based on the + /// current context. + /// + /// If this is true and the current thread is currently inside a span, then + /// that span should be the new events's parent. Otherwise, if the current + /// thread is _not_ inside a span, then the new event will be the root of its + /// own trace tree. + pub fn is_contextual(&self) -> bool { + match self.parent { + Parent::Current => true, + _ => false, + } + } + + /// Returns the new event's explicitly-specified parent, if there is one. + /// + /// Otherwise (if the new event is a root or is a child of the current span), + /// returns false. + pub fn parent(&self) -> Option<&Id> { + match self.parent { + Parent::Explicit(ref p) => Some(p), + _ => None, + } + } } diff --git a/tokio-trace/tokio-trace-core/src/lib.rs b/tokio-trace/tokio-trace-core/src/lib.rs index e6bc3d50f..b72670c32 100644 --- a/tokio-trace/tokio-trace-core/src/lib.rs +++ b/tokio-trace/tokio-trace-core/src/lib.rs @@ -195,6 +195,7 @@ pub mod dispatcher; pub mod event; pub mod field; pub mod metadata; +mod parent; pub mod span; pub mod subscriber; diff --git a/tokio-trace/tokio-trace-core/src/parent.rs b/tokio-trace/tokio-trace-core/src/parent.rs new file mode 100644 index 000000000..91715ad93 --- /dev/null +++ b/tokio-trace/tokio-trace-core/src/parent.rs @@ -0,0 +1,11 @@ +use span::Id; + +#[derive(Debug)] +pub(crate) enum Parent { + /// The new span will be a root span. + Root, + /// The new span will be rooted in the current span. + Current, + /// The new span has an explicitly-specified parent. + Explicit(Id), +} diff --git a/tokio-trace/tokio-trace-core/src/span.rs b/tokio-trace/tokio-trace-core/src/span.rs index 7858e2c0b..64d32c9d2 100644 --- a/tokio-trace/tokio-trace-core/src/span.rs +++ b/tokio-trace/tokio-trace-core/src/span.rs @@ -1,5 +1,6 @@ //! Spans represent periods of time in the execution of a program. +use parent::Parent; use {field, Metadata}; /// Identifies a span within the context of a subscriber. @@ -30,16 +31,6 @@ pub struct Record<'a> { values: &'a field::ValueSet<'a>, } -#[derive(Debug)] -enum Parent { - /// The new span will be a root span. - Root, - /// The new span will be rooted in the current span. - Current, - /// The new span has an explicitly-specified parent. - Explicit(Id), -} - // ===== impl Span ===== impl Id {