about summary refs log tree commit diff
path: root/compiler/rustc_const_eval/src/interpret/call.rs
diff options
context:
space:
mode:
authorGuillaume Gomez <guillaume1.gomez@gmail.com>2025-08-14 11:39:35 +0200
committerGitHub <noreply@github.com>2025-08-14 11:39:35 +0200
commit6ac5c28412bebe7c15f0738c032cfb8333c25e46 (patch)
treece18eedbe0ee7fc473a54f9b1278d438f42f0e48 /compiler/rustc_const_eval/src/interpret/call.rs
parent31d8277abe4957e01437f40d1136c6760081751b (diff)
parent99769bc301d6e9187d0e7881bb36162fd48fd573 (diff)
downloadrust-6ac5c28412bebe7c15f0738c032cfb8333c25e46.tar.gz
rust-6ac5c28412bebe7c15f0738c032cfb8333c25e46.zip
Rollup merge of #144727 - Stypox:add-tracing-to-resolve, r=RalfJung
Add tracing to resolve-related functions

Resolve-related functions are not called often but still make up for ~3% of execution time for non-repetitive programs (as seen in the first table below, obtained from running the rust snippet at the bottom with `n=1`). On the other hand, for repetitive programs they become less relevant (I tested the same snippet but with `n=100` and got ~1.5%), and it appears that only `try_resolve` is called more often (see the last two tables).

The first table was obtained by opening the trace file in https://ui.perfetto.dev and running the following query:

```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
```

<img width="1687" height="242" alt="image" src="https://github.com/user-attachments/assets/4d4bd890-869b-40f3-a473-8e4c42b02da4" />

The following two tables show how many `resolve` spans there per subname/subcategory, and how much time is spent in each. The first is for `n=1` and the second for `n=100`. The query that was used is:

```sql
select args.string_value as name, count(*), max(dur), avg(dur), sum(dur) from slices inner join args USING (arg_set_id) where args.key = "args." || slices.name and name = "resolve" group by args.string_value
```

<img width="1688" height="159" alt="image" src="https://github.com/user-attachments/assets/a8749856-c099-492e-a86e-6d67b146af9c" />

<img width="1688" height="159" alt="image" src="https://github.com/user-attachments/assets/ce3ac1b5-5c06-47d9-85a6-9b921aea348e" />

The snippet I tested with Miri to obtain the above traces is:

```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;
    }
}
```
Diffstat (limited to 'compiler/rustc_const_eval/src/interpret/call.rs')
-rw-r--r--compiler/rustc_const_eval/src/interpret/call.rs23
1 files changed, 15 insertions, 8 deletions
diff --git a/compiler/rustc_const_eval/src/interpret/call.rs b/compiler/rustc_const_eval/src/interpret/call.rs
index b1cc0cc2878..a61cb7f2b09 100644
--- a/compiler/rustc_const_eval/src/interpret/call.rs
+++ b/compiler/rustc_const_eval/src/interpret/call.rs
@@ -736,13 +736,16 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> {
         let existential_trait_ref = ty::ExistentialTraitRef::erase_self_ty(tcx, virtual_trait_ref);
         let concrete_trait_ref = existential_trait_ref.with_self_ty(tcx, dyn_ty);
 
-        let concrete_method = Instance::expect_resolve_for_vtable(
-            tcx,
-            self.typing_env,
-            def_id,
-            virtual_instance.args.rebase_onto(tcx, trait_def_id, concrete_trait_ref.args),
-            self.cur_span(),
-        );
+        let concrete_method = {
+            let _trace = enter_trace_span!(M, resolve::expect_resolve_for_vtable, ?def_id);
+            Instance::expect_resolve_for_vtable(
+                tcx,
+                self.typing_env,
+                def_id,
+                virtual_instance.args.rebase_onto(tcx, trait_def_id, concrete_trait_ref.args),
+                self.cur_span(),
+            )
+        };
         assert_eq!(concrete_instance, concrete_method);
     }
 
@@ -825,7 +828,11 @@ impl<'tcx, M: Machine<'tcx>> InterpCx<'tcx, M> {
                 place
             }
         };
-        let instance = ty::Instance::resolve_drop_in_place(*self.tcx, place.layout.ty);
+        let instance = {
+            let _trace =
+                enter_trace_span!(M, resolve::resolve_drop_in_place, ty = ?place.layout.ty);
+            ty::Instance::resolve_drop_in_place(*self.tcx, place.layout.ty)
+        };
         let fn_abi = self.fn_abi_of_instance(instance, ty::List::empty())?;
 
         let arg = self.mplace_to_ref(&place)?;