From 908cc432a5994f6e17c8f36e13c217dc40085704 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?David=20Ml=C3=A1dek?= Date: Fri, 1 Mar 2024 21:59:00 +0100 Subject: [PATCH] tracing: fix event macros with constant field names in the first position (#2883) ## Motivation Const argumetns in `level!` macros do not work when in the first position. This also seems to have fixed #2748 where literals for fields names like `info!("foo" = 2)` could not be used outside the `event!` macro. Fixes #2837 Fixes #2738 ## Solution Previsously, `level!($(args:tt))` was forwarded to `event!(target: ..., level: ..., { $(args:tt) })` but the added curly braces seem to have prevented the `event` macro from correctly understanding the arguments and it tried to pass them to `format!`. With this change there may have some performance impact when expanding the macros in most cases where the braces could have been added as it will take one more step. These are the two relevant `event!` blocks I believe, the new tests used to expand to the first one (with empty fields), now they expand to the latter: ``` (target: $target:expr, $lvl:expr, { $($fields:tt)* }, $($arg:tt)+ ) => ( $crate::event!( target: $target, $lvl, { message = $crate::__macro_support::format_args!($($arg)+), $($fields)* } ) ); (target: $target:expr, $lvl:expr, $($arg:tt)+ ) => ( $crate::event!(target: $target, $lvl, { $($arg)+ }) ); ``` --- tracing/src/macros.rs | 5 ---- tracing/tests/event.rs | 54 +++++++++++++++++++++++++++++++++++++++++ tracing/tests/macros.rs | 32 +++++++++++++++++++++++- 3 files changed, 85 insertions(+), 6 deletions(-) diff --git a/tracing/src/macros.rs b/tracing/src/macros.rs index 9f6bd7670d..5de45cb75b 100644 --- a/tracing/src/macros.rs +++ b/tracing/src/macros.rs @@ -1545,7 +1545,6 @@ macro_rules! trace { $crate::event!( target: module_path!(), $crate::Level::TRACE, - {}, $($arg)+ ) ); @@ -1822,7 +1821,6 @@ macro_rules! debug { $crate::event!( target: module_path!(), $crate::Level::DEBUG, - {}, $($arg)+ ) ); @@ -2110,7 +2108,6 @@ macro_rules! info { $crate::event!( target: module_path!(), $crate::Level::INFO, - {}, $($arg)+ ) ); @@ -2391,7 +2388,6 @@ macro_rules! warn { $crate::event!( target: module_path!(), $crate::Level::WARN, - {}, $($arg)+ ) ); @@ -2668,7 +2664,6 @@ macro_rules! error { $crate::event!( target: module_path!(), $crate::Level::ERROR, - {}, $($arg)+ ) ); diff --git a/tracing/tests/event.rs b/tracing/tests/event.rs index a370b700cd..0af0602e96 100644 --- a/tracing/tests/event.rs +++ b/tracing/tests/event.rs @@ -416,6 +416,12 @@ fn constant_field_name() { ) }; let (collector, handle) = collector::mock() + .event(expect_event()) + .event(expect_event()) + .event(expect_event()) + .event(expect_event()) + .event(expect_event()) + .event(expect_event()) .event(expect_event()) .event(expect_event()) .only() @@ -439,6 +445,54 @@ fn constant_field_name() { }, "quux" ); + tracing::info!( + { std::convert::identity(FOO) } = "bar", + { "constant string" } = "also works", + foo.bar = "baz", + "quux" + ); + tracing::info!( + { + { std::convert::identity(FOO) } = "bar", + { "constant string" } = "also works", + foo.bar = "baz", + }, + "quux" + ); + tracing::event!( + Level::INFO, + { std::convert::identity(FOO) } = "bar", + { "constant string" } = "also works", + foo.bar = "baz", + "{}", + "quux" + ); + tracing::event!( + Level::INFO, + { + { std::convert::identity(FOO) } = "bar", + { "constant string" } = "also works", + foo.bar = "baz", + }, + "{}", + "quux" + ); + tracing::info!( + { std::convert::identity(FOO) } = "bar", + { "constant string" } = "also works", + foo.bar = "baz", + "{}", + "quux" + ); + tracing::info!( + { + { std::convert::identity(FOO) } = "bar", + { "constant string" } = "also works", + foo.bar = "baz", + }, + "{}", + "quux" + ); }); handle.assert_finished(); diff --git a/tracing/tests/macros.rs b/tracing/tests/macros.rs index 8d58bf6107..a072389e24 100644 --- a/tracing/tests/macros.rs +++ b/tracing/tests/macros.rs @@ -555,12 +555,15 @@ fn trace() { trace!(foo = ?3, bar.baz = %2, quux = false); trace!(foo = 3, bar.baz = 2, quux = false); trace!(foo = 3, bar.baz = 3,); + trace!("foo" = 3, bar.baz = 3,); + trace!(foo = 3, "bar.baz" = 3,); trace!("foo"); trace!("foo: {}", 3); trace!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); trace!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); trace!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); trace!({ foo = 3, bar.baz = 80 }, "quux"); + trace!({ "foo" = 3, "bar.baz" = 80 }, "quux"); trace!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); trace!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); trace!({ foo = 2, bar.baz = 78 }, "quux"); @@ -579,6 +582,9 @@ fn trace() { trace!(?foo); trace!(%foo); trace!(foo); + trace!("foo" = ?foo); + trace!("foo" = %foo); + trace!("foo" = foo); trace!(name: "foo", ?foo); trace!(name: "foo", %foo); trace!(name: "foo", foo); @@ -615,12 +621,15 @@ fn debug() { debug!(foo = ?3, bar.baz = %2, quux = false); debug!(foo = 3, bar.baz = 2, quux = false); debug!(foo = 3, bar.baz = 3,); + debug!("foo" = 3, bar.baz = 3,); + debug!(foo = 3, "bar.baz" = 3,); debug!("foo"); debug!("foo: {}", 3); debug!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); debug!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); debug!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); debug!({ foo = 3, bar.baz = 80 }, "quux"); + debug!({ "foo" = 3, "bar.baz" = 80 }, "quux"); debug!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); debug!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); debug!({ foo = 2, bar.baz = 78 }, "quux"); @@ -639,6 +648,9 @@ fn debug() { debug!(?foo); debug!(%foo); debug!(foo); + debug!("foo" = ?foo); + debug!("foo" = %foo); + debug!("foo" = foo); debug!(name: "foo", ?foo); debug!(name: "foo", %foo); debug!(name: "foo", foo); @@ -675,12 +687,15 @@ fn info() { info!(foo = ?3, bar.baz = %2, quux = false); info!(foo = 3, bar.baz = 2, quux = false); info!(foo = 3, bar.baz = 3,); + info!("foo" = 3, bar.baz = 3,); + info!(foo = 3, "bar.baz" = 3,); info!("foo"); info!("foo: {}", 3); info!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); info!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); info!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); info!({ foo = 3, bar.baz = 80 }, "quux"); + info!({ "foo" = 3, "bar.baz" = 80 }, "quux"); info!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); info!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); info!({ foo = 2, bar.baz = 78 }, "quux"); @@ -699,6 +714,9 @@ fn info() { info!(?foo); info!(%foo); info!(foo); + info!("foo" = ?foo); + info!("foo" = %foo); + info!("foo" = foo); info!(name: "foo", ?foo); info!(name: "foo", %foo); info!(name: "foo", foo); @@ -735,12 +753,15 @@ fn warn() { warn!(foo = ?3, bar.baz = %2, quux = false); warn!(foo = 3, bar.baz = 2, quux = false); warn!(foo = 3, bar.baz = 3,); + warn!("foo" = 3, bar.baz = 3,); + warn!(foo = 3, "bar.baz" = 3,); warn!("foo"); warn!("foo: {}", 3); warn!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); warn!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); warn!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); warn!({ foo = 3, bar.baz = 80 }, "quux"); + warn!({ "foo" = 3, "bar.baz" = 80 }, "quux"); warn!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); warn!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); warn!({ foo = 2, bar.baz = 78 }, "quux"); @@ -759,6 +780,9 @@ fn warn() { warn!(?foo); warn!(%foo); warn!(foo); + warn!("foo" = ?foo); + warn!("foo" = %foo); + warn!("foo" = foo); warn!(name: "foo", ?foo); warn!(name: "foo", %foo); warn!(name: "foo", foo); @@ -795,15 +819,18 @@ fn error() { error!(foo = ?3, bar.baz = %2, quux = false); error!(foo = 3, bar.baz = 2, quux = false); error!(foo = 3, bar.baz = 3,); + error!("foo" = 3, bar.baz = 3,); + error!(foo = 3, "bar.baz" = 3,); error!("foo"); error!("foo: {}", 3); error!(foo = ?3, bar.baz = %2, quux = false, "hello world {:?}", 42); error!(foo = 3, bar.baz = 2, quux = false, "hello world {:?}", 42); error!(foo = 3, bar.baz = 3, "hello world {:?}", 42,); error!({ foo = 3, bar.baz = 80 }, "quux"); + error!({ "foo" = 3, "bar.baz" = 80 }, "quux"); error!({ foo = 2, bar.baz = 79 }, "quux {:?}", true); error!({ foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false); - error!({ foo = 2, bar.baz = 78, }, "quux"); + error!({ foo = 2, bar.baz = 78 }, "quux"); error!({ foo = ?2, bar.baz = %78 }, "quux"); error!(name: "foo", foo = 3, bar.baz = 2, quux = false); error!(name: "foo", target: "foo_events", foo = 3, bar.baz = 2, quux = false); @@ -819,6 +846,9 @@ fn error() { error!(?foo); error!(%foo); error!(foo); + error!("foo" = ?foo); + error!("foo" = %foo); + error!("foo" = foo); error!(name: "foo", ?foo); error!(name: "foo", %foo); error!(name: "foo", foo);