Log calculated world state contents upon state root mismatch (#8099)

Collect trielog rolling exceptions and display upon state root mismatch

Signed-off-by: Simon Dudley <simon.dudley@consensys.net>

ethereum/referencetests/src/main/java/org/hyperledger/besu/ethereum/referencetests/BonsaiReferenceTestWorldState.java

@@ -22,7 +22,6 @@ import org.hyperledger.besu.ethereum.trie.diffbased.bonsai.cache.BonsaiCachedMer
 import org.hyperledger.besu.ethereum.trie.diffbased.bonsai.cache.NoOpBonsaiCachedWorldStorageManager;
 import org.hyperledger.besu.ethereum.trie.diffbased.bonsai.storage.BonsaiPreImageProxy;
 import org.hyperledger.besu.ethereum.trie.diffbased.bonsai.storage.BonsaiWorldStateKeyValueStorage;
-import org.hyperledger.besu.ethereum.trie.diffbased.bonsai.storage.BonsaiWorldStateLayerStorage;
 import org.hyperledger.besu.ethereum.trie.diffbased.bonsai.worldview.BonsaiWorldState;
 import org.hyperledger.besu.ethereum.trie.diffbased.bonsai.worldview.BonsaiWorldStateUpdateAccumulator;
 import org.hyperledger.besu.ethereum.trie.diffbased.common.cache.DiffBasedCachedWorldStorageManager;
@@ -38,6 +37,8 @@ import org.hyperledger.besu.metrics.ObservableMetricsSystem;
 import org.hyperledger.besu.metrics.noop.NoOpMetricsSystem;
 import org.hyperledger.besu.plugin.services.trielogs.TrieLog;
 
+import java.util.ArrayList;
+import java.util.Collection;
 import java.util.Map;
 import java.util.Optional;
 import java.util.stream.Stream;
@@ -47,13 +48,18 @@ import com.google.common.cache.Cache;
 import com.google.common.cache.CacheBuilder;
 import org.apache.tuweni.bytes.Bytes;
 import org.apache.tuweni.bytes.Bytes32;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 public class BonsaiReferenceTestWorldState extends BonsaiWorldState
     implements ReferenceTestWorldState {
 
+  private static final Logger LOG = LoggerFactory.getLogger(BonsaiReferenceTestWorldState.class);
+
   private final BonsaiReferenceTestWorldStateStorage refTestStorage;
   private final BonsaiPreImageProxy preImageProxy;
   private final EvmConfiguration evmConfiguration;
+  private final Collection<Exception> exceptionCollector = new ArrayList<>();
 
   protected BonsaiReferenceTestWorldState(
       final BonsaiReferenceTestWorldStateStorage worldStateKeyValueStorage,
@@ -110,7 +116,8 @@ public class BonsaiReferenceTestWorldState extends BonsaiWorldState
   }
 
   @Override
-  public void processExtraStateStorageFormatValidation(final BlockHeader blockHeader) {
+  public Collection<Exception> processExtraStateStorageFormatValidation(
+      final BlockHeader blockHeader) {
     if (blockHeader != null) {
       final Hash parentStateRoot = getWorldStateRootHash();
       final BonsaiReferenceTestUpdateAccumulator originalUpdater =
@@ -121,6 +128,7 @@ public class BonsaiReferenceTestWorldState extends BonsaiWorldState
       // validate trielog generation with frozen state
       validateStateRolling(parentStateRoot, originalUpdater, blockHeader, true);
     }
+    return exceptionCollector;
   }
 
   /**
@@ -156,9 +164,12 @@ public class BonsaiReferenceTestWorldState extends BonsaiWorldState
       bonsaiWorldState.persist(blockHeader);
       Hash generatedRootHash = bonsaiWorldState.rootHash();
       if (!bonsaiWorldState.rootHash().equals(blockHeader.getStateRoot())) {
-        throw new RuntimeException(
+        final String msg =
             "state root becomes invalid following a rollForward %s != %s"
-                .formatted(blockHeader.getStateRoot(), generatedRootHash));
+                .formatted(blockHeader.getStateRoot(), generatedRootHash);
+        final RuntimeException e = new RuntimeException(msg);
+        exceptionCollector.add(e);
+        LOG.atError().setMessage(msg).setCause(e).log();
       }
 
       updaterForState = (BonsaiWorldStateUpdateAccumulator) bonsaiWorldState.updater();
@@ -167,9 +178,12 @@ public class BonsaiReferenceTestWorldState extends BonsaiWorldState
       bonsaiWorldState.persist(null);
       generatedRootHash = bonsaiWorldState.rootHash();
       if (!bonsaiWorldState.rootHash().equals(parentStateRoot)) {
-        throw new RuntimeException(
+        final String msg =
             "state root becomes invalid following a rollBackward %s != %s"
-                .formatted(parentStateRoot, generatedRootHash));
+                .formatted(parentStateRoot, generatedRootHash);
+        final RuntimeException e = new RuntimeException(msg);
+        exceptionCollector.add(e);
+        LOG.atError().setMessage(msg).setCause(e).log();
       }
     }
   }
@@ -189,19 +203,11 @@ public class BonsaiReferenceTestWorldState extends BonsaiWorldState
   }
 
   private BonsaiWorldState createBonsaiWorldState(final boolean isFrozen) {
-    BonsaiWorldState bonsaiWorldState =
+    final BonsaiReferenceTestWorldState copy = (BonsaiReferenceTestWorldState) this.copy();
-        new BonsaiWorldState(
-            new BonsaiWorldStateLayerStorage(
-                (BonsaiWorldStateKeyValueStorage) worldStateKeyValueStorage),
-            bonsaiCachedMerkleTrieLoader,
-            cachedWorldStorageManager,
-            trieLogManager,
-            evmConfiguration,
-            new DiffBasedWorldStateConfig());
     if (isFrozen) {
-      bonsaiWorldState.freeze(); // freeze state
+      copy.freeze();
     }
-    return bonsaiWorldState;
+    return copy;
   }
 
   @JsonCreator

ethereum/referencetests/src/main/java/org/hyperledger/besu/ethereum/referencetests/ForestReferenceTestWorldState.java

@@ -24,6 +24,8 @@ import org.hyperledger.besu.evm.worldstate.WorldState;
 import org.hyperledger.besu.evm.worldstate.WorldUpdater;
 import org.hyperledger.besu.services.kvstore.InMemoryKeyValueStorage;
 
+import java.util.Collection;
+import java.util.Collections;
 import java.util.Map;
 
 import com.fasterxml.jackson.annotation.JsonCreator;
@@ -56,8 +58,10 @@ public class ForestReferenceTestWorldState extends ForestMutableWorldState
    * root has been validated, to ensure the integrity of other aspects of the state.
    */
   @Override
-  public void processExtraStateStorageFormatValidation(final BlockHeader blockHeader) {
+  public Collection<Exception> processExtraStateStorageFormatValidation(
+      final BlockHeader blockHeader) {
     // nothing more to verify with forest
+    return Collections.emptyList();
   }
 
   @JsonCreator

ethereum/referencetests/src/main/java/org/hyperledger/besu/ethereum/referencetests/ReferenceTestWorldState.java

@@ -22,6 +22,7 @@ import org.hyperledger.besu.evm.account.MutableAccount;
 import org.hyperledger.besu.evm.internal.EvmConfiguration;
 import org.hyperledger.besu.evm.worldstate.WorldUpdater;
 
+import java.util.Collection;
 import java.util.HashMap;
 import java.util.Map;
 
@@ -91,7 +92,7 @@ public interface ReferenceTestWorldState extends MutableWorldState {
 
   ReferenceTestWorldState copy();
 
-  void processExtraStateStorageFormatValidation(final BlockHeader blockHeader);
+  Collection<Exception> processExtraStateStorageFormatValidation(final BlockHeader blockHeader);
 
   @JsonCreator
   static ReferenceTestWorldState create(final Map<String, AccountMock> accounts) {

ethereum/referencetests/src/reference-test/java/org/hyperledger/besu/ethereum/vm/GeneralStateReferenceTestTools.java

@@ -22,6 +22,13 @@ import java.util.List;
 import java.util.Map;
 import java.util.Optional;
 
+import com.fasterxml.jackson.databind.ObjectMapper;
+import com.fasterxml.jackson.databind.node.ObjectNode;
+import org.apache.tuweni.bytes.Bytes;
+import org.apache.tuweni.bytes.Bytes32;
+import org.apache.tuweni.units.bigints.UInt256;
+import org.assertj.core.api.SoftAssertions;
+import org.hyperledger.besu.datatypes.Address;
 import org.hyperledger.besu.datatypes.BlobGas;
 import org.hyperledger.besu.datatypes.Hash;
 import org.hyperledger.besu.datatypes.Wei;
@@ -42,8 +49,12 @@ import org.hyperledger.besu.evm.account.Account;
 import org.hyperledger.besu.evm.log.Log;
 import org.hyperledger.besu.evm.worldstate.WorldUpdater;
 import org.hyperledger.besu.testutil.JsonTestParameters;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 public class GeneralStateReferenceTestTools {
+  private static final Logger LOG = LoggerFactory.getLogger(GeneralStateReferenceTestTools.class);
+
   private static final List<String> SPECS_PRIOR_TO_DELETING_EMPTY_ACCOUNTS =
       Arrays.asList("Frontier", "Homestead", "EIP150");
 
@@ -179,16 +190,26 @@ public class GeneralStateReferenceTestTools {
       worldStateUpdater.deleteAccount(coinbase.getAddress());
     }
     worldStateUpdater.commit();
-    worldState.processExtraStateStorageFormatValidation(blockHeader);
+    Collection<Exception> additionalExceptions = worldState.processExtraStateStorageFormatValidation(blockHeader);
     worldState.persist(blockHeader);
 
     // Check the world state root hash.
     final Hash expectedRootHash = spec.getExpectedRootHash();
-    assertThat(worldState.rootHash())
+    // If the root hash doesn't match, first dump the world state for debugging.
-        .withFailMessage(
+    if (!expectedRootHash.equals(worldState.rootHash())) {
-            "Unexpected world state root hash; expected state: %s, computed state: %s",
+      logWorldState(worldState);
-            spec.getExpectedRootHash(), worldState.rootHash())
+    }
-        .isEqualTo(expectedRootHash);
+    SoftAssertions.assertSoftly(
+        softly -> {
+          softly.assertThat(worldState.rootHash())
+              .withFailMessage(
+                  "Unexpected world state root hash; expected state: %s, computed state: %s",
+                  spec.getExpectedRootHash(), worldState.rootHash())
+              .isEqualTo(expectedRootHash);
+          additionalExceptions.forEach(
+              e -> softly.fail("Additional exception during state validation: " + e.getMessage()));
+
+        });
 
     // Check the logs.
     final Hash expectedLogsHash = spec.getExpectedLogsHash();
@@ -206,4 +227,33 @@ public class GeneralStateReferenceTestTools {
   private static boolean shouldClearEmptyAccounts(final String eip) {
     return !SPECS_PRIOR_TO_DELETING_EMPTY_ACCOUNTS.contains(eip);
   }
+
+  private static void logWorldState(final ReferenceTestWorldState worldState) {
+    ObjectMapper mapper = new ObjectMapper();
+    ObjectNode worldStateJson = mapper.createObjectNode();
+    worldState.streamAccounts(Bytes32.ZERO, Integer.MAX_VALUE)
+        .forEach(
+            account -> {
+              ObjectNode accountJson = mapper.createObjectNode();
+              accountJson.put("nonce", Bytes.ofUnsignedLong(account.getNonce()).toShortHexString());
+              accountJson.put("balance", account.getBalance().toShortHexString());
+              accountJson.put("code", account.getCode().toHexString());
+              ObjectNode storageJson = mapper.createObjectNode();
+              var storageEntries = account.storageEntriesFrom(Bytes32.ZERO, Integer.MAX_VALUE);
+              storageEntries.values().stream()
+                  .map(
+                      e ->
+                          Map.entry(
+                              e.getKey().orElse(UInt256.fromBytes(Bytes.EMPTY)),
+                              account.getStorageValue(UInt256.fromBytes(e.getKey().get()))))
+                  .sorted(Map.Entry.comparingByKey())
+                  .forEach(e -> storageJson.put(e.getKey().toQuantityHexString(), e.getValue().toQuantityHexString()));
+
+              if (!storageEntries.isEmpty()) {
+                accountJson.set("storage", storageJson);
+              }
+              worldStateJson.set(account.getAddress().orElse(Address.wrap(Bytes.EMPTY)).toHexString(), accountJson);
+            });
+    LOG.error("Calculated world state: \n{}", worldStateJson.toPrettyString());
+  }
 }