about summary refs log tree commit diff
path: root/compiler/rustc_const_eval/src/interpret/step.rs
diff options
context:
space:
mode:
author许杰友 Jieyou Xu (Joe) <39484203+jieyouxu@users.noreply.github.com>2025-08-19 19:42:09 +0800
committerGitHub <noreply@github.com>2025-08-19 19:42:09 +0800
commitba20d77a444a7125a764e9d69024c6377023b45f (patch)
treef89462bb41412f1cdb279cf911ab6c320625527b /compiler/rustc_const_eval/src/interpret/step.rs
parent0b378a7108e550b6edb7ee0669a64f24dac364f1 (diff)
parentdc72692591c937e15cb016c57d4dee6a81340bbd (diff)
downloadrust-ba20d77a444a7125a764e9d69024c6377023b45f.tar.gz
rust-ba20d77a444a7125a764e9d69024c6377023b45f.zip
Rollup merge of #145306 - Stypox:tracing-misc, r=RalfJung
Add tracing to various miscellaneous functions

This PR adds tracing to:
- `ty.fn_sig()`. There is only one place where `fn_sig` is called for real within `rustc_const_eval`. There are three other places where it's called, but one is inside `ConstCx::fn_sig` (which does not seem to be used anywhere), another is under `if cfg!(debug_assertions)`, and the last is within `call_main` and thus gets called only once.
- the two possible things `find_mir_or_eval_fn` can do: "emulate_foreign_item" and "load_mir"
- all calls to `Const.eval()` within the Miri or the `rustc_const_eval` codebase.
- a separate commit also fixes the style of some tracing macros

Those are all quite long-lived operations, that in total make up for 6-7% of the total time spent in the program. I found out about them by looking for long periods of time that were previously not traced at all, using this SQL query in ui.perfetto.dev:

```sql
with ordered as (select s1.*, row_number() over (order by s1.ts) as rn from slices as s1 where s1.parent_id is null and s1.dur > 0 and s1.name != "frame" and s1.name != "step" and s1.name != "backtrace") select a.ts+a.dur as ts, b.ts-a.ts-a.dur as dur, a.id, a.track_id, a.category, a.depth, a.stack_id, a.parent_stack_id, a.parent_id, a.arg_set_id, a.thread_ts, a.thread_instruction_count, a.thread_instruction_delta, a.cat, a.slice_id, "empty" as name from ordered as a inner join ordered as b on a.rn=b.rn-1 /*where b.ts-a.ts-a.dur > 5000*/ order by b.ts-a.ts-a.dur desc
```

<details>
<summary>How the table was obtained</summary>

The above image was obtained in ui.perfetto.dev with the following SQL query after obtaining a trace file by running Miri on the following Rust code with `n=100`.

```sql
select "TOTAL PROGRAM DURATION" as name, count(*), max(ts + dur) as "sum(dur)", 100.0 as "%", null as "min(dur)", null as "max(dur)", null as "avg(dur)", null as "stddev(dur)" from slices union select "TOTAL OVER ALL SPANS (excluding events)" as name, count(*), sum(dur), cast(cast(sum(dur) as float) / (select max(ts + dur) from slices) * 1000 as int) / 10.0 as "%", min(dur), max(dur), cast(avg(dur) as int) as "avg(dur)", cast(sqrt(avg(dur*dur)-avg(dur)*avg(dur)) as int) as "stddev(dur)" from slices where parent_id is null and name != "frame" and name != "step" and dur > 0 union select name, count(*), sum(dur), cast(cast(sum(dur) as float) / (select max(ts + dur) from slices) * 1000 as int) / 10.0 as "%", min(dur), max(dur), cast(avg(dur) as int) as "avg(dur)", cast(sqrt(avg(dur*dur)-avg(dur)*avg(dur)) as int) as "stddev(dur)" from slices where parent_id is null and name != "frame" and name != "step" group by name order by sum(dur) desc, count(*) desc
```

```rust
fn main() {
    let n: usize = std::env::args().nth(1).unwrap().parse().unwrap();
    let mut v = (0..n).into_iter().collect::<Vec<_>>();
    for i in &mut v {
        *i += 1;
    }
}
```

</details>

<img width="1689" height="317" alt="image" src="https://github.com/user-attachments/assets/ee2c81f5-d74a-4da5-b4b6-ab2770175b14" />
Diffstat (limited to 'compiler/rustc_const_eval/src/interpret/step.rs')
-rw-r--r--compiler/rustc_const_eval/src/interpret/step.rs5
1 files changed, 4 insertions, 1 deletions
diff --git a/compiler/rustc_const_eval/src/interpret/step.rs b/compiler/rustc_const_eval/src/interpret/step.rs
index f1995b3f132..5143278e69a 100644
--- a/compiler/rustc_const_eval/src/interpret/step.rs
+++ b/compiler/rustc_const_eval/src/interpret/step.rs
@@ -436,7 +436,10 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> {
             .map(|arg| self.eval_fn_call_argument(&arg.node))
             .collect::<InterpResult<'tcx, Vec<_>>>()?;
 
-        let fn_sig_binder = func.layout.ty.fn_sig(*self.tcx);
+        let fn_sig_binder = {
+            let _trace = enter_trace_span!(M, "fn_sig", ty = ?func.layout.ty.kind());
+            func.layout.ty.fn_sig(*self.tcx)
+        };
         let fn_sig = self.tcx.normalize_erasing_late_bound_regions(self.typing_env, fn_sig_binder);
         let extra_args = &args[fn_sig.inputs().len()..];
         let extra_args =