feat: adding additional fine grained spans

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<Self, Self::Error> {
+        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::<Result<Vec<_>, _>>()?;
 
+        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<EvolveEnginePayloadAttributes>
         }
     }
 }
+
+#[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"
+        );
+    }
+}

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<ChainSpec, EvTxEvmFactory>;
 
@@ -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,

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,24 +206,29 @@ 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,
             cached_reads: CachedReads::default(),
         })
     }
 
+    #[instrument(skip(self, config), fields(
+        payload_id = %config.attributes.payload_id(),
+        duration_ms = tracing::field::Empty,
+    ))]
     fn build_empty_payload(
         &self,
         config: PayloadConfig<Self::Attributes, HeaderForPayload<Self::BuiltPayload>>,
     ) -> Result<Self::BuiltPayload, PayloadBuilderError> {
+        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"
+        );
+    }
 }

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<Box<dyn AccountInfoReader + Send>>,
     ) -> 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<Box<dyn AccountInfoReader + Send>>,
+    ) -> 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<Box<dyn AccountInfoReader + Send>> = 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"
+        );
+    }
 }