diff --git a/CHANGELOG.md b/CHANGELOG.md index 9c2b25e9a3..9577c269af 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -36,6 +36,8 @@ Both branches support Stwo prover opcodes (Blake2s, QM31) since v2.0.0. * refactor: Make HintReference dereference count explicit in `get_maybe_relocatable_from_reference` [#2296](https://github.com/lambdaclass/cairo-vm/pull/2296) +* chore: Add logs to `cairo_run_program_with_initial_scope` [#2319](https://github.com/lambdaclass/cairo-vm/pull/2319) + #### [3.1.0] - 2026-01-19 **Summary**: Introduces stateful VM hooks via the `StepHooks` trait, enabling debuggers and instrumentation tools. diff --git a/Cargo.lock b/Cargo.lock index a96148c734..a5cee912e1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -916,6 +916,7 @@ dependencies = [ "starknet-crypto", "starknet-types-core 0.2.0", "thiserror", + "tracing", "wasm-bindgen-test", "zip", ] diff --git a/Cargo.toml b/Cargo.toml index 01de1956ff..dfe5df14aa 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -46,6 +46,7 @@ starknet-crypto = { version = "0.8.0", default-features = false, features = [ "alloc", ] } sha3 = { version = "0.10.8", default-features = false } +tracing = { version = "0.1.40", default-features = false } indoc = { version = "2.0.5", default-features = false } lazy_static = { version = "1.4.0", default-features = false, features = [ "spin_no_std", diff --git a/vm/Cargo.toml b/vm/Cargo.toml index 1d00564983..8846cad1a0 100644 --- a/vm/Cargo.toml +++ b/vm/Cargo.toml @@ -46,6 +46,7 @@ serde = { workspace = true } serde_json = { workspace = true } starknet-crypto = { workspace = true } sha3 = { workspace = true } +tracing = { workspace = true } indoc = { workspace = true } lazy_static = { workspace = true } nom = { workspace = true } diff --git a/vm/src/cairo_run.rs b/vm/src/cairo_run.rs index c04be8d9e3..8e709520c8 100644 --- a/vm/src/cairo_run.rs +++ b/vm/src/cairo_run.rs @@ -19,6 +19,7 @@ use crate::types::exec_scope::ExecutionScopes; #[cfg(feature = "test_utils")] use arbitrary::{self, Arbitrary}; use core::fmt; +use tracing::{info, span, Level}; #[cfg_attr(feature = "test_utils", derive(Arbitrary))] pub struct CairoRunConfig<'a> { @@ -74,6 +75,7 @@ pub fn cairo_run_program_with_initial_scope( hint_processor: &mut dyn HintProcessor, exec_scopes: ExecutionScopes, ) -> Result { + let _span = span!(Level::INFO, "cairo run").entered(); let secure_run = cairo_run_config .secure_run .unwrap_or(!cairo_run_config.proof_mode); @@ -93,9 +95,11 @@ pub fn cairo_run_program_with_initial_scope( cairo_runner.exec_scopes = exec_scopes; + info!(layout = ?cairo_run_config.layout, proof_mode = ?cairo_run_config.proof_mode, trace_enabled = ?cairo_run_config.trace_enabled, disable_trace_padding = ?cairo_run_config.disable_trace_padding, allow_missing_builtins = ?allow_missing_builtins, "Initializing Cairo runner."); let end = cairo_runner.initialize(allow_missing_builtins)?; // check step calculation + info!("Running until PC."); cairo_runner .run_until_pc(end, hint_processor) .map_err(|err| VmException::from_vm_error(&cairo_runner, err))?; @@ -105,6 +109,8 @@ pub fn cairo_run_program_with_initial_scope( // rather than the one after it. cairo_runner.run_for_steps(1, hint_processor)?; } + + info!(disable_trace_padding = ?cairo_run_config.disable_trace_padding, fill_holes = ?cairo_run_config.fill_holes, "Ending run."); cairo_runner.end_run( cairo_run_config.disable_trace_padding, false, @@ -112,13 +118,19 @@ pub fn cairo_run_program_with_initial_scope( cairo_run_config.fill_holes, )?; + info!("Reading return values."); cairo_runner.read_return_values(allow_missing_builtins)?; if cairo_run_config.proof_mode { + info!("In proof mode, finalizing segments."); cairo_runner.finalize_segments()?; } + if secure_run { + info!("In secure run, verifying secure runner."); verify_secure_runner(&cairo_runner, true, None)?; } + + info!(relocate_mem = ?cairo_run_config.relocate_mem, relocate_trace = ?cairo_run_config.relocate_trace, "Relocating."); cairo_runner.relocate( cairo_run_config.relocate_mem, cairo_run_config.relocate_trace, diff --git a/vm/src/vm/runners/cairo_runner.rs b/vm/src/vm/runners/cairo_runner.rs index 2d2b362307..54b64fc83d 100644 --- a/vm/src/vm/runners/cairo_runner.rs +++ b/vm/src/vm/runners/cairo_runner.rs @@ -59,6 +59,7 @@ use super::{ cairo_pie::{self, CairoPie, CairoPieMetadata, CairoPieVersion}, }; use crate::types::instance_definitions::mod_instance_def::ModInstanceDef; +use tracing::info; pub const ORDERED_BUILTIN_LIST: &[BuiltinName] = &[ BuiltinName::output, @@ -275,14 +276,19 @@ impl CairoRunner { } pub fn initialize(&mut self, allow_missing_builtins: bool) -> Result { + info!("Initializing builtins."); self.initialize_builtins(allow_missing_builtins)?; + info!("Initializing segments."); self.initialize_segments(None); + info!("Initializing main entrypoint."); let end = self.initialize_main_entrypoint()?; + info!("Initializing zero segments."); for builtin_runner in self.vm.builtin_runners.iter_mut() { if let BuiltinRunner::Mod(runner) = builtin_runner { runner.initialize_zero_segment(&mut self.vm.segments); } } + info!("Initializing VM."); self.initialize_vm()?; Ok(end) } @@ -903,6 +909,7 @@ impl CairoRunner { return Err(RunnerError::EndRunCalledTwice.into()); } + info!("Relocating memory."); self.vm.segments.memory.relocate_memory()?; self.vm.end_run(&self.exec_scopes, fill_holes)?; @@ -910,8 +917,10 @@ impl CairoRunner { return Ok(()); } + info!("Computing effective sizes of segments."); self.vm.segments.compute_effective_sizes(); if self.is_proof_mode() && !disable_trace_padding { + info!("in proof mode and enabling trace padding, running until next power of 2."); self.run_until_next_power_of_2(hint_processor)?; loop { match self.check_used_cells() {