chore(trie): sparse trie trace logs and assertion messages (#12969)

crates/engine/tree/src/tree/root.rs

@@ -224,6 +224,7 @@ where
         for (address, account) in update {
             if account.is_touched() {
                 let hashed_address = keccak256(address);
+                trace!(target: "engine::root", ?address, ?hashed_address, "Adding account to state update");
 
                 let destroyed = account.is_selfdestructed();
                 let info = if account.is_empty() { None } else { Some(account.info.into()) };
@@ -377,6 +378,8 @@ where
                             "Processing calculated proof"
                         );
 
+                        trace!(target: "engine::root", ?proof, "Proof calculated");
+
                         if let Some((combined_proof, combined_state_update)) =
                             self.on_proof(sequence_number, proof, state_update)
                         {
@@ -496,6 +499,7 @@ fn update_sparse_trie(
     targets: HashMap<B256, HashSet<B256>>,
     state: HashedPostState,
 ) -> SparseStateTrieResult<(Box<SparseStateTrie>, Duration)> {
+    trace!(target: "engine::root::sparse", "Updating sparse trie");
     let started_at = Instant::now();
 
     // Reveal new accounts and storage slots.
@@ -503,18 +507,23 @@ fn update_sparse_trie(
 
     // Update storage slots with new values and calculate storage roots.
     for (address, storage) in state.storages {
+        trace!(target: "engine::root::sparse", ?address, "Updating storage");
         let storage_trie = trie.storage_trie_mut(&address).ok_or(SparseTrieError::Blind)?;
 
         if storage.wiped {
+            trace!(target: "engine::root::sparse", ?address, "Wiping storage");
             storage_trie.wipe();
         }
 
         for (slot, value) in storage.storage {
             let slot_nibbles = Nibbles::unpack(slot);
             if value.is_zero() {
+                trace!(target: "engine::root::sparse", ?address, ?slot, "Removing storage slot");
+
                 // TODO: handle blinded node error
                 storage_trie.remove_leaf(&slot_nibbles)?;
             } else {
+                trace!(target: "engine::root::sparse", ?address, ?slot, "Updating storage slot");
                 storage_trie
                     .update_leaf(slot_nibbles, alloy_rlp::encode_fixed_size(&value).to_vec())?;
             }
@@ -525,6 +534,7 @@ fn update_sparse_trie(
 
     // Update accounts with new values
     for (address, account) in state.accounts {
+        trace!(target: "engine::root::sparse", ?address, "Updating account");
         trie.update_account(address, account.unwrap_or_default())?;
     }
 

crates/trie/sparse/src/state.rs

@@ -7,6 +7,7 @@ use alloy_primitives::{
 };
 use alloy_rlp::{Decodable, Encodable};
 use reth_primitives_traits::Account;
+use reth_tracing::tracing::trace;
 use reth_trie_common::{
     updates::{StorageTrieUpdates, TrieUpdates},
     MultiProof, Nibbles, TrieAccount, TrieNode, EMPTY_ROOT_HASH, TRIE_ACCOUNT_RLP_MAX_SIZE,
@@ -149,6 +150,7 @@ impl SparseStateTrie {
             // Reveal the remaining proof nodes.
             for (path, bytes) in account_nodes {
                 let node = TrieNode::decode(&mut &bytes[..])?;
+                trace!(target: "trie::sparse", ?path, ?node, "Revealing account node");
                 trie.reveal_node(path, node)?;
             }
         }
@@ -168,6 +170,7 @@ impl SparseStateTrie {
                 // Reveal the remaining proof nodes.
                 for (path, bytes) in storage_nodes {
                     let node = TrieNode::decode(&mut &bytes[..])?;
+                    trace!(target: "trie::sparse", ?account, ?path, ?node, "Revealing storage node");
                     trie.reveal_node(path, node)?;
                 }
             }
@@ -209,8 +212,10 @@ impl SparseStateTrie {
     pub fn update_account(&mut self, address: B256, account: Account) -> SparseStateTrieResult<()> {
         let nibbles = Nibbles::unpack(address);
         let storage_root = if let Some(storage_trie) = self.storages.get_mut(&address) {
+            trace!(target: "trie::sparse", ?address, "Calculating storage root to update account");
             storage_trie.root().ok_or(SparseTrieError::Blind)?
         } else if self.revealed.contains_key(&address) {
+            trace!(target: "trie::sparse", ?address, "Retrieving storage root from account leaf to update account");
             let state = self.state.as_revealed_mut().ok_or(SparseTrieError::Blind)?;
             // The account was revealed, either...
             if let Some(value) = state.get_leaf_value(&nibbles) {
@@ -225,8 +230,10 @@ impl SparseStateTrie {
         };
 
         if account.is_empty() && storage_root == EMPTY_ROOT_HASH {
+            trace!(target: "trie::sparse", ?address, "Removing account");
             self.remove_account_leaf(&nibbles)
         } else {
+            trace!(target: "trie::sparse", ?address, "Updating account");
             self.account_rlp_buf.clear();
             TrieAccount::from((account, storage_root)).encode(&mut self.account_rlp_buf);
             self.update_account_leaf(nibbles, self.account_rlp_buf.clone())

crates/trie/sparse/src/trie.rs

@@ -5,7 +5,7 @@ use alloy_primitives::{
     B256,
 };
 use alloy_rlp::Decodable;
-use reth_tracing::tracing::debug;
+use reth_tracing::tracing::trace;
 use reth_trie_common::{
     prefix_set::{PrefixSet, PrefixSetMut},
     BranchNodeCompact, BranchNodeRef, ExtensionNodeRef, LeafNodeRef, Nibbles, RlpNode, TrieMask,
@@ -371,7 +371,7 @@ impl RevealedSparseTrie {
         // in `nodes`, but not in the `values`.
 
         let mut removed_nodes = self.take_nodes_for_path(path)?;
-        debug!(target: "trie::sparse", ?path, ?removed_nodes, "Removed nodes for path");
+        trace!(target: "trie::sparse", ?path, ?removed_nodes, "Removed nodes for path");
         // Pop the first node from the stack which is the leaf node we want to remove.
         let mut child = removed_nodes.pop().expect("leaf exists");
         #[cfg(debug_assertions)]
@@ -459,7 +459,7 @@ impl RevealedSparseTrie {
                         // Remove the only child node.
                         let child = self.nodes.get(&child_path).unwrap();
 
-                        debug!(target: "trie::sparse", ?removed_path, ?child_path, ?child, "Branch node has only one child");
+                        trace!(target: "trie::sparse", ?removed_path, ?child_path, ?child, "Branch node has only one child");
 
                         let mut delete_child = false;
                         let new_node = match child {
@@ -520,7 +520,7 @@ impl RevealedSparseTrie {
                 node: new_node.clone(),
                 unset_branch_nibble: None,
             };
-            debug!(target: "trie::sparse", ?removed_path, ?new_node, "Re-inserting the node");
+            trace!(target: "trie::sparse", ?removed_path, ?new_node, "Re-inserting the node");
             self.nodes.insert(removed_path, new_node);
         }
 
@@ -561,7 +561,13 @@ impl RevealedSparseTrie {
                     {
                         let mut current = current.clone();
                         current.extend_from_slice_unchecked(key);
-                        assert!(path.starts_with(&current));
+                        assert!(
+                            path.starts_with(&current),
+                            "path: {:?}, current: {:?}, key: {:?}",
+                            path,
+                            current,
+                            key
+                        );
                     }
 
                     let path = current.clone();
@@ -570,7 +576,14 @@ impl RevealedSparseTrie {
                 }
                 SparseNode::Branch { state_mask, .. } => {
                     let nibble = path[current.len()];
-                    debug_assert!(state_mask.is_bit_set(nibble));
+                    debug_assert!(
+                        state_mask.is_bit_set(nibble),
+                        "current: {:?}, path: {:?}, nibble: {:?}, state_mask: {:?}",
+                        current,
+                        path,
+                        nibble,
+                        state_mask
+                    );
 
                     // If the branch node has a child that is a leaf node that we're removing,
                     // we need to unset this nibble.