diff --git a/derivation/src/derivation.rs b/derivation/src/derivation.rs index 0767dc7..ef2d985 100644 --- a/derivation/src/derivation.rs +++ b/derivation/src/derivation.rs @@ -1,6 +1,8 @@ -use crate::errors; use crate::errors::Error; use crate::oracle::{MemoryOracleClient, NopeHintWriter}; +use crate::{errors, logger}; +use alloc::fmt::format; +use alloc::format; use alloc::sync::Arc; use alloy_consensus::Header; use alloy_primitives::{keccak256, Sealed, B256}; @@ -73,6 +75,12 @@ impl Derivation { rollup_config: rollup_config.clone(), }; let rollup_config = Arc::new(boot.rollup_config.clone()); + + logger::info(&format!( + "fetching safe head hash {:?} for L2 derivation", + boot.agreed_l2_output_root + )); + let safe_head_hash = fetch_safe_head_hash(&oracle, boot.agreed_l2_output_root).await?; let oracle_for_preimage = oracle.clone(); let oracle = Arc::new(oracle); @@ -106,6 +114,7 @@ impl Derivation { ) .await?; + logger::info(&format!("create evm factory")); let evm_factory = FpvmOpEvmFactory::new(NopeHintWriter, oracle_for_preimage); let executor = KonaExecutor::new( rollup_config.as_ref(), @@ -118,10 +127,18 @@ impl Derivation { // Run the derivation pipeline until we are able to produce the output root of the claimed // L2 block. + logger::info(&format!( + "start advancing to target L2 block {}", + boot.claimed_l2_block_number + )); let (_, output_root) = driver .advance_to_target(&boot.rollup_config, Some(boot.claimed_l2_block_number)) .await?; + logger::info(&format!( + "end advancing to target L2 block {}", + boot.claimed_l2_block_number + )); //////////////////////////////////////////////////////////////// // EPILOGUE // //////////////////////////////////////////////////////////////// diff --git a/derivation/src/lib.rs b/derivation/src/lib.rs index bb6d352..d625cb9 100644 --- a/derivation/src/lib.rs +++ b/derivation/src/lib.rs @@ -3,6 +3,7 @@ extern crate alloc; pub mod derivation; pub mod errors; +pub mod logger; pub mod oracle; pub mod types; diff --git a/derivation/src/logger.rs b/derivation/src/logger.rs new file mode 100644 index 0000000..586fd81 --- /dev/null +++ b/derivation/src/logger.rs @@ -0,0 +1,26 @@ +use alloc::vec::Vec; + +extern "C" { + fn ocall_info(msg: *const i8); + fn ocall_debug(msg: *const i8); +} + +#[no_mangle] +pub extern "C" fn info(msg: &str) { + let mut buf: Vec = msg.as_bytes().to_vec(); + buf.push(0); // Append NUL terminator + + unsafe { + ocall_info(buf.as_ptr() as *const i8); + } +} + +#[no_mangle] +pub extern "C" fn debug(msg: &str) { + let mut buf: Vec = msg.as_bytes().to_vec(); + buf.push(0); // Append NUL terminator + + unsafe { + ocall_debug(buf.as_ptr() as *const i8); + } +} diff --git a/derivation/src/oracle.rs b/derivation/src/oracle.rs index 01b1c4c..412b4df 100644 --- a/derivation/src/oracle.rs +++ b/derivation/src/oracle.rs @@ -1,7 +1,7 @@ use crate::errors::Error; use crate::errors::Error::UnexpectedPreimageKeySize; use crate::types::Preimage; -use crate::POSITION_FIELD_ELEMENT; +use crate::{logger, POSITION_FIELD_ELEMENT}; use alloc::boxed::Box; use alloc::format; use alloc::sync::Arc; @@ -108,8 +108,16 @@ impl TryFrom> for MemoryOracleClient { type Error = Error; fn try_from(value: Vec) -> Result { + logger::info(&format!( + "try from MemoryOracleClient capacity={}", + value.len() + )); let mut inner = HashMap::with_capacity(value.len()); - for preimage in value { + logger::info("MemoryOracleClient start to insert into hash "); + for (i, preimage) in value.into_iter().enumerate() { + if i % 10000 == 0 { + logger::info(&format!("MemoryOracleClient insert into hash {}", i)); + } let key: [u8; 32] = preimage .key .try_into() @@ -117,6 +125,9 @@ impl TryFrom> for MemoryOracleClient { let preimage_key = PreimageKey::try_from(key) .map_err(|e| Error::UnexpectedPreimageKey { source: e, key })?; + if i % 10000 == 0 { + logger::info(&format!("verify hash {}", i)); + } // Ensure hash type preimage is valid match preimage_key.key_type() { PreimageKeyType::Keccak256 => { @@ -137,10 +148,14 @@ impl TryFrom> for MemoryOracleClient { } } + logger::info("generate_valid_suffixes"); // Ensure blob preimage is valid let (valid_suffixes, roots_of_unity) = generate_valid_suffixes(); let mut kzg_cache = HashSet::>::new(); - for (key, _) in inner.iter() { + for (i, (key, _)) in inner.iter().enumerate() { + if i % 10000 == 0 { + logger::info(&format!("verify_blob and precompile {}", i)); + } if key.key_type() == PreimageKeyType::Blob { verify_blob_preimage( key, @@ -153,6 +168,7 @@ impl TryFrom> for MemoryOracleClient { verify_precompile(key, &inner)? } } + logger::info("try from MemoryOracleClient success"); Ok(Self { preimages: Arc::new(inner), }) diff --git a/light-client/src/client.rs b/light-client/src/client.rs index 1cbb14f..9968416 100644 --- a/light-client/src/client.rs +++ b/light-client/src/client.rs @@ -6,8 +6,8 @@ use crate::header::Header; use crate::message::ClientMessage; use crate::misbehaviour::Misbehaviour; use alloc::string::{String, ToString}; -use alloc::vec; use alloc::vec::Vec; +use alloc::{format, vec}; use alloy_primitives::keccak256; use core::time::Duration; use ethereum_consensus::types::H256; @@ -21,6 +21,7 @@ use light_client::{ CreateClientResult, Error as LightClientError, HostClientReader, LightClient, MisbehaviourData, UpdateClientResult, UpdateStateData, VerifyMembershipResult, VerifyNonMembershipResult, }; +use optimism_derivation::logger; pub struct OptimismLightClient; @@ -86,6 +87,7 @@ impl LightClient client_id: ClientId, client_message: Any, ) -> Result { + logger::info(&format!("update_client {}", client_id.to_string())); match ClientMessage::::try_from(client_message.clone())? { ClientMessage::Header(header) => Ok(self.update_state(ctx, client_id, header)?.into()), ClientMessage::Misbehaviour(misbehaviour) => Ok(self @@ -173,6 +175,11 @@ impl OptimismLightClient, ) -> Result { + logger::info(&format!( + "update_state {} trusted_height={}", + client_id.to_string(), + header.trusted_height.revision_height() + )); let trusted_height = header.trusted_height; let any_client_state = ctx.client_state(&client_id).map_err(Error::LCPError)?; let any_consensus_state = ctx diff --git a/light-client/src/client_state.rs b/light-client/src/client_state.rs index 5f247e2..4642011 100644 --- a/light-client/src/client_state.rs +++ b/light-client/src/client_state.rs @@ -8,6 +8,7 @@ use crate::misc::{ validate_state_timestamp_within_trusting_period, }; use alloc::borrow::ToOwned; +use alloc::format; use alloc::vec::Vec; use alloy_primitives::B256; use ethereum_consensus::beacon::Version; @@ -17,6 +18,7 @@ use ethereum_light_client_verifier::context::Fraction; use ethereum_light_client_verifier::execution::ExecutionVerifier; use kona_genesis::RollupConfig; use light_client::types::{Any, ClientId, Height, Time}; +use optimism_derivation::logger; use optimism_ibc_proto::google::protobuf::Any as IBCAny; use optimism_ibc_proto::ibc::lightclients::ethereum::v1::{ Fork as ProtoFork, ForkParameters as ProtoForkParameters, ForkSpec as ProtoForkSpec, @@ -70,6 +72,10 @@ impl ClientState { trusted_consensus_state: &ConsensusState, header: Header, ) -> Result<(ClientState, ConsensusState, Height), Error> { + logger::info(&format!( + "check_header_and_update_state trusted_height={}", + header.trusted_height.revision_height() + )); // Since the L1 block hash is used for L2 derivation, the validity of L1 must be verified. let l1_consensus = header.verify_l1( &self.l1_config, diff --git a/light-client/src/header.rs b/light-client/src/header.rs index 2521621..9b4015e 100644 --- a/light-client/src/header.rs +++ b/light-client/src/header.rs @@ -3,11 +3,13 @@ use crate::consensus_state::ConsensusState; use crate::errors::Error; use crate::l1::{L1Config, L1Consensus, L1Header}; use alloc::boxed::Box; +use alloc::format; use alloc::vec::Vec; use alloy_primitives::B256; use kona_genesis::RollupConfig; use light_client::types::{Any, Height}; use optimism_derivation::derivation::Derivation; +use optimism_derivation::logger; use optimism_derivation::oracle::MemoryOracleClient; use optimism_derivation::types::Preimages; use optimism_ibc_proto::google::protobuf::Any as IBCAny; @@ -51,6 +53,10 @@ impl L1Headers { let mut updated_as_next = false; for (i, l1_header) in self.trusted_to_deterministic.iter().enumerate() { + logger::info(&format!( + "verify l1 trusted_to_deterministic index={i} number={}", + l1_header.execution_update.block_number + )); let result = l1_header.verify(now_sec, l1_config, &l1_consensus); let result = result.map_err(|e| { Error::L1HeaderTrustedToDeterministicVerifyError( @@ -67,6 +73,10 @@ impl L1Headers { // Verify finalized l1 header by last l1 consensus for L2 derivation let mut l1_consensus_for_verify_only = l1_consensus.clone(); for (i, l1_header) in self.deterministic_to_latest.iter().enumerate() { + logger::info(&format!( + "verify l1 deterministic_to_latest index={i} number={}", + l1_header.execution_update.block_number + )); let result = l1_header.verify(now_sec, l1_config, &l1_consensus_for_verify_only); let result = result.map_err(|e| { Error::L1HeaderDeterministicToLatestVerifyError( @@ -110,6 +120,10 @@ impl Header { trusted_output_root: B256, rollup_config: &RollupConfig, ) -> Result<(alloy_consensus::Header, u64, B256), Error> { + logger::info(&format!( + "verify l2 derivation={:?}", + self.derivation.l2_block_number + )); // Ensure trusted if self.derivation.agreed_l2_output_root != trusted_output_root { return Err(Error::UnexpectedTrustedOutputRoot( @@ -131,11 +145,13 @@ impl TryFrom for Header Result { + logger::info("try from trusted_to_deterministic"); let mut trusted_to_deterministic: Vec> = Vec::with_capacity(header.trusted_to_deterministic.len()); for l1_header in header.trusted_to_deterministic { trusted_to_deterministic.push(l1_header.try_into()?); } + logger::info("try from deterministic_to_latest"); let mut deterministic_to_latest: Vec> = Vec::with_capacity(header.deterministic_to_latest.len()); for l1_header in header.deterministic_to_latest { @@ -143,6 +159,7 @@ impl TryFrom for Header TryFrom for Header