From 597f271c08fab0720babf04f9de88105e8bd16c6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jo=C3=A3o=20Oliveira?= Date: Tue, 2 Apr 2019 19:29:23 +0100 Subject: [PATCH] trace: Remove default trace level and make levels mandatory on span! macro (#1025) ## Motivation Was determined that having the span! macro default to the TRACE level is probably not ideal (see discussion on #952). Closes #1013 ## Solution Remove default trace level and make log lvl mandatory on span! macro, and add the respective `trace_span!`, `debug_span!`, `info_span!`, `warn_span!` and `error_span!` macros that behave as span! macro, but with defined log levels ## Notes I think this is it, also removed some captures that were repeated, and some testcases that also seemed repeated after adding the mandatory log level, but please review it, if more tests or examples are needed happy to provide (tried to find a way to get the generated macros log level, but didn't find one, if there is a way i can add tests to assert that the generated macro has the matching log level ). thanks --- tokio-trace/benches/no_subscriber.rs | 4 +- tokio-trace/benches/subscriber.rs | 11 +- tokio-trace/examples/counters.rs | 12 +- tokio-trace/examples/sloggish/main.rs | 10 +- tokio-trace/src/lib.rs | 15 +- tokio-trace/src/macros.rs | 571 +++++++++++++++--- tokio-trace/src/span.rs | 9 +- .../test-log-support/tests/log_no_trace.rs | 7 +- .../tests/test.rs | 10 +- tokio-trace/tests/event.rs | 4 +- tokio-trace/tests/macros.rs | 319 +++++++--- tokio-trace/tests/span.rs | 70 ++- tokio-trace/tests/subscriber.rs | 17 +- 13 files changed, 815 insertions(+), 244 deletions(-) diff --git a/tokio-trace/benches/no_subscriber.rs b/tokio-trace/benches/no_subscriber.rs index 84a5bc428..c086c412f 100644 --- a/tokio-trace/benches/no_subscriber.rs +++ b/tokio-trace/benches/no_subscriber.rs @@ -5,11 +5,12 @@ extern crate tokio_trace; extern crate log; extern crate test; use test::Bencher; +use tokio_trace::Level; #[bench] fn bench_span_no_subscriber(b: &mut Bencher) { b.iter(|| { - span!("span"); + span!(Level::TRACE, "span"); }); } @@ -24,6 +25,7 @@ fn bench_log_no_logger(b: &mut Bencher) { fn bench_costly_field_no_subscriber(b: &mut Bencher) { b.iter(|| { span!( + Level::TRACE, "span", foo = tokio_trace::field::display(format!("bar {:?}", 2)) ); diff --git a/tokio-trace/benches/subscriber.rs b/tokio-trace/benches/subscriber.rs index e4a14a741..745fb6ae6 100644 --- a/tokio-trace/benches/subscriber.rs +++ b/tokio-trace/benches/subscriber.rs @@ -4,6 +4,7 @@ extern crate tokio_trace; extern crate test; use test::Bencher; +use tokio_trace::Level; use std::{ fmt, @@ -97,13 +98,15 @@ const N_SPANS: usize = 100; #[bench] fn span_no_fields(b: &mut Bencher) { - tokio_trace::subscriber::with_default(EnabledSubscriber, || b.iter(|| span!("span"))); + tokio_trace::subscriber::with_default(EnabledSubscriber, || { + b.iter(|| span!(Level::TRACE, "span")) + }); } #[bench] fn enter_span(b: &mut Bencher) { tokio_trace::subscriber::with_default(EnabledSubscriber, || { - b.iter(|| test::black_box(span!("span").enter(|| {}))) + b.iter(|| test::black_box(span!(Level::TRACE, "span").enter(|| {}))) }); } @@ -111,7 +114,7 @@ fn enter_span(b: &mut Bencher) { fn span_repeatedly(b: &mut Bencher) { #[inline] fn mk_span(i: u64) -> tokio_trace::Span { - span!("span", i = i) + span!(Level::TRACE, "span", i = i) } let n = test::black_box(N_SPANS); @@ -125,6 +128,7 @@ fn span_with_fields(b: &mut Bencher) { tokio_trace::subscriber::with_default(EnabledSubscriber, || { b.iter(|| { span!( + Level::TRACE, "span", foo = "foo", bar = "bar", @@ -141,6 +145,7 @@ fn span_with_fields_record(b: &mut Bencher) { tokio_trace::subscriber::with_default(subscriber, || { b.iter(|| { span!( + Level::TRACE, "span", foo = "foo", bar = "bar", diff --git a/tokio-trace/examples/counters.rs b/tokio-trace/examples/counters.rs index 3d120405f..45717184d 100644 --- a/tokio-trace/examples/counters.rs +++ b/tokio-trace/examples/counters.rs @@ -5,7 +5,7 @@ use tokio_trace::{ field::{Field, Visit}, span, subscriber::{self, Subscriber}, - Event, Id, Metadata, + Event, Id, Level, Metadata, }; use std::{ @@ -125,10 +125,16 @@ fn main() { tokio_trace::subscriber::with_default(subscriber, || { let mut foo: u64 = 2; - span!("my_great_span", foo_count = &foo).enter(|| { + span!(Level::TRACE, "my_great_span", foo_count = &foo).enter(|| { foo += 1; info!({ yak_shaved = true, yak_count = 1 }, "hi from inside my span"); - span!("my other span", foo_count = &foo, baz_count = 5).enter(|| { + span!( + Level::TRACE, + "my other span", + foo_count = &foo, + baz_count = 5 + ) + .enter(|| { warn!({ yak_shaved = false, yak_count = -1 }, "failed to shave yak"); }); }); diff --git a/tokio-trace/examples/sloggish/main.rs b/tokio-trace/examples/sloggish/main.rs index 443fb341d..fcf48363e 100644 --- a/tokio-trace/examples/sloggish/main.rs +++ b/tokio-trace/examples/sloggish/main.rs @@ -13,7 +13,7 @@ #[macro_use] extern crate tokio_trace; -use tokio_trace::field; +use tokio_trace::{field, Level}; mod sloggish_subscriber; use self::sloggish_subscriber::SloggishSubscriber; @@ -22,16 +22,16 @@ fn main() { let subscriber = SloggishSubscriber::new(2); tokio_trace::subscriber::with_default(subscriber, || { - span!("", version = &field::display(5.0)).enter(|| { - span!("server", host = "localhost", port = 8080).enter(|| { + span!(Level::TRACE, "", version = &field::display(5.0)).enter(|| { + span!(Level::TRACE, "server", host = "localhost", port = 8080).enter(|| { info!("starting"); info!("listening"); - let mut peer1 = span!("conn", peer_addr = "82.9.9.9", port = 42381); + let mut peer1 = span!(Level::TRACE, "conn", peer_addr = "82.9.9.9", port = 42381); peer1.enter(|| { debug!("connected"); debug!({ length = 2 }, "message received"); }); - let mut peer2 = span!("conn", peer_addr = "8.8.8.8", port = 18230); + let mut peer2 = span!(Level::TRACE, "conn", peer_addr = "8.8.8.8", port = 18230); peer2.enter(|| { debug!("connected"); }); diff --git a/tokio-trace/src/lib.rs b/tokio-trace/src/lib.rs index da544c571..324dc8b17 100644 --- a/tokio-trace/src/lib.rs +++ b/tokio-trace/src/lib.rs @@ -56,9 +56,10 @@ //! construct one span and perform the entire loop inside of that span, like: //! ```rust //! # #[macro_use] extern crate tokio_trace; +//! # use tokio_trace::Level; //! # fn main() { //! # let n = 1; -//! span!("my loop").enter(|| { +//! span!(Level::TRACE, "my loop").enter(|| { //! for i in 0..n { //! # let _ = i; //! // ... @@ -69,11 +70,12 @@ //! Or, should we create a new span for each iteration of the loop, as in: //! ```rust //! # #[macro_use] extern crate tokio_trace; +//! # use tokio_trace::Level; //! # fn main() { //! # let n = 1u64; //! for i in 0..n { //! # let _ = i; -//! span!("my loop", iteration = i).enter(|| { +//! span!(Level::TRACE, "my loop", iteration = i).enter(|| { //! // ... //! }) //! } @@ -154,9 +156,10 @@ //! ```rust //! # #[macro_use] //! # extern crate tokio_trace; +//! # use tokio_trace::Level; //! # fn main() { -//! // Construct a new span named "my span". -//! let mut span = span!("my span"); +//! // Construct a new span named "my span" with trace log level. +//! let mut span = span!(Level::TRACE, "my span"); //! span.enter(|| { //! // Any trace events in this closure or code called by it will occur within //! // the span. @@ -188,7 +191,7 @@ //! ```rust //! #[macro_use] //! extern crate tokio_trace; -//! use tokio_trace::field; +//! use tokio_trace::{field, Level}; //! # #[derive(Debug)] pub struct Yak(String); //! # impl Yak { fn shave(&mut self, _: u32) {} } //! # fn find_a_razor() -> Result { Ok(1) } @@ -196,7 +199,7 @@ //! pub fn shave_the_yak(yak: &mut Yak) { //! // Create a new span for this invocation of `shave_the_yak`, annotated //! // with the yak being shaved as a *field* on the span. -//! span!("shave_the_yak", yak = field::debug(&yak)).enter(|| { +//! span!(Level::TRACE, "shave_the_yak", yak = field::debug(&yak)).enter(|| { //! // Since the span is annotated with the yak, it is part of the context //! // for everything happening inside the span. Therefore, we don't need //! // to add it to the message for this event, as the `log` crate does. diff --git a/tokio-trace/src/macros.rs b/tokio-trace/src/macros.rs index 4dcd677fb..417432638 100644 --- a/tokio-trace/src/macros.rs +++ b/tokio-trace/src/macros.rs @@ -6,8 +6,9 @@ /// ``` /// # #[macro_use] /// # extern crate tokio_trace; +/// # use tokio_trace::Level; /// # fn main() { -/// let mut span = span!("my span"); +/// let mut span = span!(Level::TRACE, "my span"); /// span.enter(|| { /// // do work inside the span... /// }); @@ -18,8 +19,9 @@ /// ``` /// # #[macro_use] /// # extern crate tokio_trace; +/// # use tokio_trace::Level; /// # fn main() { -/// span!("my span", foo = 2, bar = "a string").enter(|| { +/// span!(Level::TRACE, "my span", foo = 2, bar = "a string").enter(|| { /// // do work inside the span... /// }); /// # } @@ -29,8 +31,10 @@ /// ``` /// # #[macro_use] /// # extern crate tokio_trace; +/// # use tokio_trace::Level; /// # fn main() { /// span!( +/// Level::TRACE, /// "my span", /// foo = 2, /// bar = "a string", @@ -42,10 +46,11 @@ /// ``` /// # #[macro_use] /// # extern crate tokio_trace; +/// # use tokio_trace::Level; /// # fn main() { /// span!( +/// Level::TRACE, /// target: "app_span", -/// level: tokio_trace::Level::TRACE, /// "my span", /// foo = 3, /// bar = "another string" @@ -57,8 +62,9 @@ /// ``` /// # #[macro_use] /// # extern crate tokio_trace; +/// # use tokio_trace::Level; /// # fn main() { -/// let mut my_span = span!("my span", foo = 2, bar); +/// let mut my_span = span!(Level::TRACE, "my span", foo = 2, bar); /// my_span.record("bar", &7); /// # } /// ``` @@ -67,8 +73,10 @@ /// ```rust,compile_fail /// # #[macro_use] /// # extern crate tokio_trace; +/// # use tokio_trace::Level; /// # fn main() { /// span!( +/// Level::TRACE, /// "too many fields!", /// a = 1, b = 2, c = 3, d = 4, e = 5, f = 6, g = 7, h = 8, i = 9, /// j = 10, k = 11, l = 12, m = 13, n = 14, o = 15, p = 16, q = 17, @@ -79,28 +87,16 @@ /// ``` #[macro_export(local_inner_macros)] macro_rules! span { - ( - target: $target:expr, - level: $lvl:expr, - parent: $parent:expr, - $name:expr, - $($k:ident $( = $val:expr )* ),*, - ) => { + ($lvl:expr, target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr )* ),*,) => { span!( + $lvl, target: $target, - level: $lvl, parent: $parent, $name, $($k $( = $val)*),* ) }; - ( - target: $target:expr, - level: $lvl:expr, - parent: $parent:expr, - $name:expr, - $($k:ident $( = $val:expr )* ),* - ) => { + ($lvl:expr, target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr )* ),*) => { { use $crate::callsite; use $crate::callsite::Callsite; @@ -126,12 +122,7 @@ macro_rules! span { } } }; - ( - target: $target:expr, - level: $lvl:expr, - $name:expr, - $($k:ident $( = $val:expr )* ),* - ) => { + ($lvl:expr, target: $target:expr, $name:expr,$($k:ident $( = $val:expr )* ),*) => { { use $crate::callsite; use $crate::callsite::Callsite; @@ -157,34 +148,118 @@ macro_rules! span { } }; - (target: $target:expr, level: $lvl:expr, parent: $parent:expr, $name:expr) => { - span!(target: $target, level: $lvl, parent: $parent, $name,) + ($lvl:expr, target: $target:expr, parent: $parent:expr, $name:expr) => { + span!($lvl, target: $target, parent: $parent, $name,) }; - (level: $lvl:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr )* ),*,) => { + ($lvl:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { span!( + $lvl, target: __tokio_trace_module_path!(), - level: $lvl, parent: $parent, $name, $($k $( = $val)*),* ) }; - (level: $lvl:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr )* ),*) => { + ($lvl:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { span!( + $lvl, target: __tokio_trace_module_path!(), - level: $lvl, parent: $parent, $name, $($k $( = $val)*),* ) }; - (level: $lvl:expr, parent: $parent:expr, $name:expr) => { - span!(target: __tokio_trace_module_path!(), level: $lvl, parent: $parent, $name,) + ($lvl:expr, parent: $parent:expr, $name:expr) => { + span!( + $lvl, + target: __tokio_trace_module_path!(), + parent: $parent, + $name, + ) + }; + ($lvl:expr, target: $target:expr, $name:expr, $($k:ident $( = $val:expr )* ),*, + ) => { + span!( + $lvl, + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + ($lvl:expr, target: $target:expr, $name:expr, $($k:ident $( = $val:expr )* ),*) => { + span!( + $lvl, + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + ($lvl:expr, target: $target:expr, $name:expr) => { + span!($lvl, target: $target, $name,) + }; + ($lvl:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + span!( + $lvl, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + ($lvl:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $lvl, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + ($lvl:expr, $name:expr) => { + span!( + $lvl, + target: __tokio_trace_module_path!(), + $name, + ) + }; +} + +/// Constructs a span at the trace level. +/// +/// # Examples +/// +/// ```rust +/// # #[macro_use] +/// # extern crate tokio_trace; +/// # fn main() { +/// let mut span = trace_span!("my span"); +/// span.enter(|| { +/// // do work inside the span... +/// }); +/// # } +/// ``` +#[macro_export(local_inner_macros)] +macro_rules! trace_span { + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + trace_span!( + target: $target, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::TRACE, + target: $target, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, parent: $parent:expr, $name:expr) => { + trace_span!(target: $target, parent: $parent, $name,) }; (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { - span!( - target: __tokio_trace_module_path!(), - level: $crate::Level::TRACE, + trace_span!( parent: $parent, $name, $($k $( = $val)*),* @@ -192,98 +267,403 @@ macro_rules! span { }; (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { span!( + $crate::Level::TRACE, target: __tokio_trace_module_path!(), - level: $crate::Level::TRACE, - parent: $parent, $name, $($k $( = $val)*),* ) }; (parent: $parent:expr, $name:expr) => { - span!( - target: __tokio_trace_module_path!(), - level: $crate::Level::TRACE, - parent: $parent, - $name, - ) + trace_span!(parent: $parent, $name,) }; - ( - target: $target:expr, - level: $lvl:expr, - $name:expr, - $($k:ident $( = $val:expr )* ),*, - ) => { - span!( + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + trace_span!( target: $target, - level: $lvl, $name, $($k $( = $val)*),* ) }; - ( - target: $target:expr, - level: $lvl:expr, - $name:expr, - $($k:ident $( = $val:expr )* ),* - ) => { + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { span!( + $crate::Level::TRACE, target: $target, - level: $lvl, $name, $($k $( = $val)*),* ) }; - (target: $target:expr, level: $lvl:expr, $name:expr) => { - span!(target: $target, level: $lvl, $name,) - }; - (target: $target:expr, level: $lvl:expr, $name:expr,) => { - span!( - target: $target, - level: $lvl, - $name, - ) - }; - (level: $lvl:expr, $name:expr, $($k:ident $( = $val:expr )* ),*,) => { - span!( - target: __tokio_trace_module_path!(), - level: $lvl, - $name, - $($k $( = $val)*),* - ) - }; - (level: $lvl:expr, $name:expr, $($k:ident $( = $val:expr )* ),*) => { - span!( - target: __tokio_trace_module_path!(), - level: $lvl, - $name, $($k $( = $val)*),* - ) - }; - (level: $lvl:expr, $name:expr) => { - span!(target: __tokio_trace_module_path!(), level: $lvl, $name,) + (target: $target:expr, $name:expr) => { + trace_span!(target: $target, $name,) }; ($name:expr, $($k:ident $( = $val:expr)*),*,) => { - span!( - target: __tokio_trace_module_path!(), - level: $crate::Level::TRACE, + trace_span!( $name, $($k $( = $val)*),* ) }; ($name:expr, $($k:ident $( = $val:expr)*),*) => { span!( + $crate::Level::TRACE, target: __tokio_trace_module_path!(), - level: $crate::Level::TRACE, $name, $($k $( = $val)*),* ) }; - ($name:expr) => { - span!( - target: __tokio_trace_module_path!(), - level: $crate::Level::TRACE, + ($name:expr) => {trace_span!($name,)}; +} + +/// Constructs a span at the debug level. +/// +/// # Examples +/// +/// ```rust +/// # #[macro_use] +/// # extern crate tokio_trace; +/// # fn main() { +/// let mut span = debug_span!("my span"); +/// span.enter(|| { +/// // do work inside the span... +/// }); +/// # } +/// ``` +#[macro_export(local_inner_macros)] +macro_rules! debug_span { + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + debug_span!( + target: $target, + parent: $parent, $name, + $($k $( = $val)*),* ) }; + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::DEBUG, + target: $target, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, parent: $parent:expr, $name:expr) => { + debug_span!(target: $target, parent: $parent, $name,) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + debug_span!( + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::DEBUG, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr) => { + debug_span!(parent: $parent, $name,) + }; + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + debug_span!( + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::DEBUG, + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, $name:expr) => { + debug_span!(target: $target, $name,) + }; + ($name:expr, $($k:ident $( = $val:expr)*),*,) => { + debug_span!( + $name, + $($k $( = $val)*),* + ) + }; + ($name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::DEBUG, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + ($name:expr) => {debug_span!($name,)}; +} + +/// Constructs a span at the info level. +/// +/// # Examples +/// +/// ```rust +/// # #[macro_use] +/// # extern crate tokio_trace; +/// # fn main() { +/// let mut span = info_span!("my span"); +/// span.enter(|| { +/// // do work inside the span... +/// }); +/// # } +/// ``` +#[macro_export(local_inner_macros)] +macro_rules! info_span { + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + info_span!( + target: $target, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::INFO, + target: $target, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, parent: $parent:expr, $name:expr) => { + info_span!(target: $target, parent: $parent, $name,) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + info_span!( + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::INFO, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr) => { + info_span!(parent: $parent, $name,) + }; + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + info_span!( + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::INFO, + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, $name:expr) => { + info_span!(target: $target, $name,) + }; + ($name:expr, $($k:ident $( = $val:expr)*),*,) => { + info_span!( + $name, + $($k $( = $val)*),* + ) + }; + ($name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::INFO, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + ($name:expr) => {info_span!($name,)}; +} + +/// Constructs a span at the warn level. +/// +/// # Examples +/// +/// ```rust +/// # #[macro_use] +/// # extern crate tokio_trace; +/// # fn main() { +/// let mut span = warn_span!("my span"); +/// span.enter(|| { +/// // do work inside the span... +/// }); +/// # } +/// ``` +#[macro_export(local_inner_macros)] +macro_rules! warn_span { + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + warn_span!( + target: $target, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::WARN, + target: $target, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, parent: $parent:expr, $name:expr) => { + warn_span!(target: $target, parent: $parent, $name,) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + warn_span!( + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::WARN, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr) => { + warn_span!(parent: $parent, $name,) + }; + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + warn_span!( + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::WARN, + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, $name:expr) => { + warn_span!(target: $target, $name,) + }; + ($name:expr, $($k:ident $( = $val:expr)*),*,) => { + warn_span!( + $name, + $($k $( = $val)*),* + ) + }; + ($name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::WARN, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + ($name:expr) => {warn_span!($name,)}; +} +/// Constructs a span at the error level. +/// +/// # Examples +/// +/// ```rust +/// # #[macro_use] +/// # extern crate tokio_trace; +/// # fn main() { +/// let mut span = error_span!("my span"); +/// span.enter(|| { +/// // do work inside the span... +/// }); +/// # } +/// ``` +#[macro_export(local_inner_macros)] +macro_rules! error_span { + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + error_span!( + target: $target, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::ERROR, + target: $target, + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, parent: $parent:expr, $name:expr) => { + error_span!(target: $target, parent: $parent, $name,) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + error_span!( + parent: $parent, + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::ERROR, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + (parent: $parent:expr, $name:expr) => { + error_span!(parent: $parent, $name,) + }; + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*,) => { + error_span!( + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, $name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::ERROR, + target: $target, + $name, + $($k $( = $val)*),* + ) + }; + (target: $target:expr, $name:expr) => { + error_span!(target: $target, $name,) + }; + ($name:expr, $($k:ident $( = $val:expr)*),*,) => { + error_span!( + $name, + $($k $( = $val)*),* + ) + }; + ($name:expr, $($k:ident $( = $val:expr)*),*) => { + span!( + $crate::Level::ERROR, + target: __tokio_trace_module_path!(), + $name, + $($k $( = $val)*),* + ) + }; + ($name:expr) => {error_span!($name,)}; } /// Constructs a new `Event`. @@ -331,8 +711,9 @@ macro_rules! span { /// ```rust,compile_fail /// # #[macro_use] /// # extern crate tokio_trace; +/// # use tokio_trace::Level; /// # fn main() { -/// event!(tokio_trace::Level::INFO, +/// event!(Level::INFO, /// a = 1, b = 2, c = 3, d = 4, e = 5, f = 6, g = 7, h = 8, i = 9, /// j = 10, k = 11, l = 12, m = 13, n = 14, o = 15, p = 16, q = 17, /// r = 18, s = 19, t = 20, u = 21, v = 22, w = 23, x = 24, y = 25, diff --git a/tokio-trace/src/span.rs b/tokio-trace/src/span.rs index 3232b26ad..c392501d1 100644 --- a/tokio-trace/src/span.rs +++ b/tokio-trace/src/span.rs @@ -12,9 +12,10 @@ //! if the span exists: //! ``` //! # #[macro_use] extern crate tokio_trace; +//! # use tokio_trace::Level; //! # fn main() { //! let my_var: u64 = 5; -//! let mut my_span = span!("my_span", my_var = &my_var); +//! let mut my_span = span!(Level::TRACE, "my_span", my_var = &my_var); //! //! my_span.enter(|| { //! // perform some work in the context of `my_span`... @@ -78,9 +79,10 @@ //! exists. For example: //! ``` //! # #[macro_use] extern crate tokio_trace; +//! # use tokio_trace::Level; //! # fn main() { //! { -//! span!("my_span").enter(|| { +//! span!(Level::TRACE, "my_span").enter(|| { //! // perform some work in the context of `my_span`... //! }); // --> Subscriber::exit(my_span) //! @@ -96,10 +98,11 @@ //! time it is exited. For example: //! ``` //! # #[macro_use] extern crate tokio_trace; +//! # use tokio_trace::Level; //! # fn main() { //! use tokio_trace::Span; //! -//! let my_span = span!("my_span"); +//! let my_span = span!(Level::TRACE, "my_span"); //! // Drop the handle to the span. //! drop(my_span); // --> Subscriber::drop_span(my_span) //! # } diff --git a/tokio-trace/test-log-support/tests/log_no_trace.rs b/tokio-trace/test-log-support/tests/log_no_trace.rs index 25eba9f02..2c3b7f1dd 100644 --- a/tokio-trace/test-log-support/tests/log_no_trace.rs +++ b/tokio-trace/test-log-support/tests/log_no_trace.rs @@ -4,6 +4,7 @@ extern crate tokio_trace; use log::{LevelFilter, Log, Metadata, Record}; use std::sync::{Arc, Mutex}; +use tokio_trace::Level; struct State { last_log: Mutex>, @@ -41,7 +42,7 @@ fn test_always_log() { info!(message = "hello world;", thingy = 42, other_thingy = 666); last(&a, "hello world; thingy=42 other_thingy=666"); - let mut foo = span!("foo"); + let mut foo = span!(Level::TRACE, "foo"); last(&a, "foo;"); foo.enter(|| { last(&a, "-> foo"); @@ -51,10 +52,10 @@ fn test_always_log() { }); last(&a, "<- foo"); - span!("foo", bar = 3, baz = false); + span!(Level::TRACE, "foo", bar = 3, baz = false); last(&a, "foo; bar=3 baz=false"); - let mut span = span!("foo", bar, baz); + let mut span = span!(Level::TRACE, "foo", bar, baz); span.record("bar", &3); last(&a, "foo; bar=3"); span.record("baz", &"a string"); diff --git a/tokio-trace/test_static_max_level_features/tests/test.rs b/tokio-trace/test_static_max_level_features/tests/test.rs index ba3f27576..ff13b2eef 100644 --- a/tokio-trace/test_static_max_level_features/tests/test.rs +++ b/tokio-trace/test_static_max_level_features/tests/test.rs @@ -51,15 +51,15 @@ fn test_static_max_level_features() { trace!(""); last(&a, None); - span!(level: Level::ERROR, ""); + span!(Level::ERROR, ""); last(&a, None); - span!(level: Level::WARN, ""); + span!(Level::WARN, ""); last(&a, None); - span!(level: Level::INFO, ""); + span!(Level::INFO, ""); last(&a, None); - span!(level: Level::DEBUG, ""); + span!(Level::DEBUG, ""); last(&a, None); - span!(level: Level::TRACE, ""); + span!(Level::TRACE, ""); last(&a, None); }); } diff --git a/tokio-trace/tests/event.rs b/tokio-trace/tests/event.rs index b2c39cdbd..85a090640 100644 --- a/tokio-trace/tests/event.rs +++ b/tokio-trace/tests/event.rs @@ -68,7 +68,7 @@ fn one_with_everything() { .and(field::mock("bar").with_value(&false)) .only(), ) - .at_level(tokio_trace::Level::ERROR) + .at_level(Level::ERROR) .with_target("whatever"), ) .done() @@ -77,7 +77,7 @@ fn one_with_everything() { with_default(subscriber, || { event!( target: "whatever", - tokio_trace::Level::ERROR, + Level::ERROR, { foo = 666, bar = false }, "{:#x} make me one with{what:.>20}", 4277009102u64, what = "everything" ); diff --git a/tokio-trace/tests/macros.rs b/tokio-trace/tests/macros.rs index 903fd2dbf..f97eea486 100644 --- a/tokio-trace/tests/macros.rs +++ b/tokio-trace/tests/macros.rs @@ -1,3 +1,5 @@ +use tokio_trace::Level; + #[macro_use] extern crate tokio_trace; // Tests that macros work across various invocation syntax. @@ -8,95 +10,258 @@ extern crate tokio_trace; #[test] fn span() { - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, "foo", bar = 2, baz = 3); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, "foo", bar = 2, baz = 4,); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, "foo"); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, "bar",); - span!(level: tokio_trace::Level::DEBUG, "foo", bar = 2, baz = 3); - span!(level: tokio_trace::Level::DEBUG, "foo", bar = 2, baz = 4,); - span!(level: tokio_trace::Level::DEBUG, "foo"); - span!(level: tokio_trace::Level::DEBUG, "bar",); - span!("foo", bar = 2, baz = 3); - span!("foo", bar = 2, baz = 4,); - span!("foo"); - span!("bar",); + span!(Level::DEBUG, target: "foo_events", "foo", bar = 2, baz = 3); + span!(Level::DEBUG, target: "foo_events", "foo", bar = 2, baz = 4,); + span!(Level::DEBUG, target: "foo_events", "foo"); + span!(Level::DEBUG, target: "foo_events", "bar",); + span!(Level::DEBUG, "foo", bar = 2, baz = 3); + span!(Level::DEBUG, "foo", bar = 2, baz = 4,); + span!(Level::TRACE, "foo", bar = 2, baz = 3); + span!(Level::TRACE, "foo", bar = 2, baz = 4,); + span!(Level::TRACE, "foo"); + span!(Level::TRACE, "bar",); +} + +#[test] +fn trace_span() { + trace_span!(target: "foo_events", "foo", bar = 2, baz = 3); + trace_span!(target: "foo_events", "foo", bar = 2, baz = 4,); + trace_span!(target: "foo_events", "foo"); + trace_span!(target: "foo_events", "bar",); + trace_span!("foo", bar = 2, baz = 3); + trace_span!("foo", bar = 2, baz = 4,); + trace_span!("bar"); + trace_span!("bar",); +} + +#[test] +fn debug_span() { + debug_span!(target: "foo_events", "foo", bar = 2, baz = 3); + debug_span!(target: "foo_events", "foo", bar = 2, baz = 4,); + debug_span!(target: "foo_events", "foo"); + debug_span!(target: "foo_events", "bar",); + debug_span!("foo", bar = 2, baz = 3); + debug_span!("foo", bar = 2, baz = 4,); + debug_span!("bar"); + debug_span!("bar",); +} + +#[test] +fn info_span() { + info_span!(target: "foo_events", "foo", bar = 2, baz = 3); + info_span!(target: "foo_events", "foo", bar = 2, baz = 4,); + info_span!(target: "foo_events", "foo"); + info_span!(target: "foo_events", "bar",); + info_span!("foo", bar = 2, baz = 3); + info_span!("foo", bar = 2, baz = 4,); + info_span!("bar"); + info_span!("bar",); +} + +#[test] +fn warn_span() { + warn_span!(target: "foo_events", "foo", bar = 2, baz = 3); + warn_span!(target: "foo_events", "foo", bar = 2, baz = 4,); + warn_span!(target: "foo_events", "foo"); + warn_span!(target: "foo_events", "bar",); + warn_span!("foo", bar = 2, baz = 3); + warn_span!("foo", bar = 2, baz = 4,); + warn_span!("bar"); + warn_span!("bar",); +} + +#[test] +fn error_span() { + error_span!(target: "foo_events", "foo", bar = 2, baz = 3); + error_span!(target: "foo_events", "foo", bar = 2, baz = 4,); + error_span!(target: "foo_events", "foo"); + error_span!(target: "foo_events", "bar",); + error_span!("foo", bar = 2, baz = 3); + error_span!("foo", bar = 2, baz = 4,); + error_span!("bar"); + error_span!("bar",); } #[test] fn span_root() { - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: None, "foo", bar = 2, baz = 3); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: None, "foo", bar = 2, baz = 4,); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: None, "foo"); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: None, "bar",); - span!( - level: tokio_trace::Level::DEBUG, - parent: None, - "foo", - bar = 2, - baz = 3 - ); - span!( - level: tokio_trace::Level::DEBUG, - parent: None, - "foo", - bar = 2, - baz = 4, - ); - span!(level: tokio_trace::Level::DEBUG, parent: None, "foo"); - span!(level: tokio_trace::Level::DEBUG, parent: None, "bar",); - span!(parent: None, "foo", bar = 2, baz = 3); - span!(parent: None, "foo", bar = 2, baz = 4,); - span!(parent: None, "foo"); - span!(parent: None, "bar",); + span!(Level::DEBUG, target: "foo_events", parent: None, "foo", bar = 2, baz = 3); + span!(Level::DEBUG, target: "foo_events", parent: None, "foo", bar = 2, baz = 4,); + span!(Level::DEBUG, target: "foo_events", parent: None, "foo"); + span!(Level::DEBUG, target: "foo_events", parent: None, "bar",); + span!(Level::TRACE, parent: None, "foo", bar = 2, baz = 3); + span!(Level::TRACE, parent: None, "foo", bar = 2, baz = 4,); + span!(Level::TRACE, parent: None, "foo"); + span!(Level::TRACE, parent: None, "bar",); +} + +#[test] +fn trace_span_root() { + trace_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 3); + trace_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 4,); + trace_span!(target: "foo_events", parent: None, "foo"); + trace_span!(target: "foo_events", parent: None, "bar",); + trace_span!(parent: None, "foo", bar = 2, baz = 3); + trace_span!(parent: None, "foo", bar = 2, baz = 4,); + trace_span!(parent: None, "foo"); + trace_span!(parent: None, "bar",); +} + +#[test] +fn debug_span_root() { + debug_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 3); + debug_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 4,); + debug_span!(target: "foo_events", parent: None, "foo"); + debug_span!(target: "foo_events", parent: None, "bar",); + debug_span!(parent: None, "foo", bar = 2, baz = 3); + debug_span!(parent: None, "foo", bar = 2, baz = 4,); + debug_span!(parent: None, "foo"); + debug_span!(parent: None, "bar",); +} + +#[test] +fn info_span_root() { + info_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 3); + info_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 4,); + info_span!(target: "foo_events", parent: None, "foo"); + info_span!(target: "foo_events", parent: None, "bar",); + info_span!(parent: None, "foo", bar = 2, baz = 3); + info_span!(parent: None, "foo", bar = 2, baz = 4,); + info_span!(parent: None, "foo"); + info_span!(parent: None, "bar",); +} + +#[test] +fn warn_span_root() { + warn_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 3); + warn_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 4,); + warn_span!(target: "foo_events", parent: None, "foo"); + warn_span!(target: "foo_events", parent: None, "bar",); + warn_span!(parent: None, "foo", bar = 2, baz = 3); + warn_span!(parent: None, "foo", bar = 2, baz = 4,); + warn_span!(parent: None, "foo"); + warn_span!(parent: None, "bar",); +} + +#[test] +fn error_span_root() { + error_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 3); + error_span!(target: "foo_events", parent: None, "foo", bar = 2, baz = 4,); + error_span!(target: "foo_events", parent: None, "foo"); + error_span!(target: "foo_events", parent: None, "bar",); + error_span!(parent: None, "foo", bar = 2, baz = 3); + error_span!(parent: None, "foo", bar = 2, baz = 4,); + error_span!(parent: None, "foo"); + error_span!(parent: None, "bar",); } #[test] fn span_with_parent() { - let p = span!("im_a_parent!"); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: &p, "foo", bar = 2, baz = 3); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: &p, "foo", bar = 2, baz = 4,); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: &p, "foo"); - span!(target: "foo_events", level: tokio_trace::Level::DEBUG, parent: &p, "bar",); - span!( - level: tokio_trace::Level::DEBUG, - parent: &p, - "foo", - bar = 2, - baz = 3 - ); - span!( - level: tokio_trace::Level::DEBUG, - parent: &p, - "foo", - bar = 2, - baz = 4, - ); - span!(level: tokio_trace::Level::DEBUG, parent: &p, "foo"); - span!(level: tokio_trace::Level::DEBUG, parent: &p, "bar",); - span!(parent: &p, "foo", bar = 2, baz = 3); - span!(parent: &p, "foo", bar = 2, baz = 4,); - span!(parent: &p, "foo"); - span!(parent: &p, "bar",); + let p = span!(Level::TRACE, "im_a_parent!"); + span!(Level::DEBUG, target: "foo_events", parent: &p, "foo", bar = 2, baz = 3); + span!(Level::DEBUG, target: "foo_events", parent: &p, "foo", bar = 2, baz = 4,); + span!(Level::DEBUG, target: "foo_events", parent: &p, "foo"); + span!(Level::DEBUG, target: "foo_events", parent: &p, "bar",); + + span!(Level::DEBUG, parent: &p, "foo", bar = 2, baz = 3); + span!(Level::DEBUG, parent: &p, "foo", bar = 2, baz = 4,); + + span!(Level::DEBUG, parent: &p, "foo"); + span!(Level::DEBUG, parent: &p, "bar",); +} + +#[test] +fn trace_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + trace_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 3); + trace_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 4,); + trace_span!(target: "foo_events", parent: &p, "foo"); + trace_span!(target: "foo_events", parent: &p, "bar",); + + trace_span!(parent: &p, "foo", bar = 2, baz = 3); + trace_span!(parent: &p, "foo", bar = 2, baz = 4,); + + trace_span!(parent: &p, "foo"); + trace_span!(parent: &p, "bar",); +} + +#[test] +fn debug_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + debug_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 3); + debug_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 4,); + debug_span!(target: "foo_events", parent: &p, "foo"); + debug_span!(target: "foo_events", parent: &p, "bar",); + + debug_span!(parent: &p, "foo", bar = 2, baz = 3); + debug_span!(parent: &p, "foo", bar = 2, baz = 4,); + + debug_span!(parent: &p, "foo"); + debug_span!(parent: &p, "bar",); +} + +#[test] +fn info_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + info_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 3); + info_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 4,); + info_span!(target: "foo_events", parent: &p, "foo"); + info_span!(target: "foo_events", parent: &p, "bar",); + + info_span!(parent: &p, "foo", bar = 2, baz = 3); + info_span!(parent: &p, "foo", bar = 2, baz = 4,); + + info_span!(parent: &p, "foo"); + info_span!(parent: &p, "bar",); +} + +#[test] +fn warn_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + warn_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 3); + warn_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 4,); + warn_span!(target: "foo_events", parent: &p, "foo"); + warn_span!(target: "foo_events", parent: &p, "bar",); + + warn_span!(parent: &p, "foo", bar = 2, baz = 3); + warn_span!(parent: &p, "foo", bar = 2, baz = 4,); + + warn_span!(parent: &p, "foo"); + warn_span!(parent: &p, "bar",); +} + +#[test] +fn error_span_with_parent() { + let p = span!(Level::TRACE, "im_a_parent!"); + error_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 3); + error_span!(target: "foo_events", parent: &p, "foo", bar = 2, baz = 4,); + error_span!(target: "foo_events", parent: &p, "foo"); + error_span!(target: "foo_events", parent: &p, "bar",); + + error_span!(parent: &p, "foo", bar = 2, baz = 3); + error_span!(parent: &p, "foo", bar = 2, baz = 4,); + + error_span!(parent: &p, "foo"); + error_span!(parent: &p, "bar",); } #[test] fn event() { - event!(tokio_trace::Level::DEBUG, foo = 3, bar = 2, baz = false); - event!(tokio_trace::Level::DEBUG, foo = 3, bar = 3,); - event!(tokio_trace::Level::DEBUG, "foo"); - event!(tokio_trace::Level::DEBUG, "foo: {}", 3); - event!(tokio_trace::Level::DEBUG, { foo = 3, bar = 80 }, "baz"); - event!(tokio_trace::Level::DEBUG, { foo = 2, bar = 79 }, "baz {:?}", true); - event!(tokio_trace::Level::DEBUG, { foo = 2, bar = 79 }, "baz {:?}, {quux}", true, quux = false); - event!(tokio_trace::Level::DEBUG, { foo = 2, bar = 78, }, "baz"); - event!(target: "foo_events", tokio_trace::Level::DEBUG, foo = 3, bar = 2, baz = false); - event!(target: "foo_events", tokio_trace::Level::DEBUG, foo = 3, bar = 3,); - event!(target: "foo_events", tokio_trace::Level::DEBUG, "foo"); - event!(target: "foo_events", tokio_trace::Level::DEBUG, "foo: {}", 3); - event!(target: "foo_events", tokio_trace::Level::DEBUG, { foo = 3, bar = 80 }, "baz"); - event!(target: "foo_events", tokio_trace::Level::DEBUG, { foo = 2, bar = 79 }, "baz {:?}", true); - event!(target: "foo_events", tokio_trace::Level::DEBUG, { foo = 2, bar = 79 }, "baz {:?}, {quux}", true, quux = false); - event!(target: "foo_events", tokio_trace::Level::DEBUG, { foo = 2, bar = 78, }, "baz"); + event!(Level::DEBUG, foo = 3, bar = 2, baz = false); + event!(Level::DEBUG, foo = 3, bar = 3,); + event!(Level::DEBUG, "foo"); + event!(Level::DEBUG, "foo: {}", 3); + event!(Level::DEBUG, { foo = 3, bar = 80 }, "baz"); + event!(Level::DEBUG, { foo = 2, bar = 79 }, "baz {:?}", true); + event!(Level::DEBUG, { foo = 2, bar = 79 }, "baz {:?}, {quux}", true, quux = false); + event!(Level::DEBUG, { foo = 2, bar = 78, }, "baz"); + event!(target: "foo_events", Level::DEBUG, foo = 3, bar = 2, baz = false); + event!(target: "foo_events", Level::DEBUG, foo = 3, bar = 3,); + event!(target: "foo_events", Level::DEBUG, "foo"); + event!(target: "foo_events", Level::DEBUG, "foo: {}", 3); + event!(target: "foo_events", Level::DEBUG, { foo = 3, bar = 80 }, "baz"); + event!(target: "foo_events", Level::DEBUG, { foo = 2, bar = 79 }, "baz {:?}", true); + event!(target: "foo_events", Level::DEBUG, { foo = 2, bar = 79 }, "baz {:?}, {quux}", true, quux = false); + event!(target: "foo_events", Level::DEBUG, { foo = 2, bar = 78, }, "baz"); } #[test] diff --git a/tokio-trace/tests/span.rs b/tokio-trace/tests/span.rs index 3ff0d95fe..7996e096a 100644 --- a/tokio-trace/tests/span.rs +++ b/tokio-trace/tests/span.rs @@ -13,7 +13,7 @@ fn handles_to_the_same_span_are_equal() { // won't enter any spans in this test, so the subscriber won't actually // expect to see any spans. with_default(subscriber::mock().run(), || { - let foo1 = span!("foo"); + let foo1 = span!(Level::TRACE, "foo"); let foo2 = foo1.clone(); // Two handles that point to the same span are equal. assert_eq!(foo1, foo2); @@ -25,8 +25,8 @@ fn handles_to_different_spans_are_not_equal() { with_default(subscriber::mock().run(), || { // Even though these spans have the same name and fields, they will have // differing metadata, since they were created on different lines. - let foo1 = span!("foo", bar = 1u64, baz = false); - let foo2 = span!("foo", bar = 1u64, baz = false); + let foo1 = span!(Level::TRACE, "foo", bar = 1u64, baz = false); + let foo2 = span!(Level::TRACE, "foo", bar = 1u64, baz = false); assert_ne!(foo1, foo2); }); @@ -37,7 +37,7 @@ fn handles_to_different_spans_with_the_same_metadata_are_not_equal() { // Every time time this function is called, it will return a _new // instance_ of a span with the same metadata, name, and fields. fn make_span() -> Span { - span!("foo", bar = 1u64, baz = false) + span!(Level::TRACE, "foo", bar = 1u64, baz = false) } with_default(subscriber::mock().run(), || { @@ -62,7 +62,7 @@ fn spans_always_go_to_the_subscriber_that_tagged_them() { let subscriber2 = subscriber::mock().run(); let mut foo = with_default(subscriber1, || { - let mut foo = span!("foo"); + let mut foo = span!(Level::TRACE, "foo"); foo.enter(|| {}); foo }); @@ -82,7 +82,7 @@ fn spans_always_go_to_the_subscriber_that_tagged_them_even_across_threads() { .done() .run(); let mut foo = with_default(subscriber1, || { - let mut foo = span!("foo"); + let mut foo = span!(Level::TRACE, "foo"); foo.enter(|| {}); foo }); @@ -107,7 +107,7 @@ fn dropping_a_span_calls_drop_span() { .done() .run_with_handle(); with_default(subscriber, || { - let mut span = span!("foo"); + let mut span = span!(Level::TRACE, "foo"); span.enter(|| {}); drop(span); }); @@ -125,7 +125,7 @@ fn span_closes_after_event() { .done() .run_with_handle(); with_default(subscriber, || { - span!("foo").enter(|| { + span!(Level::TRACE, "foo").enter(|| { event!(Level::DEBUG, {}, "my event!"); }); }); @@ -146,10 +146,10 @@ fn new_span_after_event() { .done() .run_with_handle(); with_default(subscriber, || { - span!("foo").enter(|| { + span!(Level::TRACE, "foo").enter(|| { event!(Level::DEBUG, {}, "my event!"); }); - span!("bar").enter(|| {}); + span!(Level::TRACE, "bar").enter(|| {}); }); handle.assert_finished(); @@ -166,7 +166,7 @@ fn event_outside_of_span() { .run_with_handle(); with_default(subscriber, || { debug!("my event!"); - span!("foo").enter(|| {}); + span!(Level::TRACE, "foo").enter(|| {}); }); handle.assert_finished(); @@ -178,7 +178,7 @@ fn cloning_a_span_calls_clone_span() { .clone_span(span::mock().named("foo")) .run_with_handle(); with_default(subscriber, || { - let span = span!("foo"); + let span = span!(Level::TRACE, "foo"); let _span2 = span.clone(); }); @@ -193,7 +193,7 @@ fn drop_span_when_exiting_dispatchers_context() { .drop_span(span::mock().named("foo")) .run_with_handle(); with_default(subscriber, || { - let span = span!("foo"); + let span = span!(Level::TRACE, "foo"); let _span2 = span.clone(); drop(span); }); @@ -215,7 +215,7 @@ fn clone_and_drop_span_always_go_to_the_subscriber_that_tagged_the_span() { let subscriber2 = subscriber::mock().done().run(); let mut foo = with_default(subscriber1, || { - let mut foo = span!("foo"); + let mut foo = span!(Level::TRACE, "foo"); foo.enter(|| {}); foo }); @@ -240,7 +240,7 @@ fn span_closes_when_exited() { .done() .run_with_handle(); with_default(subscriber, || { - let mut foo = span!("foo"); + let mut foo = span!(Level::TRACE, "foo"); foo.enter(|| {}); @@ -267,7 +267,11 @@ fn moved_field() { .run_with_handle(); with_default(subscriber, || { let from = "my span"; - let mut span = span!("foo", bar = display(format!("hello from {}", from))); + let mut span = span!( + Level::TRACE, + "foo", + bar = display(format!("hello from {}", from)) + ); span.enter(|| {}); }); @@ -293,7 +297,7 @@ fn borrowed_field() { with_default(subscriber, || { let from = "my span"; let mut message = format!("hello from {}", from); - let mut span = span!("foo", bar = display(&message)); + let mut span = span!(Level::TRACE, "foo", bar = display(&message)); span.enter(|| { message.insert_str(10, " inside"); }); @@ -339,8 +343,8 @@ fn move_field_out_of_struct() { x: 3.234, y: -1.223, }; - let mut foo = span!("foo", x = debug(pos.x), y = debug(pos.y)); - let mut bar = span!("bar", position = debug(pos)); + let mut foo = span!(Level::TRACE, "foo", x = debug(pos.x), y = debug(pos.y)); + let mut bar = span!(Level::TRACE, "bar", position = debug(pos)); foo.enter(|| {}); bar.enter(|| {}); }); @@ -367,7 +371,7 @@ fn add_field_after_new_span() { .run_with_handle(); with_default(subscriber, || { - let mut span = span!("foo", bar = 5, baz); + let mut span = span!(Level::TRACE, "foo", bar = 5, baz); span.record("baz", &true); span.enter(|| {}) }); @@ -394,7 +398,7 @@ fn add_fields_only_after_new_span() { .run_with_handle(); with_default(subscriber, || { - let mut span = span!("foo", bar, baz); + let mut span = span!(Level::TRACE, "foo", bar, baz); span.record("bar", &5); span.record("baz", &true); span.enter(|| {}) @@ -410,13 +414,13 @@ fn new_span_with_target_and_log_level() { span::mock() .named("foo") .with_target("app_span") - .at_level(tokio_trace::Level::DEBUG), + .at_level(Level::DEBUG), ) .done() .run_with_handle(); with_default(subscriber, || { - span!(target: "app_span", level: tokio_trace::Level::DEBUG, "foo"); + span!(Level::DEBUG, target: "app_span", "foo"); }); handle.assert_finished(); @@ -430,7 +434,7 @@ fn explicit_root_span_is_root() { .run_with_handle(); with_default(subscriber, || { - span!(parent: None, "foo"); + span!(Level::TRACE, parent: None, "foo"); }); handle.assert_finished(); @@ -447,8 +451,8 @@ fn explicit_root_span_is_root_regardless_of_ctx() { .run_with_handle(); with_default(subscriber, || { - span!("foo").enter(|| { - span!(parent: None, "bar"); + span!(Level::TRACE, "foo").enter(|| { + span!(Level::TRACE, parent: None, "bar"); }) }); @@ -464,8 +468,8 @@ fn explicit_child() { .run_with_handle(); with_default(subscriber, || { - let foo = span!("foo"); - span!(parent: foo.id(), "bar"); + let foo = span!(Level::TRACE, "foo"); + span!(Level::TRACE, parent: foo.id(), "bar"); }); handle.assert_finished(); @@ -483,8 +487,8 @@ fn explicit_child_regardless_of_ctx() { .run_with_handle(); with_default(subscriber, || { - let foo = span!("foo"); - span!("bar").enter(|| span!(parent: foo.id(), "baz")) + let foo = span!(Level::TRACE, "foo"); + span!(Level::TRACE, "bar").enter(|| span!(Level::TRACE, parent: foo.id(), "baz")) }); handle.assert_finished(); @@ -498,7 +502,7 @@ fn contextual_root() { .run_with_handle(); with_default(subscriber, || { - span!("foo"); + span!(Level::TRACE, "foo"); }); handle.assert_finished(); @@ -519,8 +523,8 @@ fn contextual_child() { .run_with_handle(); with_default(subscriber, || { - span!("foo").enter(|| { - span!("bar"); + span!(Level::TRACE, "foo").enter(|| { + span!(Level::TRACE, "bar"); }) }); diff --git a/tokio-trace/tests/subscriber.rs b/tokio-trace/tests/subscriber.rs index eee276ca6..cce3090f8 100644 --- a/tokio-trace/tests/subscriber.rs +++ b/tokio-trace/tests/subscriber.rs @@ -4,6 +4,7 @@ mod support; use self::support::*; use tokio_trace::subscriber::with_default; +use tokio_trace::Level; use std::sync::{ atomic::{AtomicUsize, Ordering}, @@ -36,9 +37,9 @@ fn filters_are_not_reevaluated_for_the_same_span() { with_default(subscriber, move || { // Enter "alice" and then "bob". The dispatcher expects to see "bob" but // not "alice." - let mut alice = span!("alice"); + let mut alice = span!(Level::TRACE, "alice"); let mut bob = alice.enter(|| { - let mut bob = span!("bob"); + let mut bob = span!(Level::TRACE, "bob"); bob.enter(|| ()); bob }); @@ -90,9 +91,9 @@ fn filters_are_reevaluated_for_different_call_sites() { with_default(subscriber, move || { // Enter "charlie" and then "dave". The dispatcher expects to see "dave" but // not "charlie." - let mut charlie = span!("charlie"); + let mut charlie = span!(Level::TRACE, "charlie"); let mut dave = charlie.enter(|| { - let mut dave = span!("dave"); + let mut dave = span!(Level::TRACE, "dave"); dave.enter(|| {}); dave }); @@ -110,14 +111,14 @@ fn filters_are_reevaluated_for_different_call_sites() { // A different span with the same name has a different call site, so it // should cause the filter to be reapplied. - let mut charlie2 = span!("charlie"); + let mut charlie2 = span!(Level::TRACE, "charlie"); charlie.enter(|| {}); assert_eq!(charlie_count.load(Ordering::Relaxed), 2); assert_eq!(dave_count.load(Ordering::Relaxed), 1); // But, the filter should not be re-evaluated for the new "charlie" span // when it is re-entered. - charlie2.enter(|| span!("dave").enter(|| {})); + charlie2.enter(|| span!(Level::TRACE, "dave").enter(|| {})); assert_eq!(charlie_count.load(Ordering::Relaxed), 2); assert_eq!(dave_count.load(Ordering::Relaxed), 2); }); @@ -126,11 +127,11 @@ fn filters_are_reevaluated_for_different_call_sites() { #[test] fn filter_caching_is_lexically_scoped() { pub fn my_great_function() -> bool { - span!("emily").enter(|| true) + span!(Level::TRACE, "emily").enter(|| true) } pub fn my_other_function() -> bool { - span!("frank").enter(|| true) + span!(Level::TRACE, "frank").enter(|| true) } let count = Arc::new(AtomicUsize::new(0));