From 8e786169e8136223f6dfac7be85aff339b4cc893 Mon Sep 17 00:00:00 2001 From: Stypox Date: Wed, 30 Jul 2025 17:33:28 +0200 Subject: [PATCH 1/4] Uniform enter_trace_span! and add documentation The macro was uniformed between rustc_const_eval and miri --- .../rustc_const_eval/src/interpret/stack.rs | 4 +- .../rustc_const_eval/src/interpret/util.rs | 63 ++++++++++++++++++- src/tools/miri/src/helpers.rs | 18 +----- 3 files changed, 65 insertions(+), 20 deletions(-) diff --git a/compiler/rustc_const_eval/src/interpret/stack.rs b/compiler/rustc_const_eval/src/interpret/stack.rs index 2e99bb4209f2b..25d163bba62f4 100644 --- a/compiler/rustc_const_eval/src/interpret/stack.rs +++ b/compiler/rustc_const_eval/src/interpret/stack.rs @@ -397,9 +397,9 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { // Finish things up. M::after_stack_push(self)?; self.frame_mut().loc = Left(mir::Location::START); - // `tracing_separate_thread` is used to instruct the chrome_tracing [tracing::Layer] in Miri + // `tracing_separate_thread` is used to instruct the tracing_chrome [tracing::Layer] in Miri // to put the "frame" span on a separate trace thread/line than other spans, to make the - // visualization in https://ui.perfetto.dev easier to interpret. It is set to a value of + // visualization in easier to interpret. It is set to a value of // [tracing::field::Empty] so that other tracing layers (e.g. the logger) will ignore it. let span = info_span!("frame", tracing_separate_thread = Empty, "{}", instance); self.frame_mut().tracing_span.enter(span); diff --git a/compiler/rustc_const_eval/src/interpret/util.rs b/compiler/rustc_const_eval/src/interpret/util.rs index 72650d545c3ca..341756f837eef 100644 --- a/compiler/rustc_const_eval/src/interpret/util.rs +++ b/compiler/rustc_const_eval/src/interpret/util.rs @@ -53,13 +53,72 @@ pub trait EnteredTraceSpan {} impl EnteredTraceSpan for () {} impl EnteredTraceSpan for tracing::span::EnteredSpan {} -/// Shortand for calling [crate::interpret::Machine::enter_trace_span] on a [tracing::info_span]. +/// Shortand for calling [crate::interpret::Machine::enter_trace_span] on a [tracing::info_span!]. /// This is supposed to be compiled out when [crate::interpret::Machine::enter_trace_span] has the /// default implementation (i.e. when it does not actually enter the span but instead returns `()`). +/// This macro takes a type implementing the [crate::interpret::Machine] trait as its first argument +/// and otherwise accepts the same syntax as [tracing::span!] (see some tips below). /// Note: the result of this macro **must be used** because the span is exited when it's dropped. +/// +/// ### Syntax accepted by this macro +/// +/// The full documentation for the [tracing::span!] syntax can be found at [tracing] under "Using the +/// Macros". A few possibly confusing syntaxes are listed here: +/// ```rust +/// # use rustc_const_eval::enter_trace_span; +/// # type M = rustc_const_eval::const_eval::CompileTimeMachine<'static>; +/// # let my_display_var = String::new(); +/// # let my_debug_var = String::new(); +/// // logs a span named "hello" with a field named "arg" of value 42 (works only because +/// // 42 implements the tracing::Value trait, otherwise use one of the options below) +/// let _span = enter_trace_span!(M, "hello", arg = 42); +/// // logs a field called "my_display_var" using the Display implementation +/// let _span = enter_trace_span!(M, "hello", %my_display_var); +/// // logs a field called "my_debug_var" using the Debug implementation +/// let _span = enter_trace_span!(M, "hello", ?my_debug_var); +/// ``` +/// +/// ### `NAME::SUBNAME` syntax +/// +/// In addition to the syntax accepted by [tracing::span!], this macro optionally allows passing +/// the span name (i.e. the first macro argument) in the form `NAME::SUBNAME` (without quotes) to +/// indicate that the span has name "NAME" (usually the name of the component) and has an additional +/// more specific name "SUBNAME" (usually the function name). The latter is passed to the [tracing] +/// infrastructure as a span field with the name "NAME". This allows not being distracted by +/// subnames when looking at the trace in , but when deeper introspection +/// is needed within a component, it's still possible to view the subnames directly in the UI by +/// selecting a span, clicking on the "NAME" argument on the right, and clicking on "Visualize +/// argument values". +/// ```rust +/// # use rustc_const_eval::enter_trace_span; +/// # type M = rustc_const_eval::const_eval::CompileTimeMachine<'static>; +/// // for example, the first will expand to the second +/// let _span = enter_trace_span!(M, borrow_tracker::on_stack_pop, /* ... */); +/// let _span = enter_trace_span!(M, "borrow_tracker", borrow_tracker = "on_stack_pop", /* ... */); +/// ``` +/// +/// ### `tracing_separate_thread` parameter +/// +/// This macro was introduced to obtain better traces of Miri without impacting release performance. +/// Miri saves traces using the the `tracing_chrome` `tracing::Layer` so that they can be visualized +/// in . To instruct `tracing_chrome` to put some spans on a separate trace +/// thread/line than other spans when viewed in , you can pass +/// `tracing_separate_thread = tracing::field::Empty` to the tracing macros. This is useful to +/// separate out spans which just indicate the current step or program frame being processed by the +/// interpreter. You should use a value of [tracing::field::Empty] so that other tracing layers +/// (e.g. the logger) will ignore the `tracing_separate_thread` field. For example: +/// ```rust +/// # use rustc_const_eval::enter_trace_span; +/// # type M = rustc_const_eval::const_eval::CompileTimeMachine<'static>; +/// let _span = enter_trace_span!(M, step::eval_statement, tracing_separate_thread = tracing::field::Empty); +/// ``` #[macro_export] macro_rules! enter_trace_span { + ($machine:ident, $name:ident :: $subname:ident $($tt:tt)*) => {{ + $crate::enter_trace_span!($machine, stringify!($name), $name = %stringify!($subname) $($tt)*) + }}; + ($machine:ident, $($tt:tt)*) => { - $machine::enter_trace_span(|| tracing::info_span!($($tt)*)) + <$machine as $crate::interpret::Machine>::enter_trace_span(|| tracing::info_span!($($tt)*)) } } diff --git a/src/tools/miri/src/helpers.rs b/src/tools/miri/src/helpers.rs index ab7e35710d349..c52796d358deb 100644 --- a/src/tools/miri/src/helpers.rs +++ b/src/tools/miri/src/helpers.rs @@ -1257,25 +1257,11 @@ pub struct MaybeEnteredTraceSpan { /// This is like [rustc_const_eval::enter_trace_span] except that it does not depend on the /// [Machine] trait to check if tracing is enabled, because from the Miri codebase we can directly /// check whether the "tracing" feature is enabled, unlike from the rustc_const_eval codebase. -/// -/// In addition to the syntax accepted by [tracing::span!], this macro optionally allows passing -/// the span name (i.e. the first macro argument) in the form `NAME::SUBNAME` (without quotes) to -/// indicate that the span has name "NAME" (usually the name of the component) and has an additional -/// more specific name "SUBNAME" (usually the function name). The latter is passed to the [tracing] -/// infrastructure as a span field with the name "NAME". This allows not being distracted by -/// subnames when looking at the trace in , but when deeper introspection -/// is needed within a component, it's still possible to view the subnames directly in the UI by -/// selecting a span, clicking on the "NAME" argument on the right, and clicking on "Visualize -/// argument values". -/// ```rust -/// // for example, the first will expand to the second -/// enter_trace_span!(borrow_tracker::on_stack_pop, /* ... */) -/// enter_trace_span!("borrow_tracker", borrow_tracker = "on_stack_pop", /* ... */) -/// ``` +/// Look at [rustc_const_eval::enter_trace_span] for complete documentation, examples and tips. #[macro_export] macro_rules! enter_trace_span { ($name:ident :: $subname:ident $($tt:tt)*) => {{ - enter_trace_span!(stringify!($name), $name = %stringify!($subname) $($tt)*) + $crate::enter_trace_span!(stringify!($name), $name = %stringify!($subname) $($tt)*) }}; ($($tt:tt)*) => { From 3b5fec08f1ad2725ffdbd2172035589314b4a4c8 Mon Sep 17 00:00:00 2001 From: Stypox Date: Wed, 30 Jul 2025 18:14:58 +0200 Subject: [PATCH 2/4] Use new enter_trace_span! syntax for layout_of & friends --- compiler/rustc_const_eval/src/interpret/eval_context.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/compiler/rustc_const_eval/src/interpret/eval_context.rs b/compiler/rustc_const_eval/src/interpret/eval_context.rs index 0a8591ca140d5..c4b705d7124ed 100644 --- a/compiler/rustc_const_eval/src/interpret/eval_context.rs +++ b/compiler/rustc_const_eval/src/interpret/eval_context.rs @@ -113,7 +113,7 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { /// See [LayoutOf::layout_of] for the original documentation. #[inline(always)] pub fn layout_of(&self, ty: Ty<'tcx>) -> >::LayoutOfResult { - let _span = enter_trace_span!(M, "InterpCx::layout_of", ty = ?ty.kind()); + let _span = enter_trace_span!(M, layouting::layout_of, ty = ?ty.kind()); LayoutOf::layout_of(self, ty) } @@ -126,7 +126,7 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { sig: ty::PolyFnSig<'tcx>, extra_args: &'tcx ty::List>, ) -> >::FnAbiOfResult { - let _span = enter_trace_span!(M, "InterpCx::fn_abi_of_fn_ptr", ?sig, ?extra_args); + let _span = enter_trace_span!(M, layouting::fn_abi_of_fn_ptr, ?sig, ?extra_args); FnAbiOf::fn_abi_of_fn_ptr(self, sig, extra_args) } @@ -139,7 +139,7 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { instance: ty::Instance<'tcx>, extra_args: &'tcx ty::List>, ) -> >::FnAbiOfResult { - let _span = enter_trace_span!(M, "InterpCx::fn_abi_of_instance", ?instance, ?extra_args); + let _span = enter_trace_span!(M, layouting::fn_abi_of_instance, ?instance, ?extra_args); FnAbiOf::fn_abi_of_instance(self, instance, extra_args) } } From e1f674cfa962fc76adbc4cfe95e9b3434299eede Mon Sep 17 00:00:00 2001 From: Stypox Date: Wed, 30 Jul 2025 18:17:02 +0200 Subject: [PATCH 3/4] Use specific name for "frame" span field Otherwise the field would be named "message" by default --- compiler/rustc_const_eval/src/interpret/stack.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/compiler/rustc_const_eval/src/interpret/stack.rs b/compiler/rustc_const_eval/src/interpret/stack.rs index 25d163bba62f4..73cc87508ef95 100644 --- a/compiler/rustc_const_eval/src/interpret/stack.rs +++ b/compiler/rustc_const_eval/src/interpret/stack.rs @@ -401,7 +401,7 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> { // to put the "frame" span on a separate trace thread/line than other spans, to make the // visualization in easier to interpret. It is set to a value of // [tracing::field::Empty] so that other tracing layers (e.g. the logger) will ignore it. - let span = info_span!("frame", tracing_separate_thread = Empty, "{}", instance); + let span = info_span!("frame", tracing_separate_thread = Empty, frame = %instance); self.frame_mut().tracing_span.enter(span); interp_ok(()) From bb08a4dfc784ad5558e42db3b41b4abbebafc5a9 Mon Sep 17 00:00:00 2001 From: Stypox Date: Thu, 31 Jul 2025 15:36:44 +0200 Subject: [PATCH 4/4] Make Miri's enter_trace_span! call const_eval's --- .../rustc_const_eval/src/interpret/util.rs | 8 +++---- src/tools/miri/src/helpers.rs | 23 ++++--------------- src/tools/miri/src/lib.rs | 4 +--- 3 files changed, 9 insertions(+), 26 deletions(-) diff --git a/compiler/rustc_const_eval/src/interpret/util.rs b/compiler/rustc_const_eval/src/interpret/util.rs index 341756f837eef..6696a0c502600 100644 --- a/compiler/rustc_const_eval/src/interpret/util.rs +++ b/compiler/rustc_const_eval/src/interpret/util.rs @@ -114,11 +114,11 @@ impl EnteredTraceSpan for tracing::span::EnteredSpan {} /// ``` #[macro_export] macro_rules! enter_trace_span { - ($machine:ident, $name:ident :: $subname:ident $($tt:tt)*) => {{ + ($machine:ty, $name:ident :: $subname:ident $($tt:tt)*) => { $crate::enter_trace_span!($machine, stringify!($name), $name = %stringify!($subname) $($tt)*) - }}; + }; - ($machine:ident, $($tt:tt)*) => { + ($machine:ty, $($tt:tt)*) => { <$machine as $crate::interpret::Machine>::enter_trace_span(|| tracing::info_span!($($tt)*)) - } + }; } diff --git a/src/tools/miri/src/helpers.rs b/src/tools/miri/src/helpers.rs index c52796d358deb..43cb1c9ae053c 100644 --- a/src/tools/miri/src/helpers.rs +++ b/src/tools/miri/src/helpers.rs @@ -1245,29 +1245,14 @@ impl ToU64 for usize { } } -/// This struct is needed to enforce `#[must_use]` on values produced by [enter_trace_span] even -/// when the "tracing" feature is not enabled. -#[must_use] -pub struct MaybeEnteredTraceSpan { - #[cfg(feature = "tracing")] - pub _entered_span: tracing::span::EnteredSpan, -} - /// Enters a [tracing::info_span] only if the "tracing" feature is enabled, otherwise does nothing. -/// This is like [rustc_const_eval::enter_trace_span] except that it does not depend on the -/// [Machine] trait to check if tracing is enabled, because from the Miri codebase we can directly -/// check whether the "tracing" feature is enabled, unlike from the rustc_const_eval codebase. +/// This calls [rustc_const_eval::enter_trace_span] with [MiriMachine] as the first argument, which +/// will in turn call [MiriMachine::enter_trace_span], which takes care of determining at compile +/// time whether to trace or not (and supposedly the call is compiled out if tracing is disabled). /// Look at [rustc_const_eval::enter_trace_span] for complete documentation, examples and tips. #[macro_export] macro_rules! enter_trace_span { - ($name:ident :: $subname:ident $($tt:tt)*) => {{ - $crate::enter_trace_span!(stringify!($name), $name = %stringify!($subname) $($tt)*) - }}; - ($($tt:tt)*) => { - $crate::MaybeEnteredTraceSpan { - #[cfg(feature = "tracing")] - _entered_span: tracing::info_span!($($tt)*).entered() - } + rustc_const_eval::enter_trace_span!($crate::MiriMachine<'static>, $($tt)*) }; } diff --git a/src/tools/miri/src/lib.rs b/src/tools/miri/src/lib.rs index 507d4f7b42896..8d34b8fc23ad1 100644 --- a/src/tools/miri/src/lib.rs +++ b/src/tools/miri/src/lib.rs @@ -143,9 +143,7 @@ pub use crate::eval::{ AlignmentCheck, BacktraceStyle, IsolatedOp, MiriConfig, MiriEntryFnType, RejectOpWith, ValidationMode, create_ecx, eval_entry, }; -pub use crate::helpers::{ - AccessKind, EvalContextExt as _, MaybeEnteredTraceSpan, ToU64 as _, ToUsize as _, -}; +pub use crate::helpers::{AccessKind, EvalContextExt as _, ToU64 as _, ToUsize as _}; pub use crate::intrinsics::EvalContextExt as _; pub use crate::machine::{ AllocExtra, DynMachineCallback, FrameExtra, MachineCallback, MemoryKind, MiriInterpCx,