diff options
| author | 许杰友 Jieyou Xu (Joe) <39484203+jieyouxu@users.noreply.github.com> | 2025-08-19 19:42:09 +0800 |
|---|---|---|
| committer | GitHub <noreply@github.com> | 2025-08-19 19:42:09 +0800 |
| commit | ba20d77a444a7125a764e9d69024c6377023b45f (patch) | |
| tree | f89462bb41412f1cdb279cf911ab6c320625527b /compiler/rustc_const_eval/src/interpret/step.rs | |
| parent | 0b378a7108e550b6edb7ee0669a64f24dac364f1 (diff) | |
| parent | dc72692591c937e15cb016c57d4dee6a81340bbd (diff) | |
| download | rust-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.rs | 5 |
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 = |
