diff --git a/crates/node/src/attributes.rs b/crates/node/src/attributes.rs index 30531b6..7dc29ca 100644 --- a/crates/node/src/attributes.rs +++ b/crates/node/src/attributes.rs @@ -13,6 +13,8 @@ use reth_payload_primitives::PayloadAttributesBuilder; use reth_primitives_traits::SealedHeader; use serde::{Deserialize, Serialize}; +use tracing::{info, instrument, Span}; + use crate::error::EvolveEngineError; use ev_primitives::TransactionSigned; @@ -68,11 +70,18 @@ impl PayloadBuilderAttributes for EvolveEnginePayloadBuilderAttributes { type RpcPayloadAttributes = EvolveEnginePayloadAttributes; type Error = EvolveEngineError; + #[instrument(skip(parent, attributes, _version), fields( + parent_hash = %parent, + raw_tx_count = attributes.transactions.as_ref().map_or(0, |t| t.len()), + gas_limit = ?attributes.gas_limit, + duration_ms = tracing::field::Empty, + ))] fn try_new( parent: B256, attributes: EvolveEnginePayloadAttributes, _version: u8, ) -> Result { + let _start = std::time::Instant::now(); let ethereum_attributes = EthPayloadBuilderAttributes::new(parent, attributes.inner); // Decode transactions from bytes if provided. @@ -86,6 +95,12 @@ impl PayloadBuilderAttributes for EvolveEnginePayloadBuilderAttributes { }) .collect::, _>>()?; + info!( + decoded_tx_count = transactions.len(), + "decoded payload attributes" + ); + Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); + Ok(Self { ethereum_attributes, transactions, @@ -166,3 +181,49 @@ impl PayloadAttributesBuilder } } } + +#[cfg(test)] +mod tests { + use super::*; + use crate::test_utils::SpanCollector; + + #[test] + fn try_new_span_has_expected_fields() { + let collector = SpanCollector::new(); + let _guard = collector.as_default(); + + let parent = B256::random(); + let attrs = EvolveEnginePayloadAttributes { + inner: RpcPayloadAttributes { + timestamp: 1710338136, + prev_randao: B256::random(), + suggested_fee_recipient: Address::random(), + withdrawals: Some(vec![]), + parent_beacon_block_root: Some(B256::ZERO), + }, + transactions: Some(vec![]), + gas_limit: Some(30_000_000), + }; + + // we only care that the span was created with the right fields. + let _ = EvolveEnginePayloadBuilderAttributes::try_new(parent, attrs, 3); + + let span = collector + .find_span("try_new") + .expect("try_new span should be recorded"); + + assert!( + span.has_field("parent_hash"), + "span missing parent_hash field" + ); + assert!( + span.has_field("raw_tx_count"), + "span missing raw_tx_count field" + ); + assert!(span.has_field("gas_limit"), "span missing gas_limit field"); + assert!( + span.has_field("duration_ms"), + "span missing duration_ms field" + ); + } +} diff --git a/crates/node/src/builder.rs b/crates/node/src/builder.rs index e25257a..19a0070 100644 --- a/crates/node/src/builder.rs +++ b/crates/node/src/builder.rs @@ -15,7 +15,7 @@ use reth_primitives_traits::SealedBlock; use reth_provider::{HeaderProvider, StateProviderFactory}; use reth_revm::{database::StateProviderDatabase, State}; use std::sync::Arc; -use tracing::{debug, debug_span, info, instrument}; +use tracing::{debug, debug_span, info, instrument, Span}; type EvolveEthEvmConfig = EvEvmConfig; @@ -185,7 +185,7 @@ where let sealed_block = block.sealed_block().clone(); - tracing::Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); + Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); info!( block_number = sealed_block.number, diff --git a/crates/node/src/payload_service.rs b/crates/node/src/payload_service.rs index e12075a..deaa008 100644 --- a/crates/node/src/payload_service.rs +++ b/crates/node/src/payload_service.rs @@ -20,7 +20,7 @@ use reth_payload_builder::PayloadBuilderError; use reth_provider::HeaderProvider; use reth_revm::cached::CachedReads; use tokio::runtime::Handle; -use tracing::{info, instrument}; +use tracing::{info, instrument, Span}; use crate::{ attributes::EvolveEnginePayloadBuilderAttributes, builder::EvolvePayloadBuilder, @@ -206,7 +206,7 @@ where None, // No blob sidecar for evolve. ); - tracing::Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); + Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); Ok(BuildOutcome::Better { payload: built_payload, @@ -214,16 +214,21 @@ where }) } + #[instrument(skip(self, config), fields( + payload_id = %config.attributes.payload_id(), + duration_ms = tracing::field::Empty, + ))] fn build_empty_payload( &self, config: PayloadConfig>, ) -> Result { + let _start = std::time::Instant::now(); let PayloadConfig { parent_header, attributes, } = config; - info!("Evolve engine payload builder: building empty payload"); + info!("building empty payload"); // Create empty evolve attributes (no transactions). // If no gas_limit provided, default to the parent header's gas limit (genesis for first block). @@ -263,6 +268,7 @@ where .map_err(PayloadBuilderError::other)?; let gas_used = sealed_block.gas_used; + Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); Ok(EvBuiltPayload::new( attributes.payload_id(), Arc::new(sealed_block), @@ -386,4 +392,86 @@ mod tests { "span missing duration_ms field" ); } + + #[tokio::test(flavor = "multi_thread", worker_threads = 2)] + async fn build_empty_payload_span_has_expected_fields() { + let collector = SpanCollector::new(); + let _guard = collector.as_default(); + + let genesis: alloy_genesis::Genesis = + serde_json::from_str(include_str!("../../tests/assets/genesis.json")) + .expect("valid genesis"); + let chain_spec = Arc::new( + ChainSpecBuilder::default() + .chain(reth_chainspec::Chain::from_id(1234)) + .genesis(genesis) + .cancun_activated() + .build(), + ); + + let provider = MockEthProvider::default(); + let genesis_hash = B256::from_slice( + &hex::decode("2b8bbb1ea1e04f9c9809b4b278a8687806edc061a356c7dbc491930d8e922503") + .unwrap(), + ); + let genesis_state_root = B256::from_slice( + &hex::decode("05e9954443da80d86f2104e56ffdfd98fe21988730684360104865b3dc8191b4") + .unwrap(), + ); + + let genesis_header = Header { + state_root: genesis_state_root, + number: 0, + gas_limit: 30_000_000, + timestamp: 1710338135, + base_fee_per_gas: Some(0), + excess_blob_gas: Some(0), + blob_gas_used: Some(0), + parent_beacon_block_root: Some(B256::ZERO), + ..Default::default() + }; + provider.add_header(genesis_hash, genesis_header.clone()); + + let config = EvolvePayloadBuilderConfig::from_chain_spec(chain_spec.as_ref()).unwrap(); + let evm_config = EvolveEvmConfig::new(chain_spec); + let evolve_builder = Arc::new(EvolvePayloadBuilder::new( + Arc::new(provider), + evm_config, + config.clone(), + )); + + let engine_builder = EvolveEnginePayloadBuilder { + evolve_builder, + config, + }; + + let rpc_attrs = RpcPayloadAttributes { + timestamp: 1710338136, + prev_randao: B256::random(), + suggested_fee_recipient: Address::random(), + withdrawals: Some(vec![]), + parent_beacon_block_root: Some(B256::ZERO), + }; + let eth_attrs = EthPayloadBuilderAttributes::new(genesis_hash, rpc_attrs); + let builder_attrs = EvolveEnginePayloadBuilderAttributes::from(eth_attrs); + + let sealed_parent = SealedHeader::new(genesis_header, genesis_hash); + let payload_config = PayloadConfig::new(Arc::new(sealed_parent), builder_attrs); + + // we only care that the span was created with the right fields. + let _ = engine_builder.build_empty_payload(payload_config); + + let span = collector + .find_span("build_empty_payload") + .expect("build_empty_payload span should be recorded"); + + assert!( + span.has_field("payload_id"), + "span missing payload_id field" + ); + assert!( + span.has_field("duration_ms"), + "span missing duration_ms field" + ); + } } diff --git a/crates/node/src/txpool.rs b/crates/node/src/txpool.rs index efeff56..02593ea 100644 --- a/crates/node/src/txpool.rs +++ b/crates/node/src/txpool.rs @@ -29,7 +29,7 @@ use reth_transaction_pool::{ EthTransactionValidator, PoolTransaction, TransactionOrigin, TransactionValidationOutcome, TransactionValidationTaskExecutor, TransactionValidator, }; -use tracing::{debug, info, instrument, warn}; +use tracing::{debug, info, instrument, warn, Span}; /// Pool transaction wrapper for `EvTxEnvelope`. #[derive(Debug, Clone)] @@ -394,12 +394,32 @@ where Ok(()) } + #[instrument(skip(self, pooled, sender_balance, state), fields( + tx_hash = %pooled.hash(), + is_evnode = matches!(pooled.transaction().inner(), EvTxEnvelope::EvNode(_)), + duration_ms = tracing::field::Empty, + ))] fn validate_evnode( &self, pooled: &EvPooledTransaction, sender_balance: U256, state: &mut Option>, ) -> Result<(), InvalidPoolTransactionError> + where + Client: StateProviderFactory, + { + let _start = std::time::Instant::now(); + let result = self.validate_evnode_inner(pooled, sender_balance, state); + Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); + result + } + + fn validate_evnode_inner( + &self, + pooled: &EvPooledTransaction, + sender_balance: U256, + state: &mut Option>, + ) -> Result<(), InvalidPoolTransactionError> where Client: StateProviderFactory, { @@ -517,7 +537,7 @@ where other => other, }; - tracing::Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); + Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); result } } @@ -821,4 +841,37 @@ mod tests { assert!(matches!(err, InvalidPoolTransactionError::Other(_))); } } + + #[test] + fn validate_evnode_span_has_expected_fields() { + use crate::test_utils::SpanCollector; + + let collector = SpanCollector::new(); + let _guard = collector.as_default(); + + let validator = create_test_validator(None); + + let gas_limit = 21_000u64; + let max_fee_per_gas = 1_000_000_000u128; + let signed_tx = create_non_sponsored_evnode_tx(gas_limit, max_fee_per_gas); + + let signer = Address::random(); + let pooled = create_pooled_tx(signed_tx, signer); + + let sender_balance = *pooled.cost() + U256::from(1); + let mut state: Option> = None; + + let _ = validator.validate_evnode(&pooled, sender_balance, &mut state); + + let span = collector + .find_span("validate_evnode") + .expect("validate_evnode span should be recorded"); + + assert!(span.has_field("tx_hash"), "span missing tx_hash field"); + assert!(span.has_field("is_evnode"), "span missing is_evnode field"); + assert!( + span.has_field("duration_ms"), + "span missing duration_ms field" + ); + } } diff --git a/crates/node/src/validator.rs b/crates/node/src/validator.rs index c0bdf55..f66f3e6 100644 --- a/crates/node/src/validator.rs +++ b/crates/node/src/validator.rs @@ -20,7 +20,7 @@ use reth_ethereum::{ }; use reth_ethereum_payload_builder::EthereumExecutionPayloadValidator; use reth_primitives_traits::{Block as _, RecoveredBlock, SealedBlock}; -use tracing::{debug, info, instrument}; +use tracing::{debug, info, instrument, Span}; use crate::{attributes::EvolveEnginePayloadAttributes, node::EvolveEngineTypes}; @@ -71,7 +71,7 @@ impl PayloadValidator for EvolveEngineValidator { // Use inner validator but with custom evolve handling. match self.inner.ensure_well_formed_payload(payload.clone()) { Ok(sealed_block) => { - let span = tracing::Span::current(); + let span = Span::current(); span.record("block_hash", tracing::field::display(sealed_block.hash())); span.record("duration_ms", _start.elapsed().as_millis() as u64); info!("payload validation succeeded"); @@ -100,7 +100,7 @@ impl PayloadValidator for EvolveEngineValidator { info!(error = ?err, "bypassing validation error for ev-reth"); // For evolve, we trust the payload builder - parse the block with EvNode support. let ev_block = parse_evolve_payload(payload)?; - let span = tracing::Span::current(); + let span = Span::current(); span.record("block_hash", tracing::field::display(ev_block.hash())); span.record("duration_ms", _start.elapsed().as_millis() as u64); ev_block @@ -133,9 +133,15 @@ fn convert_sealed_block( } /// Parses an execution payload containing `EvNode` transactions. +#[instrument(skip(payload), fields( + tx_count = payload.payload.transactions().len(), + block_number = payload.payload.block_number(), + duration_ms = tracing::field::Empty, +))] fn parse_evolve_payload( payload: ExecutionData, ) -> Result, NewPayloadError> { + let _start = std::time::Instant::now(); let ExecutionData { payload, sidecar } = payload; // Parse transactions using EvTxEnvelope which supports both Ethereum and EvNode types. @@ -184,7 +190,9 @@ fn parse_evolve_payload( }; let block = EvBlock::new(header, body); - Ok(block.seal_slow()) + let sealed = block.seal_slow(); + Span::current().record("duration_ms", _start.elapsed().as_millis() as u64); + Ok(sealed) } impl EngineApiValidator for EvolveEngineValidator { @@ -396,4 +404,64 @@ mod tests { "Should not match BlockHash error" ); } + + #[test] + fn parse_evolve_payload_span_has_expected_fields() { + use crate::test_utils::SpanCollector; + use alloy_primitives::{Address, Bloom, Bytes, B256, U256}; + use alloy_rpc_types::engine::{ + ExecutionData, ExecutionPayload, ExecutionPayloadSidecar, ExecutionPayloadV1, + ExecutionPayloadV2, ExecutionPayloadV3, + }; + + let collector = SpanCollector::new(); + let _guard = collector.as_default(); + + let v1 = ExecutionPayloadV1 { + parent_hash: B256::ZERO, + fee_recipient: Address::ZERO, + state_root: B256::ZERO, + receipts_root: B256::ZERO, + logs_bloom: Bloom::ZERO, + prev_randao: B256::ZERO, + block_number: 1, + gas_limit: 30_000_000, + gas_used: 0, + timestamp: 1710338136, + extra_data: Bytes::default(), + base_fee_per_gas: U256::ZERO, + block_hash: B256::ZERO, + transactions: vec![], + }; + let v2 = ExecutionPayloadV2 { + payload_inner: v1, + withdrawals: vec![], + }; + let v3 = ExecutionPayloadV3 { + payload_inner: v2, + blob_gas_used: 0, + excess_blob_gas: 0, + }; + + let payload = ExecutionPayload::V3(v3); + let sidecar = ExecutionPayloadSidecar::default(); + let execution_data = ExecutionData::new(payload, sidecar); + + // we only care that the span was created with the right fields. + let _ = parse_evolve_payload(execution_data); + + let span = collector + .find_span("parse_evolve_payload") + .expect("parse_evolve_payload span should be recorded"); + + assert!(span.has_field("tx_count"), "span missing tx_count field"); + assert!( + span.has_field("block_number"), + "span missing block_number field" + ); + assert!( + span.has_field("duration_ms"), + "span missing duration_ms field" + ); + } }