tracing: fix event macros with constant field names in the first posi…

…tion (tokio-rs#2883)


## Motivation

Const argumetns in `level!` macros do not work when in the first
position.

This also seems to have fixed tokio-rs#2748 where literals for fields names like
`info!("foo" = 2)` could not be used outside the `event!` macro.


Fixes tokio-rs#2837
Fixes tokio-rs#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

@@ -1547,7 +1547,6 @@ macro_rules! trace {
         $crate::event!(
             target: module_path!(),
             $crate::Level::TRACE,
-            {},
             $($arg)+
         )
     );
@@ -1824,7 +1823,6 @@ macro_rules! debug {
         $crate::event!(
             target: module_path!(),
             $crate::Level::DEBUG,
-            {},
             $($arg)+
         )
     );
@@ -2112,7 +2110,6 @@ macro_rules! info {
         $crate::event!(
             target: module_path!(),
             $crate::Level::INFO,
-            {},
             $($arg)+
         )
     );
@@ -2393,7 +2390,6 @@ macro_rules! warn {
         $crate::event!(
             target: module_path!(),
             $crate::Level::WARN,
-            {},
             $($arg)+
         )
     );
@@ -2670,7 +2666,6 @@ macro_rules! error {
         $crate::event!(
             target: module_path!(),
             $crate::Level::ERROR,
-            {},
             $($arg)+
         )
     );

tracing/tests/event.rs

@@ -525,6 +525,12 @@ fn constant_field_name() {
         )
     };
     let (subscriber, handle) = subscriber::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()
@@ -548,6 +554,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();

tracing/tests/macros.rs

@@ -545,12 +545,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");
@@ -569,6 +572,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);
@@ -589,12 +595,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");
@@ -613,6 +622,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);
@@ -633,12 +645,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");
@@ -657,6 +672,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);
@@ -677,12 +695,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");
@@ -701,6 +722,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);
@@ -721,15 +745,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);
@@ -745,6 +772,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);