From 19c84ce624d53735133fa3b12c7f980e8c14260d Mon Sep 17 00:00:00 2001 From: Lech <88630083+Artemka374@users.noreply.github.com> Date: Mon, 4 Dec 2023 11:51:17 +0200 Subject: [PATCH] feat: Add metric to CallTracer for calculating maximum depth of the calls (#535) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## What ❔ Add metric to CallTracer for calculating maximum depth of the calls ## Why ❔ We need to know what our limits are. ## Checklist - [x] PR title corresponds to the body of PR (we generate changelog entries from PRs). - [ ] Tests for the changes have been added / updated. - [x] Documentation comments have been added / updated. - [x] Code has been formatted via `zk fmt` and `zk lint`. --- .../src/tracers/call_tracer/metrics.rs | 15 ++++++ .../multivm/src/tracers/call_tracer/mod.rs | 46 +++++++++++++++++++ .../src/tracers/call_tracer/vm_latest/mod.rs | 15 ++---- .../call_tracer/vm_refunds_enhancement/mod.rs | 16 +++---- .../call_tracer/vm_virtual_blocks/mod.rs | 15 ++---- 5 files changed, 77 insertions(+), 30 deletions(-) create mode 100644 core/lib/multivm/src/tracers/call_tracer/metrics.rs diff --git a/core/lib/multivm/src/tracers/call_tracer/metrics.rs b/core/lib/multivm/src/tracers/call_tracer/metrics.rs new file mode 100644 index 00000000000..b3d94464f50 --- /dev/null +++ b/core/lib/multivm/src/tracers/call_tracer/metrics.rs @@ -0,0 +1,15 @@ +use vise::{Buckets, Histogram, Metrics}; + +#[derive(Debug, Metrics)] +#[metrics(prefix = "vm_call_tracer")] +pub struct CallMetrics { + /// Maximum call stack depth during the execution of the transaction. + #[metrics(buckets = Buckets::exponential(1.0..=64.0, 2.0))] + pub call_stack_depth: Histogram, + /// Maximum number of near calls during the execution of the transaction. + #[metrics(buckets = Buckets::exponential(1.0..=64.0, 2.0))] + pub max_near_calls: Histogram, +} + +#[vise::register] +pub static CALL_METRICS: vise::Global = vise::Global::new(); diff --git a/core/lib/multivm/src/tracers/call_tracer/mod.rs b/core/lib/multivm/src/tracers/call_tracer/mod.rs index 90343a53bf6..90f15fb68d4 100644 --- a/core/lib/multivm/src/tracers/call_tracer/mod.rs +++ b/core/lib/multivm/src/tracers/call_tracer/mod.rs @@ -1,7 +1,9 @@ +use crate::tracers::call_tracer::metrics::CALL_METRICS; use once_cell::sync::OnceCell; use std::sync::Arc; use zksync_types::vm_trace::Call; +mod metrics; pub mod vm_latest; pub mod vm_refunds_enhancement; pub mod vm_virtual_blocks; @@ -10,12 +12,23 @@ pub mod vm_virtual_blocks; pub struct CallTracer { stack: Vec, result: Arc>>, + + max_stack_depth: usize, + max_near_calls: usize, } #[derive(Debug, Clone)] struct FarcallAndNearCallCount { farcall: Call, near_calls_after: usize, + stack_depth_on_prefix: usize, +} + +impl Drop for CallTracer { + fn drop(&mut self) { + CALL_METRICS.call_stack_depth.observe(self.max_stack_depth); + CALL_METRICS.max_near_calls.observe(self.max_near_calls); + } } impl CallTracer { @@ -23,6 +36,8 @@ impl CallTracer { Self { stack: vec![], result, + max_stack_depth: 0, + max_near_calls: 0, } } @@ -38,4 +53,35 @@ impl CallTracer { let cell = self.result.as_ref(); cell.set(result).unwrap(); } + + fn push_call_and_update_stats(&mut self, farcall: Call, near_calls_after: usize) { + let stack_depth = self + .stack + .last() + .map(|x| x.stack_depth_on_prefix) + .unwrap_or(0); + + let depth_on_prefix = stack_depth + 1 + near_calls_after; + + let call = FarcallAndNearCallCount { + farcall, + near_calls_after, + stack_depth_on_prefix: depth_on_prefix, + }; + + self.stack.push(call); + + self.max_stack_depth = self.max_stack_depth.max(depth_on_prefix); + self.max_near_calls = self.max_near_calls.max(near_calls_after); + } + + fn increase_near_call_count(&mut self) { + if let Some(last) = self.stack.last_mut() { + last.near_calls_after += 1; + last.stack_depth_on_prefix += 1; + + self.max_near_calls = self.max_near_calls.max(last.near_calls_after); + self.max_stack_depth = self.max_stack_depth.max(last.stack_depth_on_prefix); + } + } } diff --git a/core/lib/multivm/src/tracers/call_tracer/vm_latest/mod.rs b/core/lib/multivm/src/tracers/call_tracer/vm_latest/mod.rs index 2b6fc144bd4..f5f5c1077d3 100644 --- a/core/lib/multivm/src/tracers/call_tracer/vm_latest/mod.rs +++ b/core/lib/multivm/src/tracers/call_tracer/vm_latest/mod.rs @@ -15,7 +15,7 @@ use crate::interface::{ tracer::VmExecutionStopReason, traits::tracers::dyn_tracers::vm_1_4_0::DynTracer, VmRevertReason, }; -use crate::tracers::call_tracer::{CallTracer, FarcallAndNearCallCount}; +use crate::tracers::call_tracer::CallTracer; use crate::vm_latest::{BootloaderState, HistoryMode, SimpleMemory, VmTracer, ZkSyncVmState}; impl DynTracer> for CallTracer { @@ -28,9 +28,7 @@ impl DynTracer> for CallTracer { ) { match data.opcode.variant.opcode { Opcode::NearCall(_) => { - if let Some(last) = self.stack.last_mut() { - last.near_calls_after += 1; - } + self.increase_near_call_count(); } Opcode::FarCall(far_call) => { // We use parent gas for properly calculating gas used in the trace. @@ -51,10 +49,7 @@ impl DynTracer> for CallTracer { }; self.handle_far_call_op_code_latest(state, memory, &mut current_call); - self.stack.push(FarcallAndNearCallCount { - farcall: current_call, - near_calls_after: 0, - }); + self.push_call_and_update_stats(current_call, 0); } Opcode::Ret(ret_code) => { self.handle_ret_op_code_latest(state, memory, ret_code); @@ -187,7 +182,7 @@ impl CallTracer { if current_call.near_calls_after > 0 { current_call.near_calls_after -= 1; - self.stack.push(current_call); + self.push_call_and_update_stats(current_call.farcall, current_call.near_calls_after); return; } @@ -203,7 +198,7 @@ impl CallTracer { if let Some(parent_call) = self.stack.last_mut() { parent_call.farcall.calls.push(current_call.farcall); } else { - self.stack.push(current_call); + self.push_call_and_update_stats(current_call.farcall, current_call.near_calls_after); } } } diff --git a/core/lib/multivm/src/tracers/call_tracer/vm_refunds_enhancement/mod.rs b/core/lib/multivm/src/tracers/call_tracer/vm_refunds_enhancement/mod.rs index 43dd363dcea..fab4ee0ff0f 100644 --- a/core/lib/multivm/src/tracers/call_tracer/vm_refunds_enhancement/mod.rs +++ b/core/lib/multivm/src/tracers/call_tracer/vm_refunds_enhancement/mod.rs @@ -15,7 +15,7 @@ use crate::interface::{ tracer::VmExecutionStopReason, traits::tracers::dyn_tracers::vm_1_3_3::DynTracer, VmRevertReason, }; -use crate::tracers::call_tracer::{CallTracer, FarcallAndNearCallCount}; +use crate::tracers::call_tracer::CallTracer; use crate::vm_refunds_enhancement::{ BootloaderState, HistoryMode, SimpleMemory, VmTracer, ZkSyncVmState, }; @@ -30,9 +30,7 @@ impl DynTracer> for CallTracer { ) { match data.opcode.variant.opcode { Opcode::NearCall(_) => { - if let Some(last) = self.stack.last_mut() { - last.near_calls_after += 1; - } + self.increase_near_call_count(); } Opcode::FarCall(far_call) => { // We use parent gas for properly calculating gas used in the trace. @@ -53,10 +51,8 @@ impl DynTracer> for CallTracer { }; self.handle_far_call_op_code_refunds_enhancement(state, memory, &mut current_call); - self.stack.push(FarcallAndNearCallCount { - farcall: current_call, - near_calls_after: 0, - }); + + self.push_call_and_update_stats(current_call, 0); } Opcode::Ret(ret_code) => { self.handle_ret_op_code_refunds_enhancement(state, memory, ret_code); @@ -189,7 +185,7 @@ impl CallTracer { if current_call.near_calls_after > 0 { current_call.near_calls_after -= 1; - self.stack.push(current_call); + self.push_call_and_update_stats(current_call.farcall, current_call.near_calls_after); return; } @@ -205,7 +201,7 @@ impl CallTracer { if let Some(parent_call) = self.stack.last_mut() { parent_call.farcall.calls.push(current_call.farcall); } else { - self.stack.push(current_call); + self.push_call_and_update_stats(current_call.farcall, current_call.near_calls_after); } } } diff --git a/core/lib/multivm/src/tracers/call_tracer/vm_virtual_blocks/mod.rs b/core/lib/multivm/src/tracers/call_tracer/vm_virtual_blocks/mod.rs index c78593b40e7..631d4d2081c 100644 --- a/core/lib/multivm/src/tracers/call_tracer/vm_virtual_blocks/mod.rs +++ b/core/lib/multivm/src/tracers/call_tracer/vm_virtual_blocks/mod.rs @@ -12,7 +12,7 @@ use zksync_types::U256; use crate::interface::{ dyn_tracers::vm_1_3_3::DynTracer, VmExecutionResultAndLogs, VmRevertReason, }; -use crate::tracers::call_tracer::{CallTracer, FarcallAndNearCallCount}; +use crate::tracers::call_tracer::CallTracer; use crate::vm_virtual_blocks::{ ExecutionEndTracer, ExecutionProcessing, HistoryMode, SimpleMemory, VmTracer, }; @@ -27,9 +27,7 @@ impl DynTracer> for CallTracer { ) { match data.opcode.variant.opcode { Opcode::NearCall(_) => { - if let Some(last) = self.stack.last_mut() { - last.near_calls_after += 1; - } + self.increase_near_call_count(); } Opcode::FarCall(far_call) => { // We use parent gas for properly calculating gas used in the trace. @@ -50,10 +48,7 @@ impl DynTracer> for CallTracer { }; self.handle_far_call_op_code_virtual_blocks(state, data, memory, &mut current_call); - self.stack.push(FarcallAndNearCallCount { - farcall: current_call, - near_calls_after: 0, - }); + self.push_call_and_update_stats(current_call, 0); } Opcode::Ret(ret_code) => { self.handle_ret_op_code_virtual_blocks(state, data, memory, ret_code); @@ -187,7 +182,7 @@ impl CallTracer { if current_call.near_calls_after > 0 { current_call.near_calls_after -= 1; - self.stack.push(current_call); + self.push_call_and_update_stats(current_call.farcall, current_call.near_calls_after); return; } @@ -203,7 +198,7 @@ impl CallTracer { if let Some(parent_call) = self.stack.last_mut() { parent_call.farcall.calls.push(current_call.farcall); } else { - self.stack.push(current_call); + self.push_call_and_update_stats(current_call.farcall, current_call.near_calls_after); } } }