diff --git a/.gitignore b/.gitignore index f35eaefcd9..ba4ef6141a 100644 --- a/.gitignore +++ b/.gitignore @@ -22,3 +22,4 @@ env/ node_modules/ *DS_Store *.iml +bin/bench-transaction/bench-tx-vm-profile.json diff --git a/CHANGELOG.md b/CHANGELOG.md index 42617cfbc6..c3dcbcf41a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,6 +15,7 @@ - [BREAKING] Added `get_asset` and `get_initial_asset` kernel procedures and removed `get_balance`, `get_initial_balance` and `has_non_fungible_asset` kernel procedures ([#2369](https://github.com/0xMiden/miden-base/pull/2369)). - Introduced `TokenMetadata` type to encapsulate fungible faucet metadata ([#2344](https://github.com/0xMiden/miden-base/issues/2344)). - Added `StandardNote::from_script_root()` and `StandardNote::name()` methods, and exposed `NoteType` `PUBLIC`/`PRIVATE` masks as public constants ([#2411](https://github.com/0xMiden/miden-base/pull/2411)). +- Added VM profile export functionality to benchmark transaction execution, enabling detailed cycle counting and trace length analysis ([#2391](https://github.com/0xMiden/miden-base/pull/2391)). ### Changes diff --git a/Cargo.lock b/Cargo.lock index ed558bfe4e..86cc357fb0 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -64,6 +64,15 @@ version = "0.2.21" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "683d7910e743518b0e34f1186f92494becacb047c7b6bf616c96772180fef923" +[[package]] +name = "android_system_properties" +version = "0.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "819e7219dbd41043ac279b19830f2efc897156490d7fd6ea916720117ee66311" +dependencies = [ + "libc", +] + [[package]] name = "anes" version = "0.1.6" @@ -224,6 +233,7 @@ name = "bench-transaction" version = "0.1.0" dependencies = [ "anyhow", + "chrono", "criterion 0.6.0", "miden-protocol", "miden-standards", @@ -231,6 +241,7 @@ dependencies = [ "miden-tx", "serde", "serde_json", + "tempfile", "tokio", ] @@ -350,6 +361,20 @@ dependencies = [ "zeroize", ] +[[package]] +name = "chrono" +version = "0.4.43" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fac4744fb15ae8337dc853fee7fb3f4e48c0fbaa23d0afe49c447b4fab126118" +dependencies = [ + "iana-time-zone", + "js-sys", + "num-traits", + "serde", + "wasm-bindgen", + "windows-link", +] + [[package]] name = "ciborium" version = "0.2.2" @@ -458,6 +483,12 @@ version = "0.4.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "3d52eff69cd5e647efe296129160853a42795992097e8af39800e1060caeea9b" +[[package]] +name = "core-foundation-sys" +version = "0.8.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "773648b94d0e5d620f64f280777445740e61fe701025087ec8b57f45c791888b" + [[package]] name = "cpufeatures" version = "0.2.17" @@ -1101,6 +1132,30 @@ dependencies = [ "digest", ] +[[package]] +name = "iana-time-zone" +version = "0.1.65" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e31bc9ad994ba00e440a8aa5c9ef0ec67d5cb5e5cb0cc7f8b744a35b389cc470" +dependencies = [ + "android_system_properties", + "core-foundation-sys", + "iana-time-zone-haiku", + "js-sys", + "log", + "wasm-bindgen", + "windows-core", +] + +[[package]] +name = "iana-time-zone-haiku" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f31827a206f56af32e590ba56d5d2d085f558508192593743f16b2306495269f" +dependencies = [ + "cc", +] + [[package]] name = "indenter" version = "0.3.4" @@ -3324,6 +3379,41 @@ version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" +[[package]] +name = "windows-core" +version = "0.62.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b8e83a14d34d0623b51dce9581199302a221863196a1dde71a7663a4c2be9deb" +dependencies = [ + "windows-implement", + "windows-interface", + "windows-link", + "windows-result", + "windows-strings", +] + +[[package]] +name = "windows-implement" +version = "0.60.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "053e2e040ab57b9dc951b72c264860db7eb3b0200ba345b4e4c3b14f67855ddf" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.114", +] + +[[package]] +name = "windows-interface" +version = "0.59.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3f316c4a2570ba26bbec722032c4099d8c8bc095efccdc15688708623367e358" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.114", +] + [[package]] name = "windows-link" version = "0.2.1" @@ -3339,6 +3429,15 @@ dependencies = [ "windows-link", ] +[[package]] +name = "windows-strings" +version = "0.5.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7837d08f69c77cf6b07689544538e017c1bfcf57e34b4c0ff58e6c2cd3b37091" +dependencies = [ + "windows-link", +] + [[package]] name = "windows-sys" version = "0.48.0" diff --git a/bin/bench-note-checker/benches/benchmarks.rs b/bin/bench-note-checker/benches/benchmarks.rs index b09a138f72..63f2911a0f 100644 --- a/bin/bench-note-checker/benches/benchmarks.rs +++ b/bin/bench-note-checker/benches/benchmarks.rs @@ -22,8 +22,13 @@ fn note_checker_benchmarks(c: &mut Criterion) { setup_mixed_notes_benchmark(MixedNotesConfig { failing_note_count: failing_count }) .expect("failed to set up mixed notes benchmark"); - b.to_async(tokio::runtime::Builder::new_current_thread().enable_all().build().unwrap()) - .iter(|| async { black_box(run_mixed_notes_check(&setup).await) }); + b.to_async( + tokio::runtime::Builder::new_current_thread() + .enable_all() + .build() + .expect("failed to build tokio runtime"), + ) + .iter(|| async { black_box(run_mixed_notes_check(&setup).await) }); }); } diff --git a/bin/bench-transaction/Cargo.toml b/bin/bench-transaction/Cargo.toml index e932ad28fa..0aa28d224f 100644 --- a/bin/bench-transaction/Cargo.toml +++ b/bin/bench-transaction/Cargo.toml @@ -24,9 +24,11 @@ miden-tx = { workspace = true } # External dependencies anyhow = { workspace = true } +chrono = { features = ["serde"], version = "0.4" } serde = { features = ["derive"], workspace = true } serde_json = { features = ["preserve_order"], package = "serde_json", version = "1.0" } tokio = { features = ["macros", "rt"], workspace = true } [dev-dependencies] criterion = { features = ["async_tokio", "html_reports"], version = "0.6" } +tempfile = { version = "3.19" } diff --git a/bin/bench-transaction/src/cycle_counting_benchmarks/utils.rs b/bin/bench-transaction/src/cycle_counting_benchmarks/utils.rs index 49a916c390..3036e29d9d 100644 --- a/bin/bench-transaction/src/cycle_counting_benchmarks/utils.rs +++ b/bin/bench-transaction/src/cycle_counting_benchmarks/utils.rs @@ -1,6 +1,7 @@ extern crate alloc; pub use alloc::collections::BTreeMap; pub use alloc::string::String; +use std::collections::HashMap; use std::fs::{read_to_string, write}; use std::path::Path; @@ -10,6 +11,14 @@ use serde::Serialize; use serde_json::{Value, from_str, to_string_pretty}; use super::ExecutionBenchmark; +use crate::vm_profile::{ + InstructionMix, + OperationDetails, + PhaseProfile, + ProcedureProfile, + TransactionKernelProfile, + VmProfile, +}; // MEASUREMENTS PRINTER // ================================================================================================ @@ -102,3 +111,495 @@ pub fn write_bench_results_to_json( Ok(()) } + +/// Writes the VM execution profile to a JSON file for synthetic benchmark generation. +/// +/// This exports a machine-readable profile that describes the transaction kernel's +/// instruction mix and cycle characteristics, which can be used by miden-vm to +/// generate representative synthetic benchmarks. +pub fn write_vm_profile( + path: &Path, + tx_benchmarks: &[(ExecutionBenchmark, MeasurementsPrinter)], +) -> anyhow::Result<()> { + // Aggregate measurements across all benchmarks to create a representative profile + let mut total_prologue = 0usize; + let mut total_notes_processing = 0usize; + let mut total_tx_script = 0usize; + let mut total_epilogue = 0usize; + let mut total_auth = 0usize; + let mut count = 0usize; + + for (_, measurements) in tx_benchmarks { + total_prologue += measurements.prologue; + total_notes_processing += measurements.notes_processing; + total_tx_script += measurements.tx_script_processing; + total_epilogue += measurements.epilogue.total; + total_auth += measurements.epilogue.auth_procedure; + count += 1; + } + + if count == 0 { + anyhow::bail!("No benchmark results to aggregate"); + } + + // Calculate averages + let avg_prologue = (total_prologue / count) as u64; + let avg_notes_processing = (total_notes_processing / count) as u64; + let avg_tx_script = (total_tx_script / count) as u64; + let avg_epilogue = (total_epilogue / count) as u64; + let avg_auth = (total_auth / count) as u64; + + // Build phase map + let mut phases = HashMap::new(); + phases.insert( + "prologue".to_string(), + PhaseProfile { + cycles: avg_prologue, + operations: HashMap::new(), /* TODO: Add operation counting when VM instrumentation + * is available */ + }, + ); + phases.insert( + "notes_processing".to_string(), + PhaseProfile { + cycles: avg_notes_processing, + operations: HashMap::new(), + }, + ); + phases.insert( + "tx_script_processing".to_string(), + PhaseProfile { + cycles: avg_tx_script, + operations: HashMap::new(), + }, + ); + phases.insert( + "epilogue".to_string(), + PhaseProfile { + cycles: avg_epilogue, + operations: HashMap::new(), + }, + ); + + // Calculate total cycles + let total_cycles = avg_prologue + avg_notes_processing + avg_tx_script + avg_epilogue; + let trace_main_len = total_cycles; + let trace_padded_len = total_cycles.next_power_of_two(); + + // Estimate instruction mix based on known characteristics + // Auth procedure (signature verification) dominates at ~85% of epilogue + let signature_ratio = if avg_epilogue > 0 { + (avg_auth as f64) / (total_cycles as f64) + } else { + 0.0 + }; + + // Remaining cycles are distributed among other operations + let remaining = 1.0 - signature_ratio; + let instruction_mix = InstructionMix { + signature_verify: signature_ratio, + hashing: remaining * 0.5, // Hashing is significant in remaining work + memory: remaining * 0.2, // Memory operations + control_flow: remaining * 0.2, // Loops, conditionals + arithmetic: remaining * 0.1, // Basic arithmetic + }; + let instruction_mix = normalize_instruction_mix(instruction_mix); + + // Key procedures - auth is the heavyweight + let key_procedures = vec![ProcedureProfile { + name: "auth_procedure".to_string(), + cycles: avg_auth, + invocations: 1, + }]; + + // Build operation details based on instruction mix + // These are estimates based on typical transaction patterns + let mut operation_details = Vec::new(); + + // Minimum threshold for including an operation type (avoid floating-point noise) + const MIN_MIX_RATIO: f64 = 0.001; // 0.1% + const SIGNATURE_VERIFY_CYCLE_COST: u64 = 59859; + // Threshold for applying minimum iteration counts (only for substantial workloads) + const MIN_CYCLES_FOR_MINIMUMS: u64 = 10000; + let apply_minimums = total_cycles >= MIN_CYCLES_FOR_MINIMUMS; + let apply_minimum = |raw: u64, minimum: u64| -> u64 { + if apply_minimums && raw >= minimum / 2 { + raw.max(minimum) + } else { + raw + } + }; + + // Signature verification operations + // Only include if the calculated count is at least 1 (avoid inflating small workloads) + let sig_count = signature_verify_count(total_cycles, &instruction_mix); + // Only include signature verification if we have at least 1 full verification + // This avoids inflating operation_details with a 60K cycle op when the + // actual average auth cost is much smaller + if sig_count > 0 { + operation_details.push(OperationDetails { + op_type: "falcon512_verify".to_string(), + input_sizes: vec![64, 32], // PK commitment (64 bytes), message (32 bytes) + iterations: sig_count, + cycle_cost: SIGNATURE_VERIFY_CYCLE_COST, + }); + } + + // Hashing operations - split hashing ratio between hperm (80%) and hmerge (20%) + // This approximates observed patterns where permutations dominate over merges + const HPERM_HASHING_RATIO: f64 = 0.8; + const HMERGE_HASHING_RATIO: f64 = 0.2; + + if instruction_mix.hashing >= MIN_MIX_RATIO { + let hperm_count = + (total_cycles as f64 * instruction_mix.hashing * HPERM_HASHING_RATIO) as u64; + if hperm_count > 0 { + operation_details.push(OperationDetails { + op_type: "hperm".to_string(), + input_sizes: vec![48], // 12 field elements state + iterations: apply_minimum(hperm_count, 100), + cycle_cost: 1, + }); + } + + let hmerge_count = + (total_cycles as f64 * instruction_mix.hashing * HMERGE_HASHING_RATIO / 16.0) as u64; + if hmerge_count > 0 { + operation_details.push(OperationDetails { + op_type: "hmerge".to_string(), + input_sizes: vec![32, 32], // Two 32-byte digests + iterations: apply_minimum(hmerge_count, 10), + cycle_cost: 16, + }); + } + } + + // Memory operations + if instruction_mix.memory >= MIN_MIX_RATIO { + let mem_count = (total_cycles as f64 * instruction_mix.memory / 10.0) as u64; + if mem_count > 0 { + operation_details.push(OperationDetails { + op_type: "load_store".to_string(), + input_sizes: vec![32], // Word-sized memory operations + iterations: apply_minimum(mem_count, 10), + cycle_cost: 10, + }); + } + } + + // Arithmetic operations + if instruction_mix.arithmetic >= MIN_MIX_RATIO { + let arith_count = (total_cycles as f64 * instruction_mix.arithmetic) as u64; + if arith_count > 0 { + operation_details.push(OperationDetails { + op_type: "arithmetic".to_string(), + input_sizes: vec![8], // Field element operations + iterations: apply_minimum(arith_count, 10), + cycle_cost: 1, + }); + } + } + + // Control flow operations + if instruction_mix.control_flow >= MIN_MIX_RATIO { + let control_count = (total_cycles as f64 * instruction_mix.control_flow / 5.0) as u64; + if control_count > 0 { + operation_details.push(OperationDetails { + op_type: "control_flow".to_string(), + input_sizes: vec![], + iterations: apply_minimum(control_count, 10), + cycle_cost: 5, + }); + } + } + + let profile = VmProfile { + profile_version: "1.0".to_string(), + source: "miden-base/bin/bench-transaction".to_string(), + timestamp: chrono::Utc::now().to_rfc3339(), + miden_vm_version: env!("CARGO_PKG_VERSION").to_string(), + transaction_kernel: TransactionKernelProfile { + total_cycles, + trace_main_len: Some(trace_main_len), + trace_padded_len: Some(trace_padded_len), + phases, + instruction_mix, + key_procedures, + operation_details, + }, + }; + + let json = serde_json::to_string_pretty(&profile)?; + write(path, json).context("failed to write VM profile to file")?; + + println!("VM profile exported to: {}", path.display()); + Ok(()) +} + +const MIX_SUM_TOLERANCE: f64 = 0.001; + +fn normalize_instruction_mix(instruction_mix: InstructionMix) -> InstructionMix { + let mix_sum = instruction_mix.arithmetic + + instruction_mix.hashing + + instruction_mix.memory + + instruction_mix.control_flow + + instruction_mix.signature_verify; + if mix_sum > 0.0 && (mix_sum - 1.0).abs() > MIX_SUM_TOLERANCE { + InstructionMix { + arithmetic: instruction_mix.arithmetic / mix_sum, + hashing: instruction_mix.hashing / mix_sum, + memory: instruction_mix.memory / mix_sum, + control_flow: instruction_mix.control_flow / mix_sum, + signature_verify: instruction_mix.signature_verify / mix_sum, + } + } else { + instruction_mix + } +} + +fn signature_verify_count(total_cycles: u64, instruction_mix: &InstructionMix) -> u64 { + const MIN_MIX_RATIO: f64 = 0.001; // 0.1% + const SIGNATURE_VERIFY_CYCLE_COST: u64 = 59859; + if instruction_mix.signature_verify >= MIN_MIX_RATIO { + (total_cycles as f64 * instruction_mix.signature_verify + / SIGNATURE_VERIFY_CYCLE_COST as f64) as u64 + } else { + 0 + } +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::context_setups::tx_consume_single_p2id_note; + + /// Test that operation details are generated with correct hashing split + #[test] + fn operation_details_hashing_split_ratio() { + let total_cycles = 100000u64; + let instruction_mix = InstructionMix { + arithmetic: 0.05, + hashing: 0.45, + memory: 0.08, + control_flow: 0.05, + signature_verify: 0.37, + }; + + // Simulate the calculation from write_vm_profile + let hperm_count = (total_cycles as f64 * instruction_mix.hashing * 0.8) as u64; + let hmerge_count = (total_cycles as f64 * instruction_mix.hashing * 0.2 / 16.0) as u64; + + // hperm should get ~80% of hashing cycles + assert_eq!(hperm_count, 36000); + // hmerge should get ~20% of hashing cycles (divided by 16 for cycle cost) + assert_eq!(hmerge_count, 562); + + // Verify the ratio is maintained + let hperm_cycles = hperm_count; + let hmerge_cycles = hmerge_count * 16; + let total_hashing_cycles = hperm_cycles + hmerge_cycles; + + // Should be close to 45% of total cycles (allowing for truncation) + let hashing_ratio = total_hashing_cycles as f64 / total_cycles as f64; + assert!((hashing_ratio - 0.45).abs() < 0.01); + } + + /// Test that small workloads don't get minimums applied + #[test] + fn small_workload_no_minimum_inflation() { + let total_cycles = 5000u64; // Below MIN_CYCLES_FOR_MINIMUMS threshold + + // For small workloads, counts should be raw calculated values + let sig_count = (total_cycles as f64 * 0.37 / 59859.0) as u64; + let hperm_count = (total_cycles as f64 * 0.45 * 0.8) as u64; + + // These should be 0 or small, not inflated to minimums + assert_eq!(sig_count, 0); // Too small for a full sig verify + assert_eq!(hperm_count, 1800); // Raw calculation, not max(100, 1800) + } + + /// Test that large workloads get minimums applied + #[test] + fn large_workload_minimums_applied() { + let total_cycles = 50000u64; // Above MIN_CYCLES_FOR_MINIMUMS threshold + let apply_minimums = total_cycles >= 10000; + + assert!(apply_minimums); + + // With minimums, small counts get bumped up + let hmerge_count = (total_cycles as f64 * 0.45 * 0.2 / 16.0) as u64; + assert_eq!(hmerge_count, 281); // Raw calculation + + // With minimum applied (raw count already above half-minimum) + let hmerge_with_min = if apply_minimums && hmerge_count >= 5 { + hmerge_count.max(10) + } else { + hmerge_count + }; + assert_eq!(hmerge_with_min, 281); // Already above minimum + + // For a very small count that would be below minimum + let tiny_count = 5u64; + let tiny_with_min = if apply_minimums && tiny_count >= 5 { + tiny_count.max(10) + } else { + tiny_count + }; + assert_eq!(tiny_with_min, 10); + } + + /// Test that minimums are skipped when raw count is far below minimum + #[test] + fn minimums_skipped_when_raw_far_below_minimum() { + let total_cycles = 10000u64; // Apply minimums + let apply_minimums = total_cycles >= 10000; + + let raw_count = 11u64; + let minimum = 100u64; + let adjusted = if apply_minimums && raw_count >= minimum / 2 { + raw_count.max(minimum) + } else { + raw_count + }; + + assert_eq!(adjusted, 11); + } + + /// Test MIN_MIX_RATIO threshold - operations below threshold excluded + #[test] + fn min_mix_ratio_threshold_excludes_small_ratios() { + let _total_cycles = 50000u64; + let min_mix_ratio = 0.001; // 0.1% + + // Very small ratio below threshold + let tiny_ratio = 0.0005; + assert!(tiny_ratio < min_mix_ratio); + + // Should be excluded from operation_details + let should_include = tiny_ratio > min_mix_ratio; + assert!(!should_include); + + // Ratio above threshold should be included + let normal_ratio = 0.05; + assert!(normal_ratio > min_mix_ratio); + } + + /// Test that normalization updates signature operation counts + #[test] + fn instruction_mix_normalization_updates_signature_ratio() { + let unnormalized_mix = InstructionMix { + arithmetic: 0.05, + hashing: 0.4, + memory: 0.2, + control_flow: 0.05, + signature_verify: 0.6, + }; + + let normalized_mix = normalize_instruction_mix(unnormalized_mix.clone()); + let mix_sum = normalized_mix.arithmetic + + normalized_mix.hashing + + normalized_mix.memory + + normalized_mix.control_flow + + normalized_mix.signature_verify; + assert!((mix_sum - 1.0).abs() < MIX_SUM_TOLERANCE); + + let total_cycles = 100000u64; + let unnormalized_sig_count = signature_verify_count(total_cycles, &unnormalized_mix); + let normalized_sig_count = signature_verify_count(total_cycles, &normalized_mix); + + assert_eq!(unnormalized_sig_count, 1); + assert_eq!(normalized_sig_count, 0); + } + + /// Test boundary at total_cycles == 10000 + #[test] + fn minimums_boundary_at_10000_cycles() { + // Just below threshold + let below_threshold = 9999u64; + let apply_minimums_below = below_threshold >= 10000; + assert!(!apply_minimums_below); + + // At threshold + let at_threshold = 10000u64; + let apply_minimums_at = at_threshold >= 10000; + assert!(apply_minimums_at); + + // Above threshold + let above_threshold = 10001u64; + let apply_minimums_above = above_threshold >= 10000; + assert!(apply_minimums_above); + } + + /// Test that zero-iteration operations are suppressed + #[test] + fn zero_iteration_operations_suppressed() { + let total_cycles = 1000u64; + + // Very small counts that truncate to 0 + let sig_count = (total_cycles as f64 * 0.37 / 59859.0) as u64; + assert_eq!(sig_count, 0); + + // Should not be included in operation_details + let should_include = sig_count > 0; + assert!(!should_include); + } + + /// Test that write_vm_profile emits operation_details in the exported profile + #[test] + fn write_vm_profile_emits_operation_details() { + let measurements = MeasurementsPrinter { + prologue: 1000, + notes_processing: 1000, + note_execution: BTreeMap::new(), + tx_script_processing: 1000, + epilogue: EpilogueMeasurements::from_parts(7000, 1000, 0), + }; + + let tx_benchmarks = vec![(ExecutionBenchmark::ConsumeSingleP2ID, measurements)]; + let temp_dir = tempfile::tempdir().expect("create temp dir"); + let path = temp_dir.path().join("vm_profile_write_test.json"); + + write_vm_profile(&path, &tx_benchmarks).expect("write vm profile"); + + let json = read_to_string(&path).expect("read vm profile"); + let profile: VmProfile = serde_json::from_str(&json).expect("deserialize vm profile"); + + assert!(!profile.transaction_kernel.operation_details.is_empty()); + assert!( + profile + .transaction_kernel + .operation_details + .iter() + .all(|detail| detail.iterations > 0) + ); + } + + /// Test that ratios can be extracted from the real transaction kernel + #[tokio::test(flavor = "current_thread")] + async fn write_vm_profile_extracts_real_kernel_mix() { + let measurements = tx_consume_single_p2id_note() + .expect("build tx") + .execute() + .await + .map(miden_protocol::transaction::TransactionMeasurements::from) + .expect("execute tx"); + + let tx_benchmarks = + vec![(ExecutionBenchmark::ConsumeSingleP2ID, MeasurementsPrinter::from(measurements))]; + + let temp_dir = tempfile::tempdir().expect("create temp dir"); + let path = temp_dir.path().join("vm_profile_real_kernel.json"); + write_vm_profile(&path, &tx_benchmarks).expect("write vm profile"); + + let json = read_to_string(&path).expect("read vm profile"); + let profile: VmProfile = serde_json::from_str(&json).expect("deserialize vm profile"); + + let mix = &profile.transaction_kernel.instruction_mix; + let mix_sum = + mix.arithmetic + mix.hashing + mix.memory + mix.control_flow + mix.signature_verify; + assert!(mix_sum.is_finite()); + assert!((mix_sum - 1.0).abs() < MIX_SUM_TOLERANCE); + assert!(profile.transaction_kernel.total_cycles > 0); + assert!(!profile.transaction_kernel.operation_details.is_empty()); + } +} diff --git a/bin/bench-transaction/src/lib.rs b/bin/bench-transaction/src/lib.rs index 882a85de80..0a9f40bc7e 100644 --- a/bin/bench-transaction/src/lib.rs +++ b/bin/bench-transaction/src/lib.rs @@ -1 +1,2 @@ pub mod context_setups; +pub mod vm_profile; diff --git a/bin/bench-transaction/src/main.rs b/bin/bench-transaction/src/main.rs index 651be7993b..d017dd451a 100644 --- a/bin/bench-transaction/src/main.rs +++ b/bin/bench-transaction/src/main.rs @@ -12,9 +12,11 @@ use context_setups::{ tx_create_single_p2id_note, }; +mod vm_profile; + mod cycle_counting_benchmarks; use cycle_counting_benchmarks::ExecutionBenchmark; -use cycle_counting_benchmarks::utils::write_bench_results_to_json; +use cycle_counting_benchmarks::utils::{write_bench_results_to_json, write_vm_profile}; #[tokio::main(flavor = "current_thread")] async fn main() -> Result<()> { @@ -51,6 +53,11 @@ async fn main() -> Result<()> { ), ]; + // Export VM profile for synthetic benchmark generation (before write_bench_results_to_json + // consumes the data) + let profile_path = Path::new("bin/bench-transaction/bench-tx-vm-profile.json"); + write_vm_profile(profile_path, &benchmark_results)?; + // store benchmark results in the JSON file write_bench_results_to_json(path, benchmark_results)?; diff --git a/bin/bench-transaction/src/time_counting_benchmarks/prove.rs b/bin/bench-transaction/src/time_counting_benchmarks/prove.rs index 5dafb4604d..b3912e19a5 100644 --- a/bin/bench-transaction/src/time_counting_benchmarks/prove.rs +++ b/bin/bench-transaction/src/time_counting_benchmarks/prove.rs @@ -36,35 +36,43 @@ fn core_benchmarks(c: &mut Criterion) { .warm_up_time(Duration::from_millis(1000)); execute_group.bench_function(BENCH_EXECUTE_TX_CONSUME_SINGLE_P2ID, |b| { - b.to_async(tokio::runtime::Builder::new_current_thread().build().unwrap()) - .iter_batched( - || { - // prepare the transaction context - tx_consume_single_p2id_note() - .expect("failed to create a context which consumes single P2ID note") - }, - |tx_context| async move { - // benchmark the transaction execution - black_box(tx_context.execute().await) - }, - BatchSize::SmallInput, - ); + b.to_async( + tokio::runtime::Builder::new_current_thread() + .build() + .expect("failed to build tokio runtime"), + ) + .iter_batched( + || { + // prepare the transaction context + tx_consume_single_p2id_note() + .expect("failed to create a context which consumes single P2ID note") + }, + |tx_context| async move { + // benchmark the transaction execution + black_box(tx_context.execute().await) + }, + BatchSize::SmallInput, + ); }); execute_group.bench_function(BENCH_EXECUTE_TX_CONSUME_TWO_P2ID, |b| { - b.to_async(tokio::runtime::Builder::new_current_thread().build().unwrap()) - .iter_batched( - || { - // prepare the transaction context - tx_consume_two_p2id_notes() - .expect("failed to create a context which consumes two P2ID notes") - }, - |tx_context| async move { - // benchmark the transaction execution - black_box(tx_context.execute().await) - }, - BatchSize::SmallInput, - ); + b.to_async( + tokio::runtime::Builder::new_current_thread() + .build() + .expect("failed to build tokio runtime"), + ) + .iter_batched( + || { + // prepare the transaction context + tx_consume_two_p2id_notes() + .expect("failed to create a context which consumes two P2ID notes") + }, + |tx_context| async move { + // benchmark the transaction execution + black_box(tx_context.execute().await) + }, + BatchSize::SmallInput, + ); }); execute_group.finish(); @@ -80,45 +88,53 @@ fn core_benchmarks(c: &mut Criterion) { .warm_up_time(Duration::from_millis(1000)); execute_and_prove_group.bench_function(BENCH_EXECUTE_AND_PROVE_TX_CONSUME_SINGLE_P2ID, |b| { - b.to_async(tokio::runtime::Builder::new_current_thread().build().unwrap()) - .iter_batched( - || { - // prepare the transaction context - tx_consume_single_p2id_note() - .expect("failed to create a context which consumes single P2ID note") - }, - |tx_context| async move { - // benchmark the transaction execution and proving - black_box(prove_transaction( - tx_context - .execute() - .await - .expect("execution of the single P2ID note consumption tx failed"), - )) - }, - BatchSize::SmallInput, - ); + b.to_async( + tokio::runtime::Builder::new_current_thread() + .build() + .expect("failed to build tokio runtime"), + ) + .iter_batched( + || { + // prepare the transaction context + tx_consume_single_p2id_note() + .expect("failed to create a context which consumes single P2ID note") + }, + |tx_context| async move { + // benchmark the transaction execution and proving + black_box(prove_transaction( + tx_context + .execute() + .await + .expect("execution of the single P2ID note consumption tx failed"), + )) + }, + BatchSize::SmallInput, + ); }); execute_and_prove_group.bench_function(BENCH_EXECUTE_AND_PROVE_TX_CONSUME_TWO_P2ID, |b| { - b.to_async(tokio::runtime::Builder::new_current_thread().build().unwrap()) - .iter_batched( - || { - // prepare the transaction context - tx_consume_two_p2id_notes() - .expect("failed to create a context which consumes two P2ID notes") - }, - |tx_context| async move { - // benchmark the transaction execution and proving - black_box(prove_transaction( - tx_context - .execute() - .await - .expect("execution of the two P2ID note consumption tx failed"), - )) - }, - BatchSize::SmallInput, - ); + b.to_async( + tokio::runtime::Builder::new_current_thread() + .build() + .expect("failed to build tokio runtime"), + ) + .iter_batched( + || { + // prepare the transaction context + tx_consume_two_p2id_notes() + .expect("failed to create a context which consumes two P2ID notes") + }, + |tx_context| async move { + // benchmark the transaction execution and proving + black_box(prove_transaction( + tx_context + .execute() + .await + .expect("execution of the two P2ID note consumption tx failed"), + )) + }, + BatchSize::SmallInput, + ); }); execute_and_prove_group.finish(); diff --git a/bin/bench-transaction/src/vm_profile.rs b/bin/bench-transaction/src/vm_profile.rs new file mode 100644 index 0000000000..b5cf347e91 --- /dev/null +++ b/bin/bench-transaction/src/vm_profile.rs @@ -0,0 +1,248 @@ +//! VM execution profile types for synthetic benchmark generation + +use std::collections::HashMap; + +use serde::{Deserialize, Serialize}; + +/// Versioned VM profile exported from transaction kernel benchmarks +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct VmProfile { + pub profile_version: String, + pub source: String, + pub timestamp: String, + pub miden_vm_version: String, + pub transaction_kernel: TransactionKernelProfile, +} + +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct TransactionKernelProfile { + pub total_cycles: u64, + #[serde(default)] + pub trace_main_len: Option, + #[serde(default)] + pub trace_padded_len: Option, + pub phases: HashMap, + pub instruction_mix: InstructionMix, + pub key_procedures: Vec, + /// Detailed operation information for generating realistic benchmarks + #[serde(default)] + pub operation_details: Vec, +} + +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct PhaseProfile { + pub cycles: u64, + pub operations: HashMap, +} + +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct InstructionMix { + pub arithmetic: f64, + pub hashing: f64, + pub memory: f64, + pub control_flow: f64, + pub signature_verify: f64, +} + +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct ProcedureProfile { + pub name: String, + pub cycles: u64, + pub invocations: u64, +} + +/// Detailed information about a specific operation type +/// Used by synthetic benchmark generators to create realistic workloads +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct OperationDetails { + /// Operation type identifier (e.g., "falcon512_verify", "hperm", "hmerge") + pub op_type: String, + /// Size of each input in bytes (for operations with variable input sizes) + pub input_sizes: Vec, + /// Number of times this operation is executed + pub iterations: u64, + /// Estimated cycle cost per operation (for validation) + pub cycle_cost: u64, +} + +#[cfg(test)] +mod tests { + use super::*; + + /// Test that old VM profiles without operation_details can be deserialized + /// This ensures backward compatibility with existing profiles + #[test] + fn deserialize_profile_without_operation_details() { + let json = r#"{ + "profile_version": "1.0", + "source": "test", + "timestamp": "2025-01-01T00:00:00Z", + "miden_vm_version": "0.20.0", + "transaction_kernel": { + "total_cycles": 1000, + "phases": {}, + "instruction_mix": { + "arithmetic": 0.2, + "hashing": 0.2, + "memory": 0.2, + "control_flow": 0.2, + "signature_verify": 0.2 + }, + "key_procedures": [] + } + }"#; + + let profile: VmProfile = + serde_json::from_str(json).expect("should deserialize old profile"); + assert!(profile.transaction_kernel.operation_details.is_empty()); + assert_eq!(profile.transaction_kernel.total_cycles, 1000); + } + + /// Test that profiles with operation_details deserialize correctly + #[test] + fn deserialize_profile_with_operation_details() { + let json = r#"{ + "profile_version": "1.0", + "source": "test", + "timestamp": "2025-01-01T00:00:00Z", + "miden_vm_version": "0.20.0", + "transaction_kernel": { + "total_cycles": 100000, + "phases": {}, + "instruction_mix": { + "arithmetic": 0.05, + "hashing": 0.45, + "memory": 0.08, + "control_flow": 0.05, + "signature_verify": 0.37 + }, + "key_procedures": [], + "operation_details": [ + { + "op_type": "falcon512_verify", + "input_sizes": [64, 32], + "iterations": 1, + "cycle_cost": 59859 + }, + { + "op_type": "hperm", + "input_sizes": [48], + "iterations": 1000, + "cycle_cost": 1 + } + ] + } + }"#; + + let profile: VmProfile = + serde_json::from_str(json).expect("should deserialize profile with details"); + assert_eq!(profile.transaction_kernel.operation_details.len(), 2); + assert_eq!(profile.transaction_kernel.operation_details[0].op_type, "falcon512_verify"); + assert_eq!(profile.transaction_kernel.operation_details[1].iterations, 1000); + } + + /// Calculate total cycles from operation details + fn calculate_operation_cycles(details: &[OperationDetails]) -> u64 { + details.iter().map(|d| d.iterations * d.cycle_cost).sum() + } + + /// Test that operation_details cycles are consistent with total_cycles + /// This validates that the operation breakdown roughly matches the total + #[test] + fn operation_details_consistent_with_total_cycles() { + // Profile with realistic operation mix + let profile = VmProfile { + profile_version: "1.0".to_string(), + source: "test".to_string(), + timestamp: "2025-01-01T00:00:00Z".to_string(), + miden_vm_version: "0.20.0".to_string(), + transaction_kernel: TransactionKernelProfile { + total_cycles: 73123, + trace_main_len: None, + trace_padded_len: None, + phases: HashMap::new(), + instruction_mix: InstructionMix { + arithmetic: 0.05, + hashing: 0.45, + memory: 0.08, + control_flow: 0.05, + signature_verify: 0.37, + }, + key_procedures: vec![], + operation_details: vec![ + OperationDetails { + op_type: "falcon512_verify".to_string(), + input_sizes: vec![64, 32], + iterations: 1, + cycle_cost: 59859, + }, + OperationDetails { + op_type: "hperm".to_string(), + input_sizes: vec![48], + iterations: 10000, + cycle_cost: 1, + }, + ], + }, + }; + + let operation_cycles = + calculate_operation_cycles(&profile.transaction_kernel.operation_details); + // Operation cycles should be within reasonable range of total_cycles + // (allowing for overhead, other operations, and estimation errors) + assert!( + operation_cycles <= profile.transaction_kernel.total_cycles * 2, + "operation cycles ({}) should not exceed 2x total_cycles ({})", + operation_cycles, + profile.transaction_kernel.total_cycles + ); + + // For this profile, falcon512_verify dominates, so operation_cycles should be significant + assert!( + operation_cycles >= profile.transaction_kernel.total_cycles / 2, + "operation cycles ({}) should be at least 50% of total_cycles ({})", + operation_cycles, + profile.transaction_kernel.total_cycles + ); + } + + /// Test that tiny workloads don't get inflated by minimums + #[test] + fn tiny_workload_no_minimum_inflation() { + // Small profile with low operation counts + let profile = VmProfile { + profile_version: "1.0".to_string(), + source: "test".to_string(), + timestamp: "2025-01-01T00:00:00Z".to_string(), + miden_vm_version: "0.20.0".to_string(), + transaction_kernel: TransactionKernelProfile { + total_cycles: 100, // Very small workload + trace_main_len: None, + trace_padded_len: None, + phases: HashMap::new(), + instruction_mix: InstructionMix { + arithmetic: 0.5, + hashing: 0.0, + memory: 0.0, + control_flow: 0.0, + signature_verify: 0.5, + }, + key_procedures: vec![], + operation_details: vec![ + // Without minimums, these should be small counts + OperationDetails { + op_type: "arithmetic".to_string(), + input_sizes: vec![8], + iterations: 50, // 50 * 1 = 50 cycles, not inflated to 10 + cycle_cost: 1, + }, + ], + }, + }; + + let operation_cycles = + calculate_operation_cycles(&profile.transaction_kernel.operation_details); + // For tiny workloads without minimums applied, iterations should be small + assert_eq!(operation_cycles, 50); + } +}