Skip to content

Commit 6ff454e

Browse files
authored
chore: add tracing spans for aot exec methods (#2275)
- add back tracing spans for pure and metered execution mirroring interpreter implementation
1 parent d475dae commit 6ff454e

File tree

2 files changed

+32
-2
lines changed

2 files changed

+32
-2
lines changed

crates/vm/src/arch/aot/metered_execute.rs

Lines changed: 16 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -362,7 +362,12 @@ where
362362
let mut vm_exec_state: Box<VmExecState<F, GuestMemory, MeteredCtx>> =
363363
Box::new(vm_exec_state);
364364

365-
unsafe {
365+
#[cfg(feature = "metrics")]
366+
let start = std::time::Instant::now();
367+
#[cfg(feature = "metrics")]
368+
let start_instret = vm_exec_state.ctx.segmentation_ctx.instret;
369+
370+
tracing::info_span!("execute_metered").in_scope(|| unsafe {
366371
let asm_run: libloading::Symbol<MeteredAsmRunFn> = self
367372
.lib
368373
.get(b"asm_run")
@@ -379,6 +384,16 @@ where
379384
from_state_pc,
380385
instret_until_end,
381386
);
387+
});
388+
389+
#[cfg(feature = "metrics")]
390+
{
391+
let elapsed = start.elapsed();
392+
let insns = vm_exec_state.ctx.segmentation_ctx.instret - start_instret;
393+
tracing::info!("instructions_executed={insns}");
394+
metrics::counter!("execute_metered_insns").absolute(insns);
395+
metrics::gauge!("execute_metered_insn_mi/s")
396+
.set(insns as f64 / elapsed.as_micros() as f64);
382397
}
383398
Ok(*vm_exec_state)
384399
}

crates/vm/src/arch/aot/pure.rs

Lines changed: 16 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -288,9 +288,15 @@ where
288288
let ctx = ExecutionCtx::new(num_insns);
289289
let instret_left = ctx.instret_left;
290290

291+
#[cfg(feature = "metrics")]
292+
let start = std::time::Instant::now();
293+
#[cfg(feature = "metrics")]
294+
let start_instret_left = instret_left;
295+
291296
let mut vm_exec_state: Box<VmExecState<F, GuestMemory, ExecutionCtx>> =
292297
Box::new(VmExecState::new(from_state, ctx));
293-
unsafe {
298+
299+
tracing::info_span!("execute_e1").in_scope(|| unsafe {
294300
let asm_run: libloading::Symbol<AsmRunFn> = self
295301
.lib
296302
.get(b"asm_run")
@@ -306,6 +312,15 @@ where
306312
from_state_pc,
307313
instret_left,
308314
);
315+
});
316+
317+
#[cfg(feature = "metrics")]
318+
{
319+
let elapsed = start.elapsed();
320+
let insns = start_instret_left - vm_exec_state.ctx.instret_left;
321+
tracing::info!("instructions_executed={insns}");
322+
metrics::counter!("execute_e1_insns").absolute(insns);
323+
metrics::gauge!("execute_e1_insn_mi/s").set(insns as f64 / elapsed.as_micros() as f64);
309324
}
310325

311326
if num_insns.is_some() {

0 commit comments

Comments
 (0)