diff --git a/crates/vm/src/arch/aot/metered_execute.rs b/crates/vm/src/arch/aot/metered_execute.rs index 8daa4ea40e..43a7002053 100644 --- a/crates/vm/src/arch/aot/metered_execute.rs +++ b/crates/vm/src/arch/aot/metered_execute.rs @@ -362,7 +362,12 @@ where let mut vm_exec_state: Box> = Box::new(vm_exec_state); - unsafe { + #[cfg(feature = "metrics")] + let start = std::time::Instant::now(); + #[cfg(feature = "metrics")] + let start_instret = vm_exec_state.ctx.segmentation_ctx.instret; + + tracing::info_span!("execute_metered").in_scope(|| unsafe { let asm_run: libloading::Symbol = self .lib .get(b"asm_run") @@ -379,6 +384,16 @@ where from_state_pc, instret_until_end, ); + }); + + #[cfg(feature = "metrics")] + { + let elapsed = start.elapsed(); + let insns = vm_exec_state.ctx.segmentation_ctx.instret - start_instret; + tracing::info!("instructions_executed={insns}"); + metrics::counter!("execute_metered_insns").absolute(insns); + metrics::gauge!("execute_metered_insn_mi/s") + .set(insns as f64 / elapsed.as_micros() as f64); } Ok(*vm_exec_state) } diff --git a/crates/vm/src/arch/aot/pure.rs b/crates/vm/src/arch/aot/pure.rs index cea704489c..ec7dc48a09 100644 --- a/crates/vm/src/arch/aot/pure.rs +++ b/crates/vm/src/arch/aot/pure.rs @@ -288,9 +288,15 @@ where let ctx = ExecutionCtx::new(num_insns); let instret_left = ctx.instret_left; + #[cfg(feature = "metrics")] + let start = std::time::Instant::now(); + #[cfg(feature = "metrics")] + let start_instret_left = instret_left; + let mut vm_exec_state: Box> = Box::new(VmExecState::new(from_state, ctx)); - unsafe { + + tracing::info_span!("execute_e1").in_scope(|| unsafe { let asm_run: libloading::Symbol = self .lib .get(b"asm_run") @@ -306,6 +312,15 @@ where from_state_pc, instret_left, ); + }); + + #[cfg(feature = "metrics")] + { + let elapsed = start.elapsed(); + let insns = start_instret_left - vm_exec_state.ctx.instret_left; + tracing::info!("instructions_executed={insns}"); + metrics::counter!("execute_e1_insns").absolute(insns); + metrics::gauge!("execute_e1_insn_mi/s").set(insns as f64 / elapsed.as_micros() as f64); } if num_insns.is_some() {