tracing: use full path when calling format_args! (#2757)

When a custom macro "format_args" is defined, macros such as `tracing::warn`, `tracing::debug`, etc. will fail. Adding the full path `::core::format_args!` to the calls fixes this. Fixes: #2721
tokio-rs · Oct 13, 2023 · b16965b · b16965b
1 parent 2297580
commit b16965b
Show file tree

Hide file tree

Showing 2 changed files with 141 additions and 28 deletions.
diff --git a/tracing/src/macros.rs b/tracing/src/macros.rs
@@ -628,7 +628,7 @@ macro_rules! event {
             target: $target,
             parent: $parent,
             $lvl,
-            { message = format_args!($($arg)+), $($fields)* }
+            { message = ::core::format_args!($($arg)+), $($fields)* }
         )
     );
     (name: $name:expr, target: $target:expr, parent: $parent:expr, $lvl:expr, $($k:ident).+ = $($fields:tt)* ) => (
@@ -679,7 +679,7 @@ macro_rules! event {
             name: $name,
             target: $target,
             $lvl,
-            { message = format_args!($($arg)+), $($fields)* }
+            { message = ::core::format_args!($($arg)+), $($fields)* }
         )
     );
     (name: $name:expr, target: $target:expr, $lvl:expr, $($k:ident).+ = $($fields:tt)* ) => (
@@ -737,7 +737,7 @@ macro_rules! event {
             target: $target,
             parent: $parent,
             $lvl,
-            { message = format_args!($($arg)+), $($fields)* }
+            { message = ::core::format_args!($($arg)+), $($fields)* }
         )
     );
     (target: $target:expr, parent: $parent:expr, $lvl:expr, $($k:ident).+ = $($fields:tt)* ) => (
@@ -790,7 +790,7 @@ macro_rules! event {
             name: $name,
             parent: $parent,
             $lvl,
-            { message = format_args!($($arg)+), $($fields)* }
+            { message = ::core::format_args!($($arg)+), $($fields)* }
         )
     );
     (name: $name:expr, parent: $parent:expr, $lvl:expr, $($k:ident).+ = $($fields:tt)* ) => (
@@ -840,7 +840,7 @@ macro_rules! event {
         $crate::event!(
             name: $name,
             $lvl,
-            { message = format_args!($($arg)+), $($fields)* }
+            { message = ::core::format_args!($($arg)+), $($fields)* }
         )
     );
     (name: $name:expr, $lvl:expr, $($k:ident).+ = $($fields:tt)* ) => (
@@ -895,7 +895,7 @@ macro_rules! event {
         $crate::event!(
             target: $target,
             $lvl,
-            { message = format_args!($($arg)+), $($fields)* }
+            { message = ::core::format_args!($($arg)+), $($fields)* }
         )
     );
     (target: $target:expr, $lvl:expr, $($k:ident).+ = $($fields:tt)* ) => (
@@ -911,7 +911,7 @@ macro_rules! event {
             target: module_path!(),
             parent: $parent,
             $lvl,
-            { message = format_args!($($arg)+), $($fields)* }
+            { message = ::core::format_args!($($arg)+), $($fields)* }
         )
     );
     (parent: $parent:expr, $lvl:expr, $($k:ident).+ = $($field:tt)*) => (
@@ -971,7 +971,7 @@ macro_rules! event {
         $crate::event!(
             target: module_path!(),
             $lvl,
-            { message = format_args!($($arg)+), $($fields)* }
+            { message = ::core::format_args!($($arg)+), $($fields)* }
         )
     );
     ($lvl:expr, $($k:ident).+ = $($field:tt)*) => (
@@ -2966,7 +2966,7 @@ macro_rules! valueset {
 
     // Remainder is unparsable, but exists --- must be format args!
     (@ { $(,)* $($out:expr),* }, $next:expr, $($rest:tt)+) => {
-        $crate::valueset!(@ { (&$next, ::core::option::Option::Some(&format_args!($($rest)+) as &dyn Value)), $($out),* }, $next, )
+        $crate::valueset!(@ { (&$next, ::core::option::Option::Some(&::core::format_args!($($rest)+) as &dyn Value)), $($out),* }, $next, )
     };
 
     // === entry ===

diff --git a/tracing/tests/macros.rs b/tracing/tests/macros.rs
@@ -126,8 +126,20 @@ fn span_root() {
     span!(target: "foo_events", parent: ::core::option::Option::None, Level::TRACE, "foo", bar.baz = 2, quux = 4,);
     span!(target: "foo_events", parent: ::core::option::Option::None, Level::TRACE, "foo");
     span!(target: "foo_events", parent: ::core::option::Option::None, Level::TRACE, "bar",);
-    span!(parent: ::core::option::Option::None, Level::DEBUG, "foo", bar.baz = 2, quux = 3);
-    span!(parent: ::core::option::Option::None, Level::DEBUG, "foo", bar.baz = 2, quux = 4,);
+    span!(
+        parent: ::core::option::Option::None,
+        Level::DEBUG,
+        "foo",
+        bar.baz = 2,
+        quux = 3
+    );
+    span!(
+        parent: ::core::option::Option::None,
+        Level::DEBUG,
+        "foo",
+        bar.baz = 2,
+        quux = 4,
+    );
     span!(parent: ::core::option::Option::None, Level::DEBUG, "foo");
     span!(parent: ::core::option::Option::None, Level::DEBUG, "bar",);
 }
@@ -139,8 +151,18 @@ fn trace_span_root() {
     trace_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
     trace_span!(target: "foo_events", parent: ::core::option::Option::None, "foo");
     trace_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",);
-    trace_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3);
-    trace_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
+    trace_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 3
+    );
+    trace_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 4,
+    );
     trace_span!(parent: ::core::option::Option::None, "foo");
     trace_span!(parent: ::core::option::Option::None, "bar",);
 }
@@ -152,8 +174,18 @@ fn debug_span_root() {
     debug_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
     debug_span!(target: "foo_events", parent: ::core::option::Option::None, "foo");
     debug_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",);
-    debug_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3);
-    debug_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
+    debug_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 3
+    );
+    debug_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 4,
+    );
     debug_span!(parent: ::core::option::Option::None, "foo");
     debug_span!(parent: ::core::option::Option::None, "bar",);
 }
@@ -165,8 +197,18 @@ fn info_span_root() {
     info_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
     info_span!(target: "foo_events", parent: ::core::option::Option::None, "foo");
     info_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",);
-    info_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3);
-    info_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
+    info_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 3
+    );
+    info_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 4,
+    );
     info_span!(parent: ::core::option::Option::None, "foo");
     info_span!(parent: ::core::option::Option::None, "bar",);
 }
@@ -178,8 +220,18 @@ fn warn_span_root() {
     warn_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
     warn_span!(target: "foo_events", parent: ::core::option::Option::None, "foo");
     warn_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",);
-    warn_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3);
-    warn_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
+    warn_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 3
+    );
+    warn_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 4,
+    );
     warn_span!(parent: ::core::option::Option::None, "foo");
     warn_span!(parent: ::core::option::Option::None, "bar",);
 }
@@ -191,8 +243,18 @@ fn error_span_root() {
     error_span!(target: "foo_events", parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
     error_span!(target: "foo_events", parent: ::core::option::Option::None, "foo");
     error_span!(target: "foo_events", parent: ::core::option::Option::None, "bar",);
-    error_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 3);
-    error_span!(parent: ::core::option::Option::None, "foo", bar.baz = 2, quux = 4,);
+    error_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 3
+    );
+    error_span!(
+        parent: ::core::option::Option::None,
+        "foo",
+        bar.baz = 2,
+        quux = 4,
+    );
     error_span!(parent: ::core::option::Option::None, "foo");
     error_span!(parent: ::core::option::Option::None, "bar",);
 }
@@ -712,9 +774,19 @@ fn event_root() {
         bar.baz = 2,
         quux = false
     );
-    event!(parent: ::core::option::Option::None, Level::DEBUG, foo = 3, bar.baz = 3,);
+    event!(
+        parent: ::core::option::Option::None,
+        Level::DEBUG,
+        foo = 3,
+        bar.baz = 3,
+    );
     event!(parent: ::core::option::Option::None, Level::DEBUG, "foo");
-    event!(parent: ::core::option::Option::None, Level::DEBUG, "foo: {}", 3);
+    event!(
+        parent: ::core::option::Option::None,
+        Level::DEBUG,
+        "foo: {}",
+        3
+    );
     event!(parent: ::core::option::Option::None, Level::DEBUG, { foo = 3, bar.baz = 80 }, "quux");
     event!(parent: ::core::option::Option::None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}", true);
     event!(parent: ::core::option::Option::None, Level::DEBUG, { foo = 2, bar.baz = 79 }, "quux {:?}, {quux}", true, quux = false);
@@ -741,7 +813,12 @@ fn event_root() {
 #[test]
 fn trace_root() {
     trace!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false);
-    trace!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false);
+    trace!(
+        parent: ::core::option::Option::None,
+        foo = 3,
+        bar.baz = 2,
+        quux = false
+    );
     trace!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,);
     trace!(parent: ::core::option::Option::None, "foo");
     trace!(parent: ::core::option::Option::None, "foo: {}", 3);
@@ -772,7 +849,12 @@ fn trace_root() {
 #[test]
 fn debug_root() {
     debug!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false);
-    debug!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false);
+    debug!(
+        parent: ::core::option::Option::None,
+        foo = 3,
+        bar.baz = 2,
+        quux = false
+    );
     debug!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,);
     debug!(parent: ::core::option::Option::None, "foo");
     debug!(parent: ::core::option::Option::None, "foo: {}", 3);
@@ -803,7 +885,12 @@ fn debug_root() {
 #[test]
 fn info_root() {
     info!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false);
-    info!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false);
+    info!(
+        parent: ::core::option::Option::None,
+        foo = 3,
+        bar.baz = 2,
+        quux = false
+    );
     info!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,);
     info!(parent: ::core::option::Option::None, "foo");
     info!(parent: ::core::option::Option::None, "foo: {}", 3);
@@ -834,7 +921,12 @@ fn info_root() {
 #[test]
 fn warn_root() {
     warn!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false);
-    warn!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false);
+    warn!(
+        parent: ::core::option::Option::None,
+        foo = 3,
+        bar.baz = 2,
+        quux = false
+    );
     warn!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,);
     warn!(parent: ::core::option::Option::None, "foo");
     warn!(parent: ::core::option::Option::None, "foo: {}", 3);
@@ -865,7 +957,12 @@ fn warn_root() {
 #[test]
 fn error_root() {
     error!(parent: ::core::option::Option::None, foo = ?3, bar.baz = %2, quux = false);
-    error!(parent: ::core::option::Option::None, foo = 3, bar.baz = 2, quux = false);
+    error!(
+        parent: ::core::option::Option::None,
+        foo = 3,
+        bar.baz = 2,
+        quux = false
+    );
     error!(parent: ::core::option::Option::None, foo = 3, bar.baz = 3,);
     error!(parent: ::core::option::Option::None, "foo");
     error!(parent: ::core::option::Option::None, "foo: {}", 3);
@@ -1156,3 +1253,19 @@ fn callsite_macro_api() {
         fields: foo,
     };
 }
+
+#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)]
+#[test]
+fn format_args_already_defined() {
+    // Reproduces: https://github.com/tokio-rs/tracing/issues/2721
+    #[allow(unused)]
+    macro_rules! format_args {
+        ($i:expr) => {};
+    }
+    event!(Level::DEBUG, "foo: {}", 3);
+    trace!("foo: {}", 3);
+    debug!("foo: {}", 3);
+    info!("foo: {}", 3);
+    warn!("foo: {}", 3);
+    error!("foo: {}", 3);
+}