From ffc962c6fd53a6e0374b25927d8d6b2de3c5f270 Mon Sep 17 00:00:00 2001 From: Ori Ziv Date: Thu, 14 Mar 2024 16:31:12 +0200 Subject: [PATCH] Added option to print used resources for tests. commit-id:008454fd fixup! Added option to print used resources for tests. --- crates/bin/cairo-test/src/main.rs | 4 + crates/cairo-lang-runner/src/casm_run/mod.rs | 49 ++++++--- crates/cairo-lang-runner/src/casm_run/test.rs | 12 +- crates/cairo-lang-runner/src/lib.rs | 53 ++++++--- crates/cairo-lang-test-runner/src/lib.rs | 104 ++++++++++++------ 5 files changed, 158 insertions(+), 64 deletions(-) diff --git a/crates/bin/cairo-test/src/main.rs b/crates/bin/cairo-test/src/main.rs index 0d6a3ab0e7a..0ae11e92ce2 100644 --- a/crates/bin/cairo-test/src/main.rs +++ b/crates/bin/cairo-test/src/main.rs @@ -59,6 +59,9 @@ struct Args { /// Should disable gas calculation. #[arg(long)] gas_disabled: bool, + /// Whether to print resource usage after each test. + #[arg(long, default_value_t = false)] + print_resource_usage: bool, } fn main() -> anyhow::Result<()> { @@ -73,6 +76,7 @@ fn main() -> anyhow::Result<()> { include_ignored: args.include_ignored, run_profiler: args.run_profiler.into(), gas_enabled: !args.gas_disabled, + print_resource_usage: args.print_resource_usage, }; let runner = TestRunner::new(&args.path, args.starknet, args.allow_warnings, config)?; diff --git a/crates/cairo-lang-runner/src/casm_run/mod.rs b/crates/cairo-lang-runner/src/casm_run/mod.rs index 38913d4e4c9..4551a38d59f 100644 --- a/crates/cairo-lang-runner/src/casm_run/mod.rs +++ b/crates/cairo-lang-runner/src/casm_run/mod.rs @@ -29,7 +29,9 @@ use cairo_vm::vm::errors::cairo_run_errors::CairoRunError; use cairo_vm::vm::errors::hint_errors::HintError; use cairo_vm::vm::errors::memory_errors::MemoryError; use cairo_vm::vm::errors::vm_errors::VirtualMachineError; -use cairo_vm::vm::runners::cairo_runner::{CairoRunner, ResourceTracker, RunResources}; +use cairo_vm::vm::runners::cairo_runner::{ + CairoRunner, ExecutionResources, ResourceTracker, RunResources, +}; use cairo_vm::vm::vm_core::VirtualMachine; use dict_manager::DictManagerExecScope; use itertools::Itertools; @@ -41,7 +43,7 @@ use {ark_secp256k1 as secp256k1, ark_secp256r1 as secp256r1}; use self::contract_address::calculate_contract_address; use self::dict_manager::DictSquashExecScope; use crate::short_string::{as_cairo_short_string, as_cairo_short_string_ex}; -use crate::{Arg, RunResultValue, SierraCasmRunner}; +use crate::{Arg, RunResultValue, SierraCasmRunner, StarknetExecutionResources}; #[cfg(test)] mod test; @@ -92,14 +94,16 @@ struct Secp256r1ExecutionScope { /// HintProcessor for Cairo compiler hints. pub struct CairoHintProcessor<'a> { /// The Cairo runner. - #[allow(dead_code)] pub runner: Option<&'a SierraCasmRunner>, - // A mapping from a string that represents a hint to the hint object. + /// A mapping from a string that represents a hint to the hint object. pub string_to_hint: HashMap, - // The starknet state. + /// The starknet state. pub starknet_state: StarknetState, - // Maintains the resources of the run. + /// Maintains the resources of the run. pub run_resources: RunResources, + /// Resources used during syscalls - does not include resources used during the current VM run. + /// At the end of the run - adding both would result in the actual expected resource usage. + pub syscalls_used_resources: StarknetExecutionResources, } pub fn cell_ref_to_relocatable(cell_ref: &CellRef, vm: &VirtualMachine) -> Relocatable { @@ -131,7 +135,6 @@ pub struct StarknetState { /// The values of addresses in the simulated storage per contract. storage: HashMap>, /// A mapping from contract address to class hash. - #[allow(dead_code)] deployed_contracts: HashMap, /// A mapping from contract address to logs. logs: HashMap, @@ -651,7 +654,9 @@ impl<'a> CairoHintProcessor<'a> { } Ok(()) }; - match std::str::from_utf8(&selector).unwrap() { + let selector = std::str::from_utf8(&selector).unwrap(); + *self.syscalls_used_resources.syscalls.entry(selector.into()).or_default() += 1; + match selector { "StorageWrite" => execute_handle_helper(&mut |system_buffer, gas_counter| { self.storage_write( gas_counter, @@ -1117,7 +1122,7 @@ impl<'a> CairoHintProcessor<'a> { self.starknet_state.clone(), ) .expect("Internal runner error."); - + self.syscalls_used_resources += res.used_resources; *gas_counter = res.gas_counter.unwrap().to_usize().unwrap(); match res.value { RunResultValue::Success(value) => { @@ -2085,8 +2090,6 @@ pub struct RunFunctionContext<'a> { pub data_len: usize, } -type RunFunctionRes = (Vec>, usize); - /// Runs CairoRunner on layout with prime. /// Allows injecting custom CairoRunner. pub fn run_function_with_runner( @@ -2128,7 +2131,17 @@ pub fn build_cairo_runner( CairoRunner::new(&program, "all_cairo", false).map_err(CairoRunError::from).map_err(Box::new) } -/// Runs `bytecode` on layout with prime, and returns the memory layout and ap value. +/// The result of [run_function]. +pub struct RunFunctionResult { + /// The memory layout after the run. + pub memory: Vec>, + /// The ap value after the run. + pub ap: usize, + /// The used resources after the run. + pub used_resources: ExecutionResources, +} + +/// Runs `bytecode` on layout with prime, and returns the matching [RunFunctionResult]. /// Allows injecting custom HintProcessor. pub fn run_function<'a, 'b: 'a>( vm: &mut VirtualMachine, @@ -2139,15 +2152,21 @@ pub fn run_function<'a, 'b: 'a>( ) -> Result<(), Box>, hint_processor: &mut dyn HintProcessor, hints_dict: HashMap>, -) -> Result> { +) -> Result> { let data: Vec = bytecode.map(Felt252::from).map(MaybeRelocatable::from).collect(); let data_len = data.len(); let mut runner = build_cairo_runner(data, builtins, hints_dict)?; run_function_with_runner(vm, data_len, additional_initialization, hint_processor, &mut runner)?; - - Ok((runner.relocated_memory, vm.get_relocated_trace().unwrap().last().unwrap().ap)) + let used_resources = runner + .get_execution_resources(vm) + .expect("Failed to get execution resources, but the run was successful."); + Ok(RunFunctionResult { + memory: runner.relocated_memory, + ap: vm.get_relocated_trace().unwrap().last().unwrap().ap, + used_resources, + }) } /// Formats the given felts as a debug string. diff --git a/crates/cairo-lang-runner/src/casm_run/test.rs b/crates/cairo-lang-runner/src/casm_run/test.rs index b58ecc82f58..2554f060542 100644 --- a/crates/cairo-lang-runner/src/casm_run/test.rs +++ b/crates/cairo-lang-runner/src/casm_run/test.rs @@ -12,7 +12,7 @@ use test_case::test_case; use super::format_for_debug; use crate::casm_run::contract_address::calculate_contract_address; -use crate::casm_run::run_function; +use crate::casm_run::{run_function, RunFunctionResult}; use crate::short_string::{as_cairo_short_string, as_cairo_short_string_ex}; use crate::{build_hints_dict, CairoHintProcessor, StarknetState}; @@ -116,6 +116,7 @@ fn test_runner(function: CasmContext, n_returns: usize, expected: &[i128]) { string_to_hint, starknet_state: StarknetState::default(), run_resources: RunResources::default(), + syscalls_used_resources: Default::default(), }; let bytecode: Vec = function .instructions @@ -123,7 +124,7 @@ fn test_runner(function: CasmContext, n_returns: usize, expected: &[i128]) { .flat_map(|instruction| instruction.assemble().encode()) .collect(); - let (cells, ap) = run_function( + let RunFunctionResult { memory, ap, .. } = run_function( &mut VirtualMachine::new(true), bytecode.iter(), vec![], @@ -132,9 +133,9 @@ fn test_runner(function: CasmContext, n_returns: usize, expected: &[i128]) { hints_dict, ) .expect("Running code failed."); - let cells = cells.into_iter().skip(ap - n_returns); + let ret_memory = memory.into_iter().skip(ap - n_returns); assert_eq!( - cells.take(n_returns).map(|cell| cell.unwrap()).collect_vec(), + ret_memory.take(n_returns).map(|cell| cell.unwrap()).collect_vec(), expected.iter().copied().map(Felt252::from).collect_vec() ); } @@ -154,11 +155,12 @@ fn test_allocate_segment() { string_to_hint, starknet_state: StarknetState::default(), run_resources: RunResources::default(), + syscalls_used_resources: Default::default(), }; let bytecode: Vec = casm.instructions.iter().flat_map(|instruction| instruction.assemble().encode()).collect(); - let (memory, ap) = run_function( + let RunFunctionResult { memory, ap, .. } = run_function( &mut VirtualMachine::new(true), bytecode.iter(), vec![], diff --git a/crates/cairo-lang-runner/src/lib.rs b/crates/cairo-lang-runner/src/lib.rs index 5098a1fbf7f..9fad64806d9 100644 --- a/crates/cairo-lang-runner/src/lib.rs +++ b/crates/cairo-lang-runner/src/lib.rs @@ -34,7 +34,7 @@ use cairo_lang_utils::unordered_hash_map::UnorderedHashMap; use cairo_vm::hint_processor::hint_processor_definition::HintProcessor; use cairo_vm::serde::deserialize_program::{BuiltinName, HintParams}; use cairo_vm::vm::errors::cairo_run_errors::CairoRunError; -use cairo_vm::vm::runners::cairo_runner::RunResources; +use cairo_vm::vm::runners::cairo_runner::{ExecutionResources, RunResources}; use cairo_vm::vm::trace::trace_entry::TraceEntry; use cairo_vm::vm::vm_core::VirtualMachine; use casm_run::hint_to_hint_params; @@ -45,7 +45,7 @@ use num_traits::ToPrimitive; use profiling::{user_function_idx_by_sierra_statement_idx, ProfilingInfo}; use thiserror::Error; -use crate::casm_run::RunFunctionContext; +use crate::casm_run::{RunFunctionContext, RunFunctionResult}; pub mod casm_run; pub mod profiling; @@ -85,6 +85,7 @@ pub struct RunResultStarknet { pub memory: Vec>, pub value: RunResultValue, pub starknet_state: StarknetState, + pub used_resources: StarknetExecutionResources, /// The profiling info of the run, if requested. pub profiling_info: Option, } @@ -95,10 +96,31 @@ pub struct RunResult { pub gas_counter: Option, pub memory: Vec>, pub value: RunResultValue, + pub used_resources: ExecutionResources, /// The profiling info of the run, if requested. pub profiling_info: Option, } +/// The execution resources in a run. +/// Extends [ExecutionResources] by including the used syscalls for starknet. +#[derive(Debug, Eq, PartialEq, Clone, Default)] +pub struct StarknetExecutionResources { + /// The basic execution resources. + pub basic_resources: ExecutionResources, + /// The used syscalls. + pub syscalls: HashMap, +} + +impl std::ops::AddAssign for StarknetExecutionResources { + /// Adds the resources of `other` to `self`. + fn add_assign(&mut self, other: Self) { + self.basic_resources += &other.basic_resources; + for (k, v) in other.syscalls { + *self.syscalls.entry(k).or_default() += v; + } + } +} + /// The ran function return value. #[derive(Debug, Eq, PartialEq, Clone)] pub enum RunResultValue { @@ -226,19 +248,24 @@ impl SierraCasmRunner { starknet_state, string_to_hint, run_resources: RunResources::default(), + syscalls_used_resources: Default::default(), }; - let RunResult { gas_counter, memory, value, profiling_info } = self.run_function( - func, - &mut hint_processor, - hints_dict, - assembled_program.bytecode.iter(), - builtins, - )?; + let RunResult { gas_counter, memory, value, used_resources, profiling_info } = self + .run_function( + func, + &mut hint_processor, + hints_dict, + assembled_program.bytecode.iter(), + builtins, + )?; + let mut all_used_resources = hint_processor.syscalls_used_resources; + all_used_resources.basic_resources += &used_resources; Ok(RunResultStarknet { gas_counter, memory, value, starknet_state: hint_processor.starknet_state, + used_resources: all_used_resources, profiling_info, }) } @@ -262,7 +289,7 @@ impl SierraCasmRunner { { let return_types = self.generic_id_and_size_from_concrete(&func.signature.ret_types); - let (cells, ap) = casm_run::run_function( + let RunFunctionResult { memory, ap, used_resources } = casm_run::run_function( vm, bytecode, builtins, @@ -270,7 +297,7 @@ impl SierraCasmRunner { hint_processor, hints_dict, )?; - let (results_data, gas_counter) = Self::get_results_data(&return_types, &cells, ap); + let (results_data, gas_counter) = Self::get_results_data(&return_types, &memory, ap); assert!(results_data.len() <= 1); let value = if results_data.is_empty() { @@ -280,14 +307,14 @@ impl SierraCasmRunner { let (ty, values) = results_data[0].clone(); let inner_ty = self.inner_type_from_panic_wrapper(&ty, func).map(|it| self.type_sizes[&it]); - Self::handle_main_return_value(inner_ty, values, &cells) + Self::handle_main_return_value(inner_ty, values, &memory) }; let profiling_info = self.run_profiler.as_ref().map(|config| { self.collect_profiling_info(vm.get_relocated_trace().unwrap(), config.clone()) }); - Ok(RunResult { gas_counter, memory: cells, value, profiling_info }) + Ok(RunResult { gas_counter, memory, value, used_resources, profiling_info }) } /// Collects profiling info of the current run using the trace. diff --git a/crates/cairo-lang-test-runner/src/lib.rs b/crates/cairo-lang-test-runner/src/lib.rs index 87efc5fe768..1fa5943cdaf 100644 --- a/crates/cairo-lang-test-runner/src/lib.rs +++ b/crates/cairo-lang-test-runner/src/lib.rs @@ -1,3 +1,4 @@ +use std::collections::HashMap; use std::path::Path; use std::sync::{Arc, Mutex}; use std::vec::IntoIter; @@ -15,7 +16,9 @@ use cairo_lang_runner::casm_run::format_next_item; use cairo_lang_runner::profiling::{ ProfilingInfo, ProfilingInfoProcessor, ProfilingInfoProcessorParams, }; -use cairo_lang_runner::{ProfilingInfoCollectionConfig, RunResultValue, SierraCasmRunner}; +use cairo_lang_runner::{ + ProfilingInfoCollectionConfig, RunResultValue, SierraCasmRunner, StarknetExecutionResources, +}; use cairo_lang_sierra::extensions::gas::CostTokenType; use cairo_lang_sierra::ids::FunctionId; use cairo_lang_sierra::program::{Program, StatementIdx}; @@ -93,7 +96,7 @@ impl CompiledTestRunner { self.compiled, self.config.include_ignored, self.config.ignored, - self.config.filter, + &self.config.filter, ); let TestsSummary { passed, failed, ignored, failed_run_results } = run_tests( @@ -103,10 +106,7 @@ impl CompiledTestRunner { compiled.function_set_costs, compiled.contracts_info, compiled.statements_functions, - RunTestsFlags { - run_profiler: self.config.run_profiler != RunProfilerConfig::None, - gas_enabled: self.config.gas_enabled, - }, + &self.config, )?; if failed.is_empty() { @@ -176,6 +176,8 @@ pub struct TestRunConfig { pub run_profiler: RunProfilerConfig, /// Whether to enable gas calculation. pub gas_enabled: bool, + /// Whether to print used resources after each test. + pub print_resource_usage: bool, } /// The test cases compiler. @@ -256,7 +258,7 @@ pub fn filter_test_cases( compiled: TestCompilation, include_ignored: bool, ignored: bool, - filter: String, + filter: &str, ) -> (TestCompilation, usize) { let total_tests_count = compiled.named_tests.len(); let named_tests = compiled.named_tests @@ -268,7 +270,7 @@ pub fn filter_test_cases( } (func, test) }) - .filter(|(name, _)| name.contains(&filter)) + .filter(|(name, _)| name.contains(filter)) // Filtering unignored tests in `ignored` mode .filter(|(_, test)| !ignored || test.ignored) .collect_vec(); @@ -289,6 +291,8 @@ struct TestResult { status: TestStatus, /// The gas usage of the run if relevant. gas_usage: Option, + /// The used resources of the run. + used_resources: StarknetExecutionResources, /// The profiling info of the run, if requested. profiling_info: Option, } @@ -301,14 +305,6 @@ pub struct TestsSummary { failed_run_results: Vec, } -/// Tests run configuration flags. -pub struct RunTestsFlags { - /// Run the profiler. - run_profiler: bool, - /// Whether to enable gas validation for [`SierraCasmRunner`]. - gas_enabled: bool, -} - /// Runs the tests and process the results for a summary. pub fn run_tests( db: Option<&RootDatabase>, @@ -317,11 +313,11 @@ pub fn run_tests( function_set_costs: OrderedHashMap>, contracts_info: OrderedHashMap, statements_functions: UnorderedHashMap, - args: RunTestsFlags, + config: &TestRunConfig, ) -> Result { let runner = SierraCasmRunner::new( sierra_program.clone(), - if args.gas_enabled { + if config.gas_enabled { Some(MetadataComputationConfig { function_set_costs, linear_gas_solver: true, @@ -333,7 +329,12 @@ pub fn run_tests( None }, contracts_info, - if args.run_profiler { Some(ProfilingInfoCollectionConfig::default()) } else { None }, + match config.run_profiler { + RunProfilerConfig::None => None, + RunProfilerConfig::Cairo | RunProfilerConfig::Sierra => { + Some(ProfilingInfoCollectionConfig::default()) + } + }, ) .with_context(|| "Failed setting up runner.")?; let suffix = if named_tests.len() != 1 { "s" } else { "" }; @@ -362,6 +363,7 @@ pub fn run_tests( process_by_cairo_function: false, ..ProfilingInfoProcessorParams::default() }, + config.print_resource_usage, ); }); } else { @@ -377,6 +379,7 @@ pub fn run_tests( &sierra_program, &statements_functions, &ProfilingInfoProcessorParams::default(), + config.print_resource_usage, ); }); } @@ -424,6 +427,7 @@ fn run_single_test( .or_else(|| { runner.initial_required_gas(func).map(|gas| gas.into_or_panic::()) }), + used_resources: result.used_resources, profiling_info: result.profiling_info, }), )) @@ -437,34 +441,72 @@ fn update_summary( sierra_program: &Program, statements_functions: &UnorderedHashMap, profiling_params: &ProfilingInfoProcessorParams, + print_resource_usage: bool, ) { let mut wrapped_summary = wrapped_summary.lock().unwrap(); if wrapped_summary.is_err() { return; } - let (name, status) = match test_result { - Ok((name, status)) => (name, status), + let (name, opt_result) = match test_result { + Ok((name, opt_result)) => (name, opt_result), Err(err) => { *wrapped_summary = Err(err); return; } }; let summary = wrapped_summary.as_mut().unwrap(); - let (res_type, status_str, gas_usage, profiling_info) = match status { - Some(TestResult { status: TestStatus::Success, gas_usage, profiling_info }) => { - (&mut summary.passed, "ok".bright_green(), gas_usage, profiling_info) - } - Some(TestResult { status: TestStatus::Fail(run_result), gas_usage, profiling_info }) => { - summary.failed_run_results.push(run_result); - (&mut summary.failed, "fail".bright_red(), gas_usage, profiling_info) - } - None => (&mut summary.ignored, "ignored".bright_yellow(), None, None), - }; + let (res_type, status_str, gas_usage, used_resources, profiling_info) = + if let Some(result) = opt_result { + let (res_type, status_str) = match result.status { + TestStatus::Success => (&mut summary.passed, "ok".bright_green()), + TestStatus::Fail(run_result) => { + summary.failed_run_results.push(run_result); + (&mut summary.failed, "fail".bright_red()) + } + }; + ( + res_type, + status_str, + result.gas_usage, + print_resource_usage.then_some(result.used_resources), + result.profiling_info, + ) + } else { + (&mut summary.ignored, "ignored".bright_yellow(), None, None, None) + }; if let Some(gas_usage) = gas_usage { println!("test {name} ... {status_str} (gas usage est.: {gas_usage})"); } else { println!("test {name} ... {status_str}"); } + if let Some(used_resources) = used_resources { + let filtered = used_resources.basic_resources.filter_unused_builtins(); + // Prints the used resources per test. E.g.: + // ```ignore + // test cairo_level_tests::interoperability::test_contract_not_deployed ... ok (gas usage est.: 77320) + // steps: 42 + // memory holes: 20 + // builtins: ("range_check_builtin": 3) + // syscalls: ("CallContract": 1) + // test cairo_level_tests::events::test_pop_log ... ok (gas usage est.: 55440) + // steps: 306 + // memory holes: 35 + // builtins: ("range_check_builtin": 24) + // syscalls: ("EmitEvent": 2) + // ``` + println!(" steps: {}", filtered.n_steps); + println!(" memory holes: {}", filtered.n_memory_holes); + let print_resource_map = |m: HashMap<_, _>, name| { + if !m.is_empty() { + println!( + " {name}: ({})", + m.into_iter().sorted().map(|(k, v)| format!(r#""{k}": {v}"#)).join(", ") + ); + } + }; + print_resource_map(filtered.builtin_instance_counter, "builtins"); + print_resource_map(used_resources.syscalls, "syscalls"); + } if let Some(profiling_info) = profiling_info { let profiling_processor = ProfilingInfoProcessor::new(db, sierra_program.clone(), statements_functions.clone());