Uniform `enter_trace_span!` and add documentation #144688

Stypox · 2025-07-30T16:08:44Z

The latest changes to enter_trace_span! were ported from Miri (see Add tracing spans to borrow tracker functions miri#4452 (comment)), so now both the rustc_const_eval and the Miri macro accept the same syntax. Furthermore, the Miri macro was changed to just call rustc_const_eval`'s, to avoid duplication.
I made the layout_of (& friends) calls use that new syntax, e.g. enter_trace_span!(layouting::layout_of, ...)
I made sure the macro specifies all types/traits/macros it refers to using $crate::, so the macro works anywhere independently of which types/traits/macros are imported in the context it is used in.
I added documentation, examples and tips to the macro's doc. To make the rustdoc compile I had to add some hidden lines (#), but now it acts as a compilation test which will avoid reintroducing issue 3. in the future. I will also create a documentation file with everything one needs to know about tracing at a later point, but I figured adding some of that info directly on the tracing macro makes it more discoverable.
In stack.rs I made it so that the "frame" span has a field named "frame" (instead of "message") with the data about the frame. This field used to be called "message" (tracing's default) since it was previously formatted using "{}", instance, and now I replaced it with frame = %instance.

rustbot · 2025-07-30T16:08:49Z

rustbot has assigned @lcnr.
They will have a look at your PR within the next two weeks and either review your PR or reassign to another reviewer.

Use r? to explicitly pick a reviewer

rustbot · 2025-07-30T16:08:50Z

The Miri subtree was changed

cc @rust-lang/miri

Some changes occurred to the CTFE / Miri interpreter

cc @rust-lang/miri

Some changes occurred to the CTFE machinery

cc @RalfJung, @oli-obk, @lcnr

The macro was uniformed between rustc_const_eval and miri

Otherwise the field would be named "message" by default

RalfJung · 2025-07-31T08:41:58Z

compiler/rustc_const_eval/src/interpret/util.rs

+/// # 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 {


Why do we duplicate this macro between Miri and rustc? Can we reuse the rustc definition in Miri?

Because from Miri we use #[cfg(feature = "tracing")] to decide whether to do tracing or not, and from rustc_const_eval we instead have to call Machine::enter_trace_span and let it decide whether to do tracing or not. I guess we could make the Miri macro pass MiriMachine<'static> as $machine to this macro and then it would work, but #[cfg(feature = "tracing")] will probably optimize things out better than a call to Machine::enter_trace_span.

Hm... then please add that as a comment in the Miri version of the macro.

It may be worth briefly benchmarking (./miri bench, not the option to save/load a baseline file) whether it makes any difference to use the rustc version from Miri -- but that doesn't have to block this PR.

I did the benchmarks in the end and it seems like there is no difference (the differences are all within statistical significance, and some are higher some lower). So I pushed a commit that makes the Miri one just call the rustc_const_eval one.

Benchmark of #[cfg(feature = "tracing")]

# benchmark of miri with tracing disabled when enter_trace_span! is disabled using #[cfg(feature = "tracing")] $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/backtraces/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/backtraces/Cargo.toml" Time (mean ± σ): 2.642 s ± 0.024 s [User: 2.557 s, System: 0.088 s] Range (min … max): 2.591 s … 2.697 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/big-allocs/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/big-allocs/Cargo.toml" Time (mean ± σ): 184.2 ms ± 2.6 ms [User: 109.8 ms, System: 80.3 ms] Range (min … max): 179.3 ms … 189.6 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/mse/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/mse/Cargo.toml" Time (mean ± σ): 815.5 ms ± 8.0 ms [User: 740.9 ms, System: 80.3 ms] Range (min … max): 804.8 ms … 834.1 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/range-iteration/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/range-iteration/Cargo.toml" Time (mean ± σ): 4.724 s ± 0.049 s [User: 4.647 s, System: 0.080 s] Range (min … max): 4.619 s … 4.829 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/serde1/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/serde1/Cargo.toml" Time (mean ± σ): 2.884 s ± 0.046 s [User: 2.800 s, System: 0.087 s] Range (min … max): 2.821 s … 3.057 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/serde2/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/serde2/Cargo.toml" Time (mean ± σ): 6.402 s ± 0.055 s [User: 6.313 s, System: 0.090 s] Range (min … max): 6.303 s … 6.565 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/slice-chunked/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/slice-chunked/Cargo.toml" Time (mean ± σ): 511.5 ms ± 7.8 ms [User: 435.7 ms, System: 81.3 ms] Range (min … max): 494.6 ms … 530.7 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/slice-get-unchecked/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/slice-get-unchecked/Cargo.toml" Time (mean ± σ): 856.6 ms ± 12.1 ms [User: 780.5 ms, System: 81.3 ms] Range (min … max): 834.9 ms … 886.5 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/string-replace/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/string-replace/Cargo.toml" Time (mean ± σ): 545.8 ms ± 9.9 ms [User: 464.7 ms, System: 86.6 ms] Range (min … max): 528.4 ms … 572.6 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/unicode/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/unicode/Cargo.toml" Time (mean ± σ): 3.766 s ± 0.052 s [User: 3.688 s, System: 0.081 s] Range (min … max): 3.679 s … 3.898 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/zip-equal/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/zip-equal/Cargo.toml" Time (mean ± σ): 3.304 s ± 0.037 s [User: 3.221 s, System: 0.086 s] Range (min … max): 3.250 s … 3.421 s 50 runs

Benchmark of deferring to rustc_const_eval::enter_trace_span!

# benchmark of miri with tracing disabled when enter_trace_span! is disabled by calling Machine::enter_trace_span (i.e. pointing to rustc_const_eval's implementation) $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/backtraces/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/backtraces/Cargo.toml" Time (mean ± σ): 2.651 s ± 0.041 s [User: 2.566 s, System: 0.088 s] Range (min … max): 2.585 s … 2.761 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/big-allocs/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/big-allocs/Cargo.toml" Time (mean ± σ): 183.6 ms ± 2.0 ms [User: 110.2 ms, System: 79.3 ms] Range (min … max): 180.5 ms … 188.9 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/mse/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/mse/Cargo.toml" Time (mean ± σ): 835.0 ms ± 10.3 ms [User: 758.1 ms, System: 82.2 ms] Range (min … max): 817.5 ms … 857.2 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/range-iteration/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/range-iteration/Cargo.toml" Time (mean ± σ): 4.755 s ± 0.043 s [User: 4.676 s, System: 0.081 s] Range (min … max): 4.678 s … 4.878 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/serde1/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/serde1/Cargo.toml" Time (mean ± σ): 2.870 s ± 0.055 s [User: 2.784 s, System: 0.088 s] Range (min … max): 2.806 s … 3.056 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/serde2/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/serde2/Cargo.toml" Time (mean ± σ): 6.359 s ± 0.080 s [User: 6.267 s, System: 0.090 s] Range (min … max): 6.249 s … 6.537 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/slice-chunked/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/slice-chunked/Cargo.toml" Time (mean ± σ): 504.2 ms ± 7.3 ms [User: 428.1 ms, System: 81.4 ms] Range (min … max): 493.3 ms … 526.9 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/slice-get-unchecked/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/slice-get-unchecked/Cargo.toml" Time (mean ± σ): 866.2 ms ± 10.2 ms [User: 790.6 ms, System: 80.6 ms] Range (min … max): 849.5 ms … 892.6 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/string-replace/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/string-replace/Cargo.toml" Time (mean ± σ): 550.5 ms ± 7.6 ms [User: 469.2 ms, System: 86.7 ms] Range (min … max): 538.0 ms … 572.5 ms 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/unicode/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/unicode/Cargo.toml" Time (mean ± σ): 3.724 s ± 0.031 s [User: 3.646 s, System: 0.080 s] Range (min … max): 3.657 s … 3.795 s 50 runs $ hyperfine -w 10 -m 50 --shell=none "cargo +miri miri run --manifest-path \"bench-cargo-miri/zip-equal/Cargo.toml\"" Benchmark 1: cargo +miri miri run --manifest-path "bench-cargo-miri/zip-equal/Cargo.toml" Time (mean ± σ): 3.268 s ± 0.026 s [User: 3.186 s, System: 0.085 s] Range (min … max): 3.211 s … 3.335 s 50 runs

Ah, you're just too fast, okay. :D

(It's easier to compare these benchmarks if you use --save-baseline/--load-baseline.)

RalfJung · 2025-07-31T13:40:41Z

src/tools/miri/src/helpers.rs

-            #[cfg(feature = "tracing")]
-            _entered_span: tracing::info_span!($($tt)*).entered()
-        }
+        rustc_const_eval::enter_trace_span!($crate::MiriMachine<'static>, $($tt)*)


So... what is your plan now? I thought I had suggested to do this in a future PR, it's anyway easier to evaluate in the miri repo than here.

I also didn't realize we'd still need a custom macro... but we can remove the MaybeEnteredTraceSpan type now, right?

So... what is your plan now? I thought I had suggested to do this in a future PR, it's anyway easier to evaluate in the miri repo than here.

Sorry, I was still writing the other comment ;-)
Given the small change I thought I would add it to this PR but if you want I can move it to a miri PR.

but we can remove the MaybeEnteredTraceSpan type now, right?

Yeah sorry about that, fixed now

RalfJung · 2025-07-31T13:49:58Z

LGTM, thanks!

@bors r+ rollup

bors · 2025-07-31T13:50:02Z

📌 Commit bb08a4d has been approved by RalfJung

It is now in the queue for this repository.

Rollup of 6 pull requests Successful merges: - #144688 (Uniform `enter_trace_span!` and add documentation) - #144702 (stall `ConstArgHasType` in `compute_goal_fast_path`) - #144711 (Consider operator's span when computing binop expr span) - #144712 (Deduplicate `IntTy`/`UintTy`/`FloatTy`.) - #144726 (merge rustc_attr_data_structures into rustc_hir) - #144733 (fix: Match width of ascii and unicode secondary file start) r? `@ghost` `@rustbot` modify labels: rollup

Rollup merge of #144688 - Stypox:better-enter-trace-span, r=RalfJung Uniform `enter_trace_span!` and add documentation 1. The latest changes to `enter_trace_span!` were ported from Miri (see rust-lang/miri#4452 (comment)), so now both the `rustc_const_eval` and the Miri macro accept the same syntax. Furthermore, the Miri macro was changed to just call rustc_const_eval`'s, to avoid duplication. 2. I made the `layout_of` (& friends) calls use that new syntax, e.g. `enter_trace_span!(layouting::layout_of, ...)` 3. I made sure the macro specifies all types/traits/macros it refers to using `$crate::`, so the macro works anywhere independently of which types/traits/macros are imported in the context it is used in. 4. I added documentation, examples and tips to the macro's doc. To make the rustdoc compile I had to add some hidden lines (`#`), but now it acts as a compilation test which will avoid reintroducing issue 3. in the future. I will also create a documentation file with everything one needs to know about tracing at a later point, but I figured adding some of that info directly on the tracing macro makes it more discoverable. 5. In `stack.rs` I made it so that the `"frame"` span has a field named "frame" (instead of "message") with the data about the frame. This field used to be called "message" (tracing's default) since it was previously formatted using `"{}", instance`, and now I replaced it with `frame = %instance`.

Rollup of 6 pull requests Successful merges: - rust-lang/rust#144688 (Uniform `enter_trace_span!` and add documentation) - rust-lang/rust#144702 (stall `ConstArgHasType` in `compute_goal_fast_path`) - rust-lang/rust#144711 (Consider operator's span when computing binop expr span) - rust-lang/rust#144712 (Deduplicate `IntTy`/`UintTy`/`FloatTy`.) - rust-lang/rust#144726 (merge rustc_attr_data_structures into rustc_hir) - rust-lang/rust#144733 (fix: Match width of ascii and unicode secondary file start) r? `@ghost` `@rustbot` modify labels: rollup

rustbot assigned lcnr Jul 30, 2025

rustbot added S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. T-compiler Relevant to the compiler team, which will review and decide on the PR/issue. labels Jul 30, 2025

rustbot assigned RalfJung and unassigned lcnr Jul 30, 2025

Stypox force-pushed the better-enter-trace-span branch from 748b153 to 55e9b65 Compare July 30, 2025 16:27

This comment has been minimized.

Sign in to view

Stypox force-pushed the better-enter-trace-span branch from 55e9b65 to 168ca43 Compare July 30, 2025 21:16

This comment has been minimized.

Sign in to view

Stypox added 3 commits July 31, 2025 00:40

Uniform enter_trace_span! and add documentation

8e78616

The macro was uniformed between rustc_const_eval and miri

Use new enter_trace_span! syntax for layout_of & friends

3b5fec0

Use specific name for "frame" span field

e1f674c

Otherwise the field would be named "message" by default

Stypox force-pushed the better-enter-trace-span branch from 168ca43 to e1f674c Compare July 30, 2025 22:40

Stypox mentioned this pull request Jul 30, 2025

Add tracing to step.rs and friends #144708

Merged

RalfJung reviewed Jul 31, 2025

View reviewed changes

Stypox mentioned this pull request Jul 31, 2025

Add tracing to resolve-related functions #144727

Open

RalfJung reviewed Jul 31, 2025

View reviewed changes

Make Miri's enter_trace_span! call const_eval's

bb08a4d

Stypox force-pushed the better-enter-trace-span branch from 3020b6c to bb08a4d Compare July 31, 2025 13:45

bors added S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels Jul 31, 2025

jdonszelmann mentioned this pull request Jul 31, 2025

Rollup of 6 pull requests #144740

Merged

bors merged commit 1fe4886 into rust-lang:master Jul 31, 2025
10 checks passed

rustbot added this to the 1.90.0 milestone Jul 31, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Uniform `enter_trace_span!` and add documentation #144688

Uniform `enter_trace_span!` and add documentation #144688

Uh oh!

Stypox commented Jul 30, 2025 •

edited

Loading

Uh oh!

rustbot commented Jul 30, 2025

Uh oh!

rustbot commented Jul 30, 2025

Uh oh!

This comment has been minimized.

This comment has been minimized.

RalfJung Jul 31, 2025

Uh oh!

Stypox Jul 31, 2025

Uh oh!

RalfJung Jul 31, 2025

Uh oh!

Stypox Jul 31, 2025

Uh oh!

RalfJung Jul 31, 2025

Uh oh!

RalfJung Jul 31, 2025

Uh oh!

Stypox Jul 31, 2025

Uh oh!

RalfJung commented Jul 31, 2025

Uh oh!

bors commented Jul 31, 2025

Uh oh!

Uh oh!

Uh oh!

Uniform enter_trace_span! and add documentation #144688

Uniform enter_trace_span! and add documentation #144688

Uh oh!

Conversation

Stypox commented Jul 30, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

rustbot commented Jul 30, 2025

Uh oh!

rustbot commented Jul 30, 2025

Uh oh!

This comment has been minimized.

This comment has been minimized.

RalfJung Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

Stypox Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

RalfJung Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

Stypox Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

RalfJung Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

RalfJung Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

Stypox Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

RalfJung commented Jul 31, 2025

Uh oh!

bors commented Jul 31, 2025

Uh oh!

Uh oh!

Uh oh!

Uniform `enter_trace_span!` and add documentation #144688

Uniform `enter_trace_span!` and add documentation #144688

Stypox commented Jul 30, 2025 •

edited

Loading