Skip to content

Commit 533f768

Browse files
hdshds
committed
tracing: support bare display and debug in macros
The `valueset!` macro imports `display`, `debug` and `Value` from `tracing::field`. This is unhygienic in that tracing macros that use `valueset!` (all the event and span macros) cannot use any symbols named `display` or `debug` when defining fields inside the macro. A side affect of this is that these three symbols can be used unqualified within the definition of fields within the tracing macros. So the following is valid: ```rust tracing::error!(foo = display("foo")); tracing::error!(quux = debug(4_u8 as u64)); tracing::error!(bar = &num as &dyn Value); ``` As per [Hyrum's Law], this behavior depended on by plenty of users and has been for years. At least 2 attempts have been made to clean this up, but they've had to be reverted as it is effectively a breaking change (see #820 and #3424 for details). [Hyrum's Law]: https://www.hyrumslaw.com/ To partially resolve this situation, this change adds support for `display` and `debug` patterns to the `valueset!` macro explicitly. As such, the use of `display(expr)`, `display(ident)` and the same for `debug` are matched in the patterns the same way that the `%` and `?` sigils already are. These patterns then get expanded the same way that the sigils do, into the fully qualified path to the appropriate function. As the use of bare `display` and `debug` are now caught by the macro, we can safely remove the import of those 2 symbols. This still leaves the import of `$crate::field::Value`, but I don't know if that's avoidable, and has also proved to be less problematic as it's a type and less likely to clash to the use of variables. However, we still don't want to break user code by removing it. The bare `display` and `debug` also continue to work with the `#[instrument]` attribute macro: ```rust #[tracing::instrument(fields(foo = debug(Some(5))))] fn foo() {} ``` Fairly extensive tests have been added to cover all the cases that the macros support (which are all the cases that could be thought up). This means that we can support all previously valid macro invocations, but we can also support the following, which didn't work before: ```rust let display = "display"; let debug = "debug"; tracing::error!("{debug:?} {display}"); ``` This change deliberately doesn't add support for wrapping an identifier in `debug` or `display` with no key. This isn't supported now and there is no need to support it when the sigils are available. That is to say that the following didn't compile before and will continue not to compile: ```rust tracing::error!(display(disp)); tracing::error!(debug(deb)); ``` To make this clear, UI tests have been added for the compilation error.
1 parent 7c44f7b commit 533f768

File tree

9 files changed

+296
-7
lines changed

9 files changed

+296
-7
lines changed

‎tracing-attributes/tests/fields.rs‎

Lines changed: 73 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -77,6 +77,33 @@ impl HasField {
7777
fn self_expr_field(&self) {}
7878
}
7979

80+
struct Disp {
81+
bar: u64,
82+
}
83+
84+
impl ::std::fmt::Display for Disp {
85+
fn fmt(&self, f: &mut ::std::fmt::Formatter<'_>) -> ::std::fmt::Result {
86+
::std::write!(f, "Disp.bar={bar}", bar = self.bar)
87+
}
88+
}
89+
90+
#[derive(Debug)]
91+
struct Deb {
92+
_val: u64,
93+
}
94+
95+
#[instrument(fields(foo = display(Disp { bar: 6, })))]
96+
fn fn_bare_display() {}
97+
98+
#[instrument(skip_all, fields(foo = display(param)))]
99+
fn fn_bare_display_param(param: Disp) {}
100+
101+
#[instrument(fields(foo = debug(Deb { _val: 100, })))]
102+
fn fn_bare_debug() {}
103+
104+
#[instrument(skip_all, fields(foo = debug(param)))]
105+
fn fn_bare_debug_param(param: Deb) {}
106+
80107
#[test]
81108
fn fields() {
82109
let span = expect::span().with_fields(
@@ -236,6 +263,52 @@ fn clashy_const_field_name() {
236263
});
237264
}
238265

266+
#[test]
267+
fn bare_display() {
268+
use tracing::field::display;
269+
270+
let span = expect::span().with_fields(expect::field("foo").with_value(&display("Disp.bar=6")));
271+
272+
run_test(span, || {
273+
fn_bare_display();
274+
});
275+
}
276+
277+
#[test]
278+
fn bare_display_param() {
279+
use tracing::field::display;
280+
281+
let span = expect::span().with_fields(expect::field("foo").with_value(&display("Disp.bar=6")));
282+
283+
run_test(span, || {
284+
fn_bare_display_param(Disp { bar: 6 });
285+
});
286+
}
287+
288+
#[test]
289+
fn bare_debug() {
290+
use tracing::field::debug;
291+
292+
let span =
293+
expect::span().with_fields(expect::field("foo").with_value(&debug(Deb { _val: 100 })));
294+
295+
run_test(span, || {
296+
fn_bare_debug();
297+
});
298+
}
299+
300+
#[test]
301+
fn bare_debug_param() {
302+
use tracing::field::debug;
303+
304+
let span =
305+
expect::span().with_fields(expect::field("foo").with_value(&debug(Deb { _val: 100 })));
306+
307+
run_test(span, || {
308+
fn_bare_debug_param(Deb { _val: 100 });
309+
});
310+
}
311+
239312
fn run_test<F: FnOnce() -> T, T>(span: NewSpan, fun: F) {
240313
let (subscriber, handle) = subscriber::mock()
241314
.new_span(span)

‎tracing/Cargo.toml‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,8 @@ criterion = { version = "0.3.6", default-features = false }
3535
futures = { version = "0.3.21", default-features = false }
3636
log = "0.4.17"
3737
tracing-mock = { path = "../tracing-mock" }
38+
trybuild = "1.0.64"
39+
rustversion = "1.0.9"
3840

3941
[target.'cfg(target_arch = "wasm32")'.dev-dependencies]
4042
wasm-bindgen-test = "0.3.38"

‎tracing/src/macros.rs‎

Lines changed: 76 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -2831,12 +2831,24 @@ macro_rules! valueset {
28312831
$($rest)*
28322832
)
28332833
};
2834+
(@ { $(,)* $($out:expr),* }, $($k:ident).+ = debug($val:expr), $($rest:tt)*) => {
2835+
$crate::valueset!(
2836+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
2837+
$($rest)*
2838+
)
2839+
};
28342840
(@ { $(,)* $($out:expr),* }, $($k:ident).+ = %$val:expr, $($rest:tt)*) => {
28352841
$crate::valueset!(
28362842
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
28372843
$($rest)*
28382844
)
28392845
};
2846+
(@ { $(,)* $($out:expr),* }, $($k:ident).+ = display($val:expr), $($rest:tt)*) => {
2847+
$crate::valueset!(
2848+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
2849+
$($rest)*
2850+
)
2851+
};
28402852
(@ { $(,)* $($out:expr),* }, $($k:ident).+ = $val:expr, $($rest:tt)*) => {
28412853
$crate::valueset!(
28422854
@ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
@@ -2866,11 +2878,21 @@ macro_rules! valueset {
28662878
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
28672879
)
28682880
};
2881+
(@ { $(,)* $($out:expr),* }, $($k:ident).+ = debug($val:expr)) => {
2882+
$crate::valueset!(
2883+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
2884+
)
2885+
};
28692886
(@ { $(,)* $($out:expr),* }, $($k:ident).+ = %$val:expr) => {
28702887
$crate::valueset!(
28712888
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
28722889
)
28732890
};
2891+
(@ { $(,)* $($out:expr),* }, $($k:ident).+ = display($val:expr)) => {
2892+
$crate::valueset!(
2893+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
2894+
)
2895+
};
28742896
(@ { $(,)* $($out:expr),* }, $($k:ident).+ = $val:expr) => {
28752897
$crate::valueset!(
28762898
@ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
@@ -2899,12 +2921,24 @@ macro_rules! valueset {
28992921
$($rest)*
29002922
)
29012923
};
2924+
(@ { $(,)* $($out:expr),* }, $k:literal = debug($val:expr), $($rest:tt)*) => {
2925+
$crate::valueset!(
2926+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
2927+
$($rest)*
2928+
)
2929+
};
29022930
(@ { $(,)* $($out:expr),* }, $k:literal = %$val:expr, $($rest:tt)*) => {
29032931
$crate::valueset!(
29042932
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
29052933
$($rest)*
29062934
)
29072935
};
2936+
(@ { $(,)* $($out:expr),* }, $k:literal = display($val:expr), $($rest:tt)*) => {
2937+
$crate::valueset!(
2938+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
2939+
$($rest)*
2940+
)
2941+
};
29082942
(@ { $(,)* $($out:expr),* }, $k:literal = $val:expr, $($rest:tt)*) => {
29092943
$crate::valueset!(
29102944
@ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
@@ -2916,11 +2950,21 @@ macro_rules! valueset {
29162950
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
29172951
)
29182952
};
2953+
(@ { $(,)* $($out:expr),* }, $k:literal = debug($val:expr)) => {
2954+
$crate::valueset!(
2955+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
2956+
)
2957+
};
29192958
(@ { $(,)* $($out:expr),* }, $k:literal = %$val:expr) => {
29202959
$crate::valueset!(
29212960
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
29222961
)
29232962
};
2963+
(@ { $(,)* $($out:expr),* }, $k:literal = display($val:expr)) => {
2964+
$crate::valueset!(
2965+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
2966+
)
2967+
};
29242968
(@ { $(,)* $($out:expr),* }, $k:literal = $val:expr) => {
29252969
$crate::valueset!(
29262970
@ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
@@ -2930,35 +2974,57 @@ macro_rules! valueset {
29302974
// Handle constant names
29312975
(@ { $(,)* $($out:expr),* }, { $k:expr } = ?$val:expr, $($rest:tt)*) => {
29322976
$crate::valueset!(
2933-
@ { $($out),*, (Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
2977+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
2978+
$($rest)*
2979+
)
2980+
};
2981+
(@ { $(,)* $($out:expr),* }, { $k:expr } = debug($val:expr), $($rest:tt)*) => {
2982+
$crate::valueset!(
2983+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
29342984
$($rest)*
29352985
)
29362986
};
29372987
(@ { $(,)* $($out:expr),* }, { $k:expr } = %$val:expr, $($rest:tt)*) => {
29382988
$crate::valueset!(
2939-
@ { $($out),*, (Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
2989+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
2990+
$($rest)*
2991+
)
2992+
};
2993+
(@ { $(,)* $($out:expr),* }, { $k:expr } = display($val:expr), $($rest:tt)*) => {
2994+
$crate::valueset!(
2995+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
29402996
$($rest)*
29412997
)
29422998
};
29432999
(@ { $(,)* $($out:expr),* }, { $k:expr } = $val:expr, $($rest:tt)*) => {
29443000
$crate::valueset!(
2945-
@ { $($out),*, (Some(&$val as &dyn $crate::field::Value)) },
3001+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
29463002
$($rest)*
29473003
)
29483004
};
29493005
(@ { $(,)* $($out:expr),* }, { $k:expr } = ?$val:expr) => {
29503006
$crate::valueset!(
2951-
@ { $($out),*, (Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
3007+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
3008+
)
3009+
};
3010+
(@ { $(,)* $($out:expr),* }, { $k:expr } = debug($val:expr)) => {
3011+
$crate::valueset!(
3012+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
29523013
)
29533014
};
29543015
(@ { $(,)* $($out:expr),* }, { $k:expr } = %$val:expr) => {
29553016
$crate::valueset!(
2956-
@ { $($out),*, (Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
3017+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
3018+
)
3019+
};
3020+
(@ { $(,)* $($out:expr),* }, { $k:expr } = display($val:expr)) => {
3021+
$crate::valueset!(
3022+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
29573023
)
29583024
};
29593025
(@ { $(,)* $($out:expr),* }, { $k:expr } = $val:expr) => {
29603026
$crate::valueset!(
2961-
@ { $($out),*, (Some(&$val as &dyn $crate::field::Value)) },
3027+
@ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
29623028
)
29633029
};
29643030

@@ -2973,7 +3039,10 @@ macro_rules! valueset {
29733039
#[allow(unused_imports)]
29743040
// This import statement CANNOT be removed as it will break existing use cases.
29753041
// See #831, #2332, #3424 for the last times we tried.
2976-
use $crate::field::{debug, display, Value};
3042+
// It previously contained `display` and `debug` as well, but those have been
3043+
// moved into the macro patterns instead, still no idea how to remove `Value`
3044+
// without breaking though.
3045+
use $crate::field::Value;
29773046
$fields.value_set_all($crate::valueset!(
29783047
@ { },
29793048
$($kvs)+

‎tracing/tests/macros.rs‎

Lines changed: 100 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,21 @@ impl ::std::fmt::Display for DisplayDebug {
2020
}
2121
}
2222

23+
struct Disp {
24+
bar: u64,
25+
}
26+
27+
impl ::std::fmt::Display for Disp {
28+
fn fmt(&self, f: &mut ::std::fmt::Formatter<'_>) -> ::std::fmt::Result {
29+
::std::write!(f, "Disp.bar={bar}", bar = self.bar)
30+
}
31+
}
32+
33+
#[derive(Debug)]
34+
struct Deb {
35+
_val: u64,
36+
}
37+
2338
// Tests that macros work across various invocation syntax.
2439
//
2540
// These are quite repetitive, and _could_ be generated by a macro. However,
@@ -1398,6 +1413,91 @@ fn borrow_val_spans() {
13981413
zero.push_str("hello world");
13991414
}
14001415

1416+
#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)]
1417+
#[test]
1418+
fn bare_display_debug() {
1419+
error!(foo = display("foo"));
1420+
error!(foo = display(Disp { bar: 4 }));
1421+
error!(quux = debug(Deb { _val: 1024 }));
1422+
error!(quux = debug(4_u8 as u64));
1423+
1424+
error!(mog = 5, foo = display("foo"));
1425+
error!(mog = 5, foo = display(Disp { bar: 4 }));
1426+
error!(mog = 5, quux = debug(Deb { _val: 1024 }));
1427+
error!(mog = 5, quux = debug(4_u8 as u64));
1428+
1429+
error!(foo = display("foo"), mog = 5);
1430+
error!(foo = display(Disp { bar: 4 }), mog = 5);
1431+
error!(quux = debug(Deb { _val: 1024 }), mog = 5);
1432+
error!(quux = debug(4_u8 as u64), mog = 5);
1433+
1434+
error!({ foo = display("foo") }, "gom = {:?}", 8);
1435+
error!({ foo = display(Disp { bar: 4 }) }, "gom = {:?}", 8);
1436+
error!({ quux = debug(Deb { _val: 1024 }) }, "gom = {:?}", 8);
1437+
error!({ quux = debug(4_u8 as u64) }, "gom = {:?}", 8);
1438+
1439+
error!("foo" = display("foo"));
1440+
error!("foo" = display(Disp { bar: 4 }));
1441+
error!("quux" = debug(Deb { _val: 1024 }));
1442+
error!("quux" = debug(4_u8 as u64));
1443+
1444+
error!(mog = 5, "foo" = display("foo"));
1445+
error!(mog = 5, "foo" = display(Disp { bar: 4 }));
1446+
error!(mog = 5, "quux" = debug(Deb { _val: 1024 }));
1447+
error!(mog = 5, "quux" = debug(4_u8 as u64));
1448+
1449+
error!("foo" = display("foo"), mog = 5);
1450+
error!("foo" = display(Disp { bar: 4 }), mog = 5);
1451+
error!("quux" = debug(Deb { _val: 1024 }), mog = 5);
1452+
error!("quux" = debug(4_u8 as u64), mog = 5);
1453+
1454+
error!({ "foo" = display("foo") }, "gom = {:?}", 8);
1455+
error!({ "foo" = display(Disp { bar: 4 }) }, "gom = {:?}", 8);
1456+
error!({ "quux" = debug(Deb { _val: 1024 }) }, "gom = {:?}", 8);
1457+
error!({ "quux" = debug(4_u8 as u64) }, "gom = {:?}", 8);
1458+
1459+
const FOO: &str = "FOO";
1460+
const QUUX: &str = "QUUX";
1461+
error!({ FOO } = display("foo"));
1462+
error!({ FOO } = display(Disp { bar: 4 }));
1463+
error!({ QUUX } = debug(Deb { _val: 1024 }));
1464+
error!({ QUUX } = debug(4_u8 as u64));
1465+
1466+
error!(mog = 5, { FOO } = display("foo"));
1467+
error!(mog = 5, { FOO } = display(Disp { bar: 4 }));
1468+
error!(mog = 5, { QUUX } = debug(Deb { _val: 1024 }));
1469+
error!(mog = 5, { QUUX } = debug(4_u8 as u64));
1470+
1471+
error!({ FOO } = display("foo"), mog = 5);
1472+
error!({ FOO } = display(Disp { bar: 4 }), mog = 5);
1473+
error!({ QUUX } = debug(Deb { _val: 1024 }), mog = 5);
1474+
error!({ QUUX } = debug(4_u8 as u64), mog = 5);
1475+
1476+
error!({ {FOO} = display("foo") }, "gom = {:?}", 8);
1477+
error!({ {FOO} = display(Disp { bar: 4, }) }, "gom = {:?}", 8);
1478+
error!({ {QUUX} = debug(Deb { _val: 1024, }) }, "gom = {:?}", 8);
1479+
error!({ {QUUX} = debug(4_u8 as u64) }, "gom = {:?}", 8);
1480+
1481+
let display = Disp { bar: 4 };
1482+
let debug = Deb { _val: 96 };
1483+
error!("{debug:?} {display}");
1484+
error!(%display, ?debug);
1485+
error!(display = %display, debug = ?debug);
1486+
1487+
let display = "str also implements Value";
1488+
let debug = "str also implements Value";
1489+
error!("{debug:?} {display}");
1490+
error!(display, debug);
1491+
error!(display = display, debug = debug);
1492+
}
1493+
1494+
#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)]
1495+
#[test]
1496+
fn bare_value() {
1497+
let num = ::std::option::Option::Some(52);
1498+
error!(bar = &num as &dyn Value);
1499+
}
1500+
14011501
#[cfg_attr(target_arch = "wasm32", wasm_bindgen_test::wasm_bindgen_test)]
14021502
#[test]
14031503
fn callsite_macro_api() {

‎tracing/tests/ui.rs‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,8 @@
1+
// Only test on stable, since UI tests are bound to change over time
2+
3+
#[rustversion::stable]
4+
#[test]
5+
fn compile_fail() {
6+
let t = trybuild::TestCases::new();
7+
t.compile_fail("tests/ui/fail/*.rs");
8+
}

‎tracing/tests/ui/fail/debug_without_key.rs‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,9 @@
1+
//! We support bare `debug` function in macros, but only when a key is
2+
//! specified (e.g. `foo = debug(foo)` is supported but just `debug(foo)`
3+
//! isn't).
4+
5+
fn main() {
6+
let foo = "foo";
7+
tracing::info!(debug(foo));
8+
}
9+

0 commit comments

Comments
 (0)