From 41ca9a43de95d56bc726881e9ecee921870ebfd9 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Sun, 9 Jun 2019 13:16:35 -0700 Subject: [PATCH] trace: Add shorthand syntax for local fields (#1103) ## Motivation A common pattern in `tokio-trace` is to use the value of a local variable as a field on a span or event. Currently, this requires code like: ```rust info!(foo = foo); ``` which is not particularly ergonomic given how commonly this occurs. Struct initializers support a shorthand syntax for fields where the name of the field is the same as a local variable, and `tokio-trace` should as well. ## Solution This branch adds support for syntax like ```rust let foo = ...; info!(foo); ``` and ```rust let foo = Foo { bar: ..., ... }; info!(foo.bar) ``` to the `tokio-trace` span and event macros. This syntax also works with the `Debug` and `Display` field shorthand. The span macros previously used a field name with no value to indicate an uninitialized field. A new issue, #1138, has been opened for finding a replacement syntax for uninitialized fields. Until then, the `tokio-trace` macros will no longer provide a way to create fields without values, although the `-core` API will continue to support this. Closes #1062 Signed-off-by: Eliza Weisman --- tokio-trace/src/lib.rs | 40 +- tokio-trace/src/macros.rs | 515 +++++++++++++++--- .../test-log-support/tests/log_no_trace.rs | 14 +- tokio-trace/tests/macros.rs | 20 + tokio-trace/tests/span.rs | 76 ++- 5 files changed, 567 insertions(+), 98 deletions(-) diff --git a/tokio-trace/src/lib.rs b/tokio-trace/src/lib.rs index 08d594c57..ff4eef0ba 100644 --- a/tokio-trace/src/lib.rs +++ b/tokio-trace/src/lib.rs @@ -101,10 +101,27 @@ //! // - "foo", with a value of 42, //! // - "bar", with the value "false" //! // - "baz", with no initial value -//! let my_span = span!(Level::INFO, "my_span", foo = 42, bar = false, baz); +//! let my_span = span!(Level::INFO, "my_span", foo = 42, bar = false); //! -//! // record a value for the field "baz" declared above: -//! my_span.record("baz", &"hello world"); +// TODO(#1138): determine a new syntax for uninitialized span fields, and +// re-enable this. +// //! // record a value for the field "baz" declared above: +// //! my_span.record("baz", &"hello world"); +//! # } +//!``` +//! +//! As shorthand, local variables may be used as field values without an +//! assignment, similar to [struct initializers]. For example: +//! ``` +//! # #[macro_use] +//! # extern crate tokio_trace; +//! # use tokio_trace::Level; +//! # fn main() { +//! let user = "ferris"; +//! +//! span!(Level::TRACE, "login", user); +//! // is equivalent to: +//! span!(Level::TRACE, "login", user = user); //! # } //!``` //! @@ -120,7 +137,7 @@ //! ``` //! # #[macro_use] //! # extern crate tokio_trace; -//! # use tokio_trace::Level; +//! # use tokio_trace::{Level, field}; //! # fn main() { //! #[derive(Debug)] //! struct MyStruct { @@ -131,14 +148,9 @@ //! my_field: "Hello world!" //! }; //! -//! let my_span = span!( -//! Level::TRACE, -//! "my_span", -//! // `my_struct` will be recorded using its `fmt::Debug` implementation. -//! my_struct = ?my_struct, -//! // `my_field` will be recorded using the implementation of `fmt::Display` for `&str`. -//! my_struct.my_field = %my_struct.my_field, -//! ); +//! span!(Level::TRACE,"my_span", ?my_struct, %my_struct.my_field); +//! // is equivalent to: +//! span!(Level::TRACE, "my_span", my_struct = field::debug(&my_struct), my_struct.my_field = field::display(&my_struct.my_field)); //! # } //!``` //! @@ -311,7 +323,7 @@ //! # fn find_a_razor() -> Result { Ok(1) } //! # fn main() { //! pub fn shave_the_yak(yak: &mut Yak) { -//! let span = span!(Level::TRACE, "shave_the_yak", yak = ?yak); +//! let span = span!(Level::TRACE, "shave_the_yak", ?yak); //! let _enter = span.enter(); //! //! // Since the span is annotated with the yak, it is part of the context @@ -324,7 +336,7 @@ //! // We can add the razor as a field rather than formatting it //! // as part of the message, allowing subscribers to consume it //! // in a more structured manner: -//! info!({ razor = %razor }, "Razor located"); +//! info!({ %razor }, "Razor located"); //! yak.shave(razor); //! break; //! } diff --git a/tokio-trace/src/macros.rs b/tokio-trace/src/macros.rs index 6311a831a..f12eb66b0 100644 --- a/tokio-trace/src/macros.rs +++ b/tokio-trace/src/macros.rs @@ -15,6 +15,18 @@ /// # } /// ``` /// +/// Creating a span with custom target: +/// ``` +/// # #[macro_use] +/// # extern crate tokio_trace; +/// # use tokio_trace::Level; +/// # fn main() { +/// span!(Level::TRACE, target: "app_span", "my span"); +/// # } +/// ``` +/// +/// # Fields +/// /// Creating a span with fields: /// ``` /// # #[macro_use] @@ -42,34 +54,69 @@ /// # } /// ``` /// -/// Creating a span with custom target and log level: +/// As shorthand, local variables may be used as field values without an +/// assignment, similar to [struct initializers]. For example: /// ``` /// # #[macro_use] /// # extern crate tokio_trace; /// # use tokio_trace::Level; /// # fn main() { -/// span!( -/// Level::TRACE, -/// target: "app_span", -/// "my span", -/// foo = 3, -/// bar = "another string" -/// ); -/// # } -/// ``` +/// let user = "ferris"; /// -/// Field values may be recorded after the span is created: +/// span!(Level::TRACE, "login", user); +/// // is equivalent to: +/// span!(Level::TRACE, "login", user = user); +/// # } +///``` +/// +/// Field names can include dots: /// ``` /// # #[macro_use] /// # extern crate tokio_trace; /// # use tokio_trace::Level; /// # fn main() { -/// let my_span = span!(Level::TRACE, "my span", foo = 2, bar); -/// my_span.record("bar", &7); +/// let user = "ferris"; +/// let email = "ferris@rust-lang.org"; +/// span!(Level::TRACE, "login", user, user.email = email); /// # } -/// ``` +///``` /// -/// Shorthand for `field::debug`: +/// Since field names can include dots, fields on local structs can be used +/// using the local variable shorthand: +/// ``` +/// # #[macro_use] +/// # extern crate tokio_trace; +/// # use tokio_trace::Level; +/// # fn main() { +/// # struct User { +/// # name: &'static str, +/// # email: &'static str, +/// # } +/// let user = User { +/// name: "ferris", +/// email: "ferris@rust-lang.org", +/// }; +/// // the span will have the fields `user.name = "ferris"` and +/// // `user.email = "ferris@rust-lang.org"`. +/// span!(Level::TRACE, "login", user.name, user.email); +/// # } +///``` +/// +// TODO(#1138): determine a new syntax for uninitialized span fields, and +// re-enable this. +// /// Field values may be recorded after the span is created. The `_` character is +// /// used to represent a field whose value has yet to be recorded: +// /// ``` +// /// # #[macro_use] +// /// # extern crate tokio_trace; +// /// # use tokio_trace::Level; +// /// # fn main() { +// /// let my_span = span!(Level::TRACE, "my span", foo = 2, bar = _); +// /// my_span.record("bar", &7); +// /// # } +// /// ``` +// /// +/// The `?` sigil is shorthand for `field::debug`: /// ``` /// # #[macro_use] /// # extern crate tokio_trace; @@ -85,11 +132,11 @@ /// }; /// /// // `my_struct` will be recorded using its `fmt::Debug` implementation. -/// let my_span = span!(Level::TRACE, "my span", my_struct = ?my_struct); +/// let my_span = span!(Level::TRACE, "my span", foo = ?my_struct); /// # } /// ``` /// -/// Shorthand for `field::display`: +/// The `%` character is shorthand for `field::display`: /// ``` /// # #[macro_use] /// # extern crate tokio_trace; @@ -104,7 +151,26 @@ /// # field: "Hello world!" /// # }; /// // `my_struct.field` will be recorded using its `fmt::Display` implementation. -/// let my_span = span!(Level::TRACE, "my span", my_struct.field = %my_struct.field); +/// let my_span = span!(Level::TRACE, "my span", foo = %my_struct.field); +/// # } +/// ``` +/// +/// The `display` and `debug` sigils may also be used with local variable shorthand: +/// ``` +/// # #[macro_use] +/// # extern crate tokio_trace; +/// # use tokio_trace::Level; +/// # fn main() { +/// # #[derive(Debug)] +/// # struct MyStruct { +/// # field: &'static str, +/// # } +/// # +/// # let my_struct = MyStruct { +/// # field: "Hello world!" +/// # }; +/// // `my_struct.field` will be recorded using its `fmt::Display` implementation. +/// let my_span = span!(Level::TRACE, "my span", %my_struct.field); /// # } /// ``` /// @@ -124,6 +190,7 @@ /// ); /// # } /// ``` +/// [struct initializers]: https://doc.rust-lang.org/book/ch05-01-defining-structs.html#using-the-field-init-shorthand-when-variables-and-fields-have-the-same-name #[macro_export(local_inner_macros)] macro_rules! span { ($lvl:expr, target: $target:expr, parent: $parent:expr, $name:expr) => { @@ -310,7 +377,7 @@ macro_rules! trace_span { macro_rules! debug_span { (target: $target:expr, parent: $parent:expr, $name:expr, $($field:tt)*) => { span!( - $crate::Level::DEBUG, + $crate::Level::INFO, target: $target, parent: $parent, $name, @@ -322,7 +389,7 @@ macro_rules! debug_span { }; (parent: $parent:expr, $name:expr, $($field:tt)*) => { span!( - $crate::Level::DEBUG, + $crate::Level::INFO, target: __tokio_trace_module_path!(), $name, $($field)* @@ -333,7 +400,7 @@ macro_rules! debug_span { }; (target: $target:expr, $name:expr, $($field:tt)*) => { span!( - $crate::Level::DEBUG, + $crate::Level::INFO, target: $target, $name, $($field)* @@ -344,7 +411,7 @@ macro_rules! debug_span { }; ($name:expr, $($field:tt)*) => { span!( - $crate::Level::DEBUG, + $crate::Level::INFO, target: __tokio_trace_module_path!(), $name, $($field)* @@ -569,10 +636,9 @@ macro_rules! error_span { /// ```rust,compile_fail /// # #[macro_use] /// # extern crate tokio_trace; -/// use tokio_trace::{Level, field}; -/// +/// # use tokio_trace::Level; /// # fn main() { -/// event!(Level::Info, foo = 5, bad_field, bar = field::display("hello")) +/// event!(Level::Info, foo = 5, bad_field, bar = "hello") /// #} /// ``` /// Shorthand for `field::debug`: @@ -686,11 +752,46 @@ macro_rules! event { { message = __tokio_trace_format_args!($($arg)+), $($fields)* } ) ); - ( $lvl:expr, $($k:ident).+ = $($fields:tt)+) => ( + ($lvl:expr, $($k:ident).+ = $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), $lvl, - { $($k).+ = $($fields)+ } + { $($k).+ = $($field)*} + ) + ); + ($lvl:expr, ?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + { ?$($k).+ = $($field)*} + ) + ); + ($lvl:expr, %$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + { %$($k).+ = $($field)*} + ) + ); + ($lvl:expr, $($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + { $($k).+, $($field)*} + ) + ); + ($lvl:expr, ?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + { ?$($k).+, $($field)*} + ) + ); + ($lvl:expr, %$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $lvl, + { %$($k).+, $($field)*} ) ); ( $lvl:expr, $($arg:tt)+ ) => ( @@ -737,25 +838,66 @@ macro_rules! trace { (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( event!(target: $target, $crate::Level::TRACE, { $($field)* }, $($arg)*) ); - (target: $target:expr, $($k:ident).+ = $($field:tt)+ ) => ( - event!(target: $target, $crate::Level::TRACE, { $($k).+ = $($field)+ }) + (target: $target:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::TRACE, { $($k).+ $($field)+ }) + ); + (target: $target:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::TRACE, { $($k).+ $($field)+ }) + ); + (target: $target:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::TRACE, { $($k).+ $($field)+ }) ); (target: $target:expr, $($arg:tt)+ ) => ( event!(target: $target, $crate::Level::TRACE, {}, $($arg)+) ); - ({ $($k:ident).+ = $($field:tt)+ }, $($arg:tt)+ ) => ( + ({ $($field:tt)+ }, $($arg:tt)+ ) => ( event!( target: __tokio_trace_module_path!(), $crate::Level::TRACE, - { $($k).+ = $($field)+ }, + { $($field)+ }, $($arg)+ ) ); - ($($k:ident).+ = $($field:tt)+) => ( + ($($k:ident).+ = $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), $crate::Level::TRACE, - { $($k).+ = $($field)+} + { $($k).+ = $($field)*} + ) + ); + (?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + { ?$($k).+ = $($field)*} + ) + ); + (%$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + { %$($k).+ = $($field)*} + ) + ); + ($($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + { $($k).+, $($field)*} + ) + ); + (?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + { ?$($k).+, $($field)*} + ) + ); + (%$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::TRACE, + { %$($k).+, $($field)*} ) ); ($($arg:tt)+) => ( @@ -785,40 +927,81 @@ macro_rules! trace { /// /// let pos = Position { x: 3.234, y: -1.223 }; /// -/// debug!(x = field::debug(pos.x), y = field::debug(pos.y)); -/// debug!(target: "app_events", { position = field::debug(&pos) }, "New position"); +/// debug!(?pos.x, ?pos.y); +/// debug!(target: "app_events", { position = ?pos }, "New position"); /// # } /// ``` #[macro_export(local_inner_macros)] macro_rules! debug { (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( - event!(target: $target, $crate::Level::DEBUG, { $($field)* }, $($arg)*) + event!(target: $target, $crate::Level::INFO, { $($field)* }, $($arg)*) ); - (target: $target:expr, $($k:ident).+ = $($field:tt)+ ) => ( - event!(target: $target, $crate::Level::DEBUG, { $($k).+ = $($field)+ }) + (target: $target:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, { $($k).+ $($field)+ }) + ); + (target: $target:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, { $($k).+ $($field)+ }) + ); + (target: $target:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, { $($k).+ $($field)+ }) ); (target: $target:expr, $($arg:tt)+ ) => ( - event!(target: $target, $crate::Level::DEBUG, {}, $($arg)+) + event!(target: $target, $crate::Level::INFO, {}, $($arg)+) ); - ({ $($k:ident).+ = $($field:tt)+ }, $($arg:tt)+ ) => ( + ({ $($field:tt)+ }, $($arg:tt)+ ) => ( event!( target: __tokio_trace_module_path!(), - $crate::Level::DEBUG, - { $($k).+ = $($field)+ }, + $crate::Level::INFO, + { $($field)+ }, $($arg)+ ) ); - ($($k:ident).+ = $($field:tt)+) => ( + ($($k:ident).+ = $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), - $crate::Level::DEBUG, - { $($k).+ = $($field)+} + $crate::Level::INFO, + { $($k).+ = $($field)*} + ) + ); + (?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { ?$($k).+ = $($field)*} + ) + ); + (%$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { %$($k).+ = $($field)*} + ) + ); + ($($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { $($k).+, $($field)*} + ) + ); + (?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { ?$($k).+, $($field)*} + ) + ); + (%$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { %$($k).+, $($field)*} ) ); ($($arg:tt)+) => ( event!( target: __tokio_trace_module_path!(), - $crate::Level::DEBUG, + $crate::Level::INFO, {}, $($arg)+ ) @@ -842,14 +1025,14 @@ macro_rules! debug { /// use tokio_trace::field; /// /// let addr = Ipv4Addr::new(127, 0, 0, 1); -/// let conn_info = Connection { port: 40, speed: 3.20 }; +/// let conn = Connection { port: 40, speed: 3.20 }; /// -/// info!({ port = conn_info.port }, "connected to {}", addr); +/// info!({ port = conn.port }, "connected to {}", addr); /// info!( /// target: "connection_events", -/// ip = field::display(addr), -/// port = conn_info.port, -/// speed = field::debug(conn_info.speed) +/// ip = %addr, +/// conn.port, +/// ?conn.speed, /// ); /// # } /// ``` @@ -858,25 +1041,66 @@ macro_rules! info { (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( event!(target: $target, $crate::Level::INFO, { $($field)* }, $($arg)*) ); - (target: $target:expr, $($k:ident).+ = $($field:tt)+ ) => ( - event!(target: $target, $crate::Level::INFO, { $($k).+ = $($field)+ }) + (target: $target:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, { $($k).+ $($field)+ }) + ); + (target: $target:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, { $($k).+ $($field)+ }) + ); + (target: $target:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::INFO, { $($k).+ $($field)+ }) ); (target: $target:expr, $($arg:tt)+ ) => ( event!(target: $target, $crate::Level::INFO, {}, $($arg)+) ); - ({ $($k:ident).+ = $($field:tt)+ }, $($arg:tt)+ ) => ( + ({ $($field:tt)+ }, $($arg:tt)+ ) => ( event!( target: __tokio_trace_module_path!(), $crate::Level::INFO, - { $($k).+ = $($field)+ }, + { $($field)+ }, $($arg)+ ) ); - ($($k:ident).+ = $($field:tt)+) => ( + ($($k:ident).+ = $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), $crate::Level::INFO, - { $($k).+ = $($field)+} + { $($k).+ = $($field)*} + ) + ); + (?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { ?$($k).+ = $($field)*} + ) + ); + (%$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { %$($k).+ = $($field)*} + ) + ); + ($($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { $($k).+, $($field)*} + ) + ); + (?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { ?$($k).+, $($field)*} + ) + ); + (%$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::INFO, + { %$($k).+, $($field)*} ) ); ($($arg:tt)+) => ( @@ -916,28 +1140,69 @@ macro_rules! info { /// ``` #[macro_export(local_inner_macros)] macro_rules! warn { - (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( + (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( event!(target: $target, $crate::Level::WARN, { $($field)* }, $($arg)*) ); - (target: $target:expr, $($k:ident).+ = $($field:tt)+ ) => ( - event!(target: $target, $crate::Level::WARN, { $($k).+ = $($field)+ }) + (target: $target:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::WARN, { $($k).+ $($field)+ }) + ); + (target: $target:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::WARN, { $($k).+ $($field)+ }) + ); + (target: $target:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::WARN, { $($k).+ $($field)+ }) ); (target: $target:expr, $($arg:tt)+ ) => ( event!(target: $target, $crate::Level::WARN, {}, $($arg)+) ); - ({ $($k:ident).+ = $($field:tt)+ }, $($arg:tt)+ ) => ( + ({ $($field:tt)+ }, $($arg:tt)+ ) => ( event!( target: __tokio_trace_module_path!(), $crate::Level::WARN, - { $($k).+ = $($field)+ }, + { $($field)+ }, $($arg)+ ) ); - ($($k:ident).+ = $($field:tt)+) => ( + ($($k:ident).+ = $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), $crate::Level::WARN, - { $($k).+ = $($field)+} + { $($k).+ = $($field)*} + ) + ); + (?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + { ?$($k).+ = $($field)*} + ) + ); + (%$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + { %$($k).+ = $($field)*} + ) + ); + ($($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + { $($k).+, $($field)*} + ) + ); + (?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + { ?$($k).+, $($field)*} + ) + ); + (%$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::WARN, + { %$($k).+, $($field)*} ) ); ($($arg:tt)+) => ( @@ -975,25 +1240,66 @@ macro_rules! error { (target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => ( event!(target: $target, $crate::Level::ERROR, { $($field)* }, $($arg)*) ); - (target: $target:expr, $($k:ident).+ = $($field:tt)+ ) => ( - event!(target: $target, $crate::Level::ERROR, { $($k).+ = $($field)+ }) + (target: $target:expr, $($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::ERROR, { $($k).+ $($field)+ }) + ); + (target: $target:expr, ?$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::ERROR, { $($k).+ $($field)+ }) + ); + (target: $target:expr, %$($k:ident).+ $($field:tt)+ ) => ( + event!(target: $target, $crate::Level::ERROR, { $($k).+ $($field)+ }) ); (target: $target:expr, $($arg:tt)+ ) => ( event!(target: $target, $crate::Level::ERROR, {}, $($arg)+) ); - ({ $($k:ident).+ = $($field:tt)+ }, $($arg:tt)+ ) => ( + ({ $($field:tt)+ }, $($arg:tt)+ ) => ( event!( target: __tokio_trace_module_path!(), $crate::Level::ERROR, - { $($k).+ = $($field)+ }, + { $($field)+ }, $($arg)+ ) ); - ($($k:ident).+ = $($field:tt)+) => ( + ($($k:ident).+ = $($field:tt)*) => ( event!( target: __tokio_trace_module_path!(), $crate::Level::ERROR, - { $($k).+ = $($field)+} + { $($k).+ = $($field)*} + ) + ); + (?$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + { ?$($k).+ = $($field)*} + ) + ); + (%$($k:ident).+ = $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + { %$($k).+ = $($field)*} + ) + ); + ($($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + { $($k).+, $($field)*} + ) + ); + (?$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + { ?$($k).+, $($field)*} + ) + ); + (%$($k:ident).+, $($field:tt)*) => ( + event!( + target: __tokio_trace_module_path!(), + $crate::Level::ERROR, + { %$($k).+, $($field)*} ) ); ($($arg:tt)+) => ( @@ -1119,6 +1425,12 @@ macro_rules! valueset { }; // === recursive case (more tts), non-empty out set === + + // TODO(#1138): determine a new syntax for uninitialized span fields, and + // re-enable this. + // (@{ $($out:expr),+ }, $next:expr, $($k:ident).+ = _, $($rest:tt)*) => { + // valueset!(@ { $($out),+, (&$next, None) }, $next, $($rest)*) + // }; (@ { $($out:expr),+ }, $next:expr, $($k:ident).+ = ?$val:expr, $($rest:tt)*) => { valueset!( @ { $($out),+, (&$next, Some(&debug(&$val) as &Value)) }, @@ -1140,11 +1452,35 @@ macro_rules! valueset { $($rest)* ) }; - (@{ $($out:expr),+ }, $next:expr, $($k:ident).+, $($rest:tt)*) => { - valueset!(@ { $($out),+, (&$next, None) }, $next, $($rest)*) + (@ { $($out:expr),+ }, $next:expr, $($k:ident).+, $($rest:tt)*) => { + valueset!( + @ { $($out),+, (&$next, Some(&$($k).+ as &Value)) }, + $next, + $($rest)* + ) + }; + (@ { $($out:expr),+ }, $next:expr, ?$($k:ident).+, $($rest:tt)*) => { + valueset!( + @ { $($out),+, (&$next, Some(&debug(&$($k).+) as &Value)) }, + $next, + $($rest)* + ) + }; + (@ { $($out:expr),+ }, $next:expr, %$($k:ident).+, $($rest:tt)*) => { + valueset!( + @ { $($out),+, (&$next, Some(&display(&$($k).+) as &Value)) }, + $next, + $($rest)* + ) }; // == recursive case (more tts), empty out set === + + // TODO(#1138): determine a new syntax for uninitialized span fields, and + // re-enable this. + // (@ { }, $next:expr, $($k:ident).+ = _, $($rest:tt)* ) => { + // valueset!(@ { (&$next, None) }, $next, $($rest)* ) + // }; (@ { }, $next:expr, $($k:ident).+ = ?$val:expr, $($rest:tt)* ) => { valueset!(@ { (&$next, Some(&debug(&$val) as &Value)) }, $next, $($rest)* ) }; @@ -1155,7 +1491,13 @@ macro_rules! valueset { valueset!(@ { (&$next, Some(&$val as &Value)) }, $next, $($rest)*) }; (@ { }, $next:expr, $($k:ident).+, $($rest:tt)*) => { - valueset!(@ { (&$next, None) }, $next, $($rest)* ) + valueset!(@ { (&$next, Some(&$($k).+ as &Value)) }, $next, $($rest)* ) + }; + (@ { }, $next:expr, ?$($k:ident).+, $($rest:tt)*) => { + valueset!(@ { (&$next, Some(&debug(&$($k).+) as &Value)) }, $next, $($rest)* ) + }; + (@ { }, $next:expr, %$($k:ident).+, $($rest:tt)*) => { + valueset!(@ { (&$next, Some(&display(&$($k).+) as &Value)) }, $next, $($rest)* ) }; // === entry === @@ -1187,7 +1529,7 @@ macro_rules! fieldset { }; // == empty out set, remaining tts == - (@ { } $($k:ident).+ = ?$_val:expr, $($rest:tt)*) => { + (@ { } $($k:ident).+ = ?$val:expr, $($rest:tt)*) => { fieldset!(@ { __tokio_trace_stringify!($($k).+) } $($rest)*) }; (@ { } $($k:ident).+ = %$val:expr, $($rest:tt)*) => { @@ -1196,10 +1538,22 @@ macro_rules! fieldset { (@ { } $($k:ident).+ = $val:expr, $($rest:tt)*) => { fieldset!(@ { __tokio_trace_stringify!($($k).+) } $($rest)*) }; + // TODO(#1138): determine a new syntax for uninitialized span fields, and + // re-enable this. + // (@ { } $($k:ident).+ = _, $($rest:tt)*) => { + // fieldset!(@ { __tokio_trace_stringify!($($k).+) } $($rest)*) + // }; + (@ { } ?$($k:ident).+, $($rest:tt)*) => { + fieldset!(@ { __tokio_trace_stringify!($($k).+) } $($rest)*) + }; + (@ { } %$($k:ident).+, $($rest:tt)*) => { + fieldset!(@ { __tokio_trace_stringify!($($k).+) } $($rest)*) + }; (@ { } $($k:ident).+, $($rest:tt)*) => { fieldset!(@ { __tokio_trace_stringify!($($k).+) } $($rest)*) }; + // == non-empty out set, remaining tts == (@ { $($out:expr),+ } $($k:ident).+ = ?$val:expr, $($rest:tt)*) => { fieldset!(@ { $($out),+,__tokio_trace_stringify!($($k).+) } $($rest)*) @@ -1210,6 +1564,17 @@ macro_rules! fieldset { (@ { $($out:expr),+ } $($k:ident).+ = $val:expr, $($rest:tt)*) => { fieldset!(@ { $($out),+, __tokio_trace_stringify!($($k).+) } $($rest)*) }; + // TODO(#1138): determine a new syntax for uninitialized span fields, and + // re-enable this. + // (@ { $($out:expr),+ } $($k:ident).+ = _, $($rest:tt)*) => { + // fieldset!(@ { $($out),+, __tokio_trace_stringify!($($k).+) } $($rest)*) + // }; + (@ { $($out:expr),+ } ?$($k:ident).+, $($rest:tt)*) => { + fieldset!(@ { $($out),+, __tokio_trace_stringify!($($k).+) } $($rest)*) + }; + (@ { $($out:expr),+ } %$($k:ident).+, $($rest:tt)*) => { + fieldset!(@ { $($out),+, __tokio_trace_stringify!($($k).+) } $($rest)*) + }; (@ { $($out:expr),+ } $($k:ident).+, $($rest:tt)*) => { fieldset!(@ { $($out),+, __tokio_trace_stringify!($($k).+) } $($rest)*) }; @@ -1288,7 +1653,7 @@ macro_rules! level_to_log { $crate::Level::ERROR => $crate::log::Level::Error, $crate::Level::WARN => $crate::log::Level::Warn, $crate::Level::INFO => $crate::log::Level::Info, - $crate::Level::DEBUG => $crate::log::Level::Debug, + $crate::Level::INFO => $crate::log::Level::Debug, _ => $crate::log::Level::Trace, } }; 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 93cf9ab61..61134dc21 100644 --- a/tokio-trace/test-log-support/tests/log_no_trace.rs +++ b/tokio-trace/test-log-support/tests/log_no_trace.rs @@ -42,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!(Level::TRACE, "foo"); + let foo = span!(Level::TRACE, "foo"); last(&a, "foo;"); foo.in_scope(|| { last(&a, "-> foo"); @@ -55,11 +55,13 @@ fn test_always_log() { span!(Level::TRACE, "foo", bar = 3, baz = false); last(&a, "foo; bar=3 baz=false"); - let mut span = span!(Level::TRACE, "foo", bar, baz); - span.record("bar", &3); - last(&a, "foo; bar=3"); - span.record("baz", &"a string"); - last(&a, "foo; baz=\"a string\""); + // TODO(#1138): determine a new syntax for uninitialized span fields, and + // re-enable these. + // let span = span!(Level::TRACE, "foo", bar = _, baz = _); + // span.record("bar", &3); + // last(&a, "foo; bar=3"); + // span.record("baz", &"a string"); + // last(&a, "foo; baz=\"a string\""); } fn last(state: &State, expected: &str) { diff --git a/tokio-trace/tests/macros.rs b/tokio-trace/tests/macros.rs index 73cfb0d0a..886319800 100644 --- a/tokio-trace/tests/macros.rs +++ b/tokio-trace/tests/macros.rs @@ -394,6 +394,26 @@ fn error() { error!(target: "foo_events", { foo = 2, bar.baz = 78, }, "quux"); } +#[test] +fn field_shorthand_only() { + #[derive(Debug)] + struct Position { + x: f32, + y: f32, + } + let pos = Position { + x: 3.234, + y: -1.223, + }; + + trace!(?pos.x, ?pos.y); + debug!(?pos.x, ?pos.y); + info!(?pos.x, ?pos.y); + warn!(?pos.x, ?pos.y); + error!(?pos.x, ?pos.y); + event!(Level::TRACE, ?pos.x, ?pos.y); +} + #[test] fn callsite_macro_api() { // This test should catch any inadvertant breaking changes diff --git a/tokio-trace/tests/span.rs b/tokio-trace/tests/span.rs index aedba833c..514213270 100644 --- a/tokio-trace/tests/span.rs +++ b/tokio-trace/tests/span.rs @@ -391,13 +391,17 @@ fn move_field_out_of_struct() { handle.assert_finished(); } +// TODO(#1138): determine a new syntax for uninitialized span fields, and +// re-enable these. +/* #[test] fn add_field_after_new_span() { let (subscriber, handle) = subscriber::mock() .new_span( span::mock() .named("foo") - .with_field(field::mock("bar").with_value(&5).only()), + .with_field(field::mock("bar").with_value(&5) + .and(field::mock("baz").with_value).only()), ) .record( span::mock().named("foo"), @@ -410,7 +414,7 @@ fn add_field_after_new_span() { .run_with_handle(); with_default(subscriber, || { - let span = span!(Level::TRACE, "foo", bar = 5, baz); + let span = span!(Level::TRACE, "foo", bar = 5, baz = false); span.record("baz", &true); span.in_scope(|| {}) }); @@ -437,7 +441,73 @@ fn add_fields_only_after_new_span() { .run_with_handle(); with_default(subscriber, || { - let span = span!(Level::TRACE, "foo", bar, baz); + let span = span!(Level::TRACE, "foo", bar = _, baz = _); + span.record("bar", &5); + span.record("baz", &true); + span.in_scope(|| {}) + }); + + handle.assert_finished(); +} +*/ + +#[test] +fn record_new_value_for_field() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("foo").with_field( + field::mock("bar") + .with_value(&5) + .and(field::mock("baz").with_value(&false)) + .only(), + ), + ) + .record( + span::mock().named("foo"), + field::mock("baz").with_value(&true).only(), + ) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let span = span!(Level::TRACE, "foo", bar = 5, baz = false); + span.record("baz", &true); + span.in_scope(|| {}) + }); + + handle.assert_finished(); +} + +#[test] +fn record_new_values_for_fields() { + let (subscriber, handle) = subscriber::mock() + .new_span( + span::mock().named("foo").with_field( + field::mock("bar") + .with_value(&4) + .and(field::mock("baz").with_value(&false)) + .only(), + ), + ) + .record( + span::mock().named("foo"), + field::mock("bar").with_value(&5).only(), + ) + .record( + span::mock().named("foo"), + field::mock("baz").with_value(&true).only(), + ) + .enter(span::mock().named("foo")) + .exit(span::mock().named("foo")) + .drop_span(span::mock().named("foo")) + .done() + .run_with_handle(); + + with_default(subscriber, || { + let span = span!(Level::TRACE, "foo", bar = 4, baz = false); span.record("bar", &5); span.record("baz", &true); span.in_scope(|| {})