Skip to content

Commit 9ddc0f0

Browse files
authored
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" />
2 parents 0ab57e7 + 68a0c7c commit 9ddc0f0

File tree

1 file changed

+2
-0
lines changed

1 file changed

+2
-0
lines changed

src/machine.rs

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1111,6 +1111,7 @@ impl<'tcx> Machine<'tcx> for MiriMachine<'tcx> {
11111111
) -> InterpResult<'tcx, Option<(&'tcx mir::Body<'tcx>, ty::Instance<'tcx>)>> {
11121112
// For foreign items, try to see if we can emulate them.
11131113
if ecx.tcx.is_foreign_item(instance.def_id()) {
1114+
let _trace = enter_trace_span!("emulate_foreign_item");
11141115
// An external function call that does not have a MIR body. We either find MIR elsewhere
11151116
// or emulate its effect.
11161117
// This will be Ok(None) if we're emulating the intrinsic entirely within Miri (no need
@@ -1123,6 +1124,7 @@ impl<'tcx> Machine<'tcx> for MiriMachine<'tcx> {
11231124
}
11241125

11251126
// Otherwise, load the MIR.
1127+
let _trace = enter_trace_span!("load_mir");
11261128
interp_ok(Some((ecx.load_mir(instance.def, None)?, instance)))
11271129
}
11281130

0 commit comments

Comments
 (0)