Skip to content

Commit ffd9210

Browse files
ilitteriCopilotgianbelinche
authored
chore(l2): granulize SP1 zkVM cycles report (#5226)
**Motivation** For SP1 we already have profiling tools like Samply to generate flamegraphs of the execution and get an idea of the spent cycles during the execution, but it is not always desired to run those. As an alternative, granulating the current cycle's report is very useful. **Description** - Decouple L1 stateless validation - Add `report_cycles!` macro that wraps a block of code with optional cycle-tracking prints - Wrap code blocks inside the `report_cycles!` macro to track cycles of them. **Example Output** ```shell 2025-11-06T20:27:17.842628Z INFO ethrex_replay::fetcher: Getting block 23721540 data from cache 2025-11-06T20:27:22.669322Z INFO execute: sp1_core_executor::syscalls::write: ┌╴read_input 2025-11-06T20:27:23.074825Z INFO execute: sp1_core_executor::syscalls::write: └╴12,868,356 cycles 2025-11-06T20:27:23.074862Z INFO execute: sp1_core_executor::syscalls::write: ┌╴execution 2025-11-06T20:27:23.074915Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴GuestProgramState::from(execution_witness) stderr: WARNING: Using insecure random number generator. 2025-11-06T20:27:28.337580Z INFO execute: sp1_core_executor::syscalls::write: │ └╴191,414,247 cycles 2025-11-06T20:27:28.337737Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴initialize_block_header_hashes 2025-11-06T20:27:28.338575Z INFO execute: sp1_core_executor::syscalls::write: │ └╴11,402 cycles 2025-11-06T20:27:28.338592Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴get_first_invalid_block_hash 2025-11-06T20:27:28.338617Z INFO execute: sp1_core_executor::syscalls::write: │ └╴585 cycles 2025-11-06T20:27:28.338707Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴state_trie_root 2025-11-06T20:27:29.836352Z INFO execute: sp1_core_executor::syscalls::write: │ └╴38,685,313 cycles 2025-11-06T20:27:29.836390Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴validate_block 2025-11-06T20:27:29.837260Z INFO execute: sp1_core_executor::syscalls::write: │ └╴16,766 cycles 2025-11-06T20:27:29.837278Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴setup_evm 2025-11-06T20:27:29.837297Z INFO execute: sp1_core_executor::syscalls::write: │ └╴458 cycles 2025-11-06T20:27:29.837310Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴execute_block 2025-11-06T20:27:57.108787Z INFO execute: sp1_core_executor::syscalls::write: │ └╴531,651,252 cycles 2025-11-06T20:27:57.108819Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴get_state_transitions 2025-11-06T20:27:57.175020Z INFO execute: sp1_core_executor::syscalls::write: │ └╴2,383,891 cycles 2025-11-06T20:27:57.175052Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴apply_account_updates 2025-11-06T20:27:59.351855Z INFO execute: sp1_core_executor::syscalls::write: │ └╴60,042,986 cycles 2025-11-06T20:27:59.381137Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴validate_gas_and_receipts 2025-11-06T20:27:59.381168Z INFO execute: sp1_core_executor::syscalls::write: │ └╴379 cycles 2025-11-06T20:27:59.381180Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴validate_receipts_root 2025-11-06T20:27:59.621535Z INFO execute: sp1_core_executor::syscalls::write: │ └╴7,450,196 cycles 2025-11-06T20:27:59.621572Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴validate_requests_hash 2025-11-06T20:27:59.621785Z INFO execute: sp1_core_executor::syscalls::write: │ └╴2,734 cycles 2025-11-06T20:27:59.621851Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴get_final_state_root 2025-11-06T20:28:00.570636Z INFO execute: sp1_core_executor::syscalls::write: │ └╴24,414,357 cycles 2025-11-06T20:28:00.570669Z INFO execute: sp1_core_executor::syscalls::write: │ ┌╴validate_state_root 2025-11-06T20:28:00.570689Z INFO execute: sp1_core_executor::syscalls::write: │ └╴624 cycles 2025-11-06T20:28:00.652210Z INFO execute: sp1_core_executor::syscalls::write: └╴858,494,608 cycles 2025-11-06T20:28:00.652242Z INFO execute: sp1_core_executor::syscalls::write: ┌╴commit_public_inputs 2025-11-06T20:28:00.652577Z INFO execute: sp1_core_executor::syscalls::write: └╴1,632 cycles 2025-11-06T20:28:00.731639Z INFO execute: sp1_prover: gas: 1145215937 2025-11-06T20:28:00.733918Z INFO ethrex_prover_lib::backend::sp1: Successfully executed SP1 program in 38.09s 2025-11-06T20:28:00.734204Z INFO ethrex_replay::report: [mainnet] Block: 23721540, Gas: 20284615, #Txs: 223, Execution Time: 42s 794ms | https://etherscan.io/block/23721540 ``` --------- Co-authored-by: Copilot <[email protected]> Co-authored-by: Gianbelinche <[email protected]>
1 parent 4657f36 commit ffd9210

File tree

4 files changed

+160
-14
lines changed

4 files changed

+160
-14
lines changed

crates/l2/prover/src/guest_program/Cargo.toml

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -39,5 +39,9 @@ sp1 = ["dep:sp1-build", "dep:sp1-sdk"]
3939
l2 = []
4040
c-kzg = ["ethrex-vm/c-kzg", "ethrex-common/c-kzg"]
4141

42+
# When this feature is enabled, the cycles used in the code inside the
43+
# report_cycles! macro will be reported to stdout when running inside SP1 zkVM.
44+
sp1-cycles = []
45+
4246
[lib]
4347
path = "./src/lib.rs"

crates/l2/prover/src/guest_program/src/execution.rs

Lines changed: 142 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,11 @@
11
use crate::input::ProgramInput;
22
use crate::output::ProgramOutput;
3+
use crate::report_cycles;
34

45
use ethrex_blockchain::error::ChainError;
56
use ethrex_blockchain::{
67
validate_block, validate_gas_used, validate_receipts_root, validate_requests_hash,
8+
validate_state_root,
79
};
810
use ethrex_common::types::AccountUpdate;
911
use ethrex_common::types::block_execution_witness::ExecutionWitness;
@@ -17,7 +19,7 @@ use ethrex_common::{H256, types::Block};
1719
use ethrex_l2_common::l1_messages::L1Message;
1820
use ethrex_rlp::encode::RLPEncode;
1921
use ethrex_vm::{Evm, EvmError, GuestProgramStateWrapper, VmDatabase};
20-
use std::collections::HashMap;
22+
use std::collections::{BTreeMap, HashMap};
2123

2224
#[cfg(feature = "l2")]
2325
use ethrex_common::types::{
@@ -116,35 +118,162 @@ pub fn execution_program(input: ProgramInput) -> Result<ProgramOutput, Stateless
116118
);
117119
}
118120

119-
stateless_validation_l1(&blocks, execution_witness, elasticity_multiplier, chain_id)
121+
stateless_validation_l1(blocks, execution_witness, elasticity_multiplier, chain_id)
120122
}
121123

122124
pub fn stateless_validation_l1(
123-
blocks: &[Block],
125+
blocks: Vec<Block>,
124126
execution_witness: ExecutionWitness,
125127
elasticity_multiplier: u64,
126128
chain_id: u64,
127129
) -> Result<ProgramOutput, StatelessExecutionError> {
128-
let StatelessResult {
129-
initial_state_hash,
130-
final_state_hash,
131-
last_block_hash,
132-
non_privileged_count,
133-
..
134-
} = execute_stateless(blocks, execution_witness, elasticity_multiplier, None)?;
130+
let guest_program_state: GuestProgramState =
131+
report_cycles("guest_program_state_initialization", || {
132+
execution_witness
133+
.try_into()
134+
.map_err(StatelessExecutionError::GuestProgramState)
135+
})?;
136+
137+
let mut wrapped_db = GuestProgramStateWrapper::new(guest_program_state);
138+
139+
let chain_config = wrapped_db.get_chain_config().map_err(|_| {
140+
StatelessExecutionError::Internal("No chain config in execution witness".to_string())
141+
})?;
142+
143+
// Hashing is an expensive operation in zkVMs, this way we avoid hashing twice
144+
// (once in get_first_invalid_block_hash(), later in validate_block()).
145+
report_cycles("initialize_block_header_hashes", || {
146+
wrapped_db.initialize_block_header_hashes(&blocks)
147+
})?;
148+
149+
// Validate execution witness' block hashes, except parent block hash (latest block hash).
150+
report_cycles("get_first_invalid_block_hash", || {
151+
if let Ok(Some(invalid_block_header)) = wrapped_db.get_first_invalid_block_hash() {
152+
return Err(StatelessExecutionError::InvalidBlockHash(
153+
invalid_block_header,
154+
));
155+
}
156+
Ok(())
157+
})?;
158+
159+
// Validate the initial state
160+
let parent_block_header = wrapped_db
161+
.get_block_parent_header(
162+
blocks
163+
.first()
164+
.ok_or(StatelessExecutionError::EmptyBatchError)?
165+
.header
166+
.number,
167+
)
168+
.map_err(StatelessExecutionError::GuestProgramState)?;
169+
170+
let initial_state_hash = report_cycles("state_trie_root", || {
171+
wrapped_db
172+
.state_trie_root()
173+
.map_err(StatelessExecutionError::GuestProgramState)
174+
})?;
175+
176+
if initial_state_hash != parent_block_header.state_root {
177+
return Err(StatelessExecutionError::InvalidInitialStateTrie);
178+
}
179+
180+
// Execute blocks
181+
let mut parent_block_header = &parent_block_header;
182+
let mut acc_account_updates: BTreeMap<Address, AccountUpdate> = BTreeMap::new();
183+
let mut acc_receipts = Vec::new();
184+
let mut non_privileged_count = 0;
185+
186+
for block in blocks.iter() {
187+
// Validate the block
188+
report_cycles("validate_block", || {
189+
validate_block(
190+
block,
191+
parent_block_header,
192+
&chain_config,
193+
elasticity_multiplier,
194+
)
195+
.map_err(StatelessExecutionError::BlockValidationError)
196+
})?;
197+
198+
let mut vm = report_cycles("setup_evm", || {
199+
let vm = Evm::new_for_l1(wrapped_db.clone());
200+
Ok::<_, StatelessExecutionError>(vm)
201+
})?;
202+
203+
let result = report_cycles("execute_block", || {
204+
vm.execute_block(block)
205+
.map_err(StatelessExecutionError::EvmError)
206+
})?;
207+
208+
let account_updates = report_cycles("get_state_transitions", || {
209+
vm.get_state_transitions()
210+
.map_err(StatelessExecutionError::EvmError)
211+
})?;
212+
213+
// Update db for the next block
214+
report_cycles("apply_account_updates", || {
215+
wrapped_db
216+
.apply_account_updates(&account_updates)
217+
.map_err(StatelessExecutionError::GuestProgramState)
218+
})?;
219+
// Update acc_account_updates
220+
for account in account_updates {
221+
let address = account.address;
222+
if let Some(existing) = acc_account_updates.get_mut(&address) {
223+
existing.merge(account);
224+
} else {
225+
acc_account_updates.insert(address, account);
226+
}
227+
}
228+
229+
report_cycles("validate_gas_and_receipts", || {
230+
validate_gas_used(&result.receipts, &block.header)
231+
.map_err(StatelessExecutionError::GasValidationError)
232+
})?;
233+
234+
report_cycles("validate_receipts_root", || {
235+
validate_receipts_root(&block.header, &result.receipts)
236+
.map_err(StatelessExecutionError::ReceiptsRootValidationError)
237+
})?;
238+
239+
// validate_requests_hash doesn't do anything for l2 blocks as this verifies l1 requests (messages, privileged transactions and consolidations)
240+
report_cycles("validate_requests_hash", || {
241+
validate_requests_hash(&block.header, &chain_config, &result.requests)
242+
.map_err(StatelessExecutionError::RequestsRootValidationError)
243+
})?;
244+
245+
non_privileged_count += block.body.transactions.len();
246+
acc_receipts.push(result.receipts);
247+
parent_block_header = &block.header;
248+
}
249+
250+
let final_state_root = report_cycles("get_final_state_root", || {
251+
wrapped_db
252+
.state_trie_root()
253+
.map_err(StatelessExecutionError::GuestProgramState)
254+
})?;
255+
256+
let last_block = blocks
257+
.last()
258+
.ok_or(StatelessExecutionError::EmptyBatchError)?;
259+
260+
report_cycles("validate_state_root", || {
261+
validate_state_root(&last_block.header, final_state_root)
262+
.map_err(|_chain_err| StatelessExecutionError::InvalidFinalStateTrie)
263+
})?;
135264

136265
Ok(ProgramOutput {
137266
initial_state_hash,
138-
final_state_hash,
267+
final_state_hash: final_state_root,
139268
#[cfg(feature = "l2")]
140269
l1messages_merkle_root: H256::zero(),
141270
#[cfg(feature = "l2")]
142271
privileged_transactions_hash: H256::zero(),
143272
#[cfg(feature = "l2")]
144273
blob_versioned_hash: H256::zero(),
145-
last_block_hash,
274+
last_block_hash: last_block.header.hash(),
146275
chain_id: chain_id.into(),
147-
non_privileged_count,
276+
non_privileged_count: non_privileged_count.into(),
148277
})
149278
}
150279

crates/l2/prover/src/guest_program/src/lib.rs

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -16,3 +16,16 @@ pub static ZKVM_RISC0_PROGRAM_VK: &str = include_str!(concat!("./risc0/out/riscv
1616
// To avoid compilation errors, we override it with an empty slice.
1717
#[cfg(any(clippy, not(feature = "risc0")))]
1818
pub const ZKVM_RISC0_PROGRAM_VK: &str = "";
19+
20+
/// Report cycles used in a code block when running inside SP1 zkVM.
21+
///
22+
/// When the feature "sp1-cycles" is enabled, it will print start and end cycle
23+
/// tracking messages that are compatible with SP1's cycle tracking system.
24+
pub fn report_cycles<T, E>(_label: &str, block: impl FnOnce() -> Result<T, E>) -> Result<T, E> {
25+
#[cfg(feature = "sp1-cycles")]
26+
println!("cycle-tracker-report-start: {_label}");
27+
let result = block();
28+
#[cfg(feature = "sp1-cycles")]
29+
println!("cycle-tracker-report-end: {_label}");
30+
result
31+
}

crates/l2/prover/src/guest_program/src/sp1/Cargo.toml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@ edition = "2024"
99
sp1-zkvm = { version = "=5.0.8" }
1010
rkyv = { version = "0.8.10", features = ["std", "unaligned"] }
1111

12-
guest_program = { path = "../../" }
12+
guest_program = { path = "../../", features = ["sp1-cycles"] }
1313

1414
ethrex-common = { path = "../../../../../../common", default-features = false }
1515
ethrex-storage = { path = "../../../../../../storage", default-features = false }

0 commit comments

Comments
 (0)