Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Critical Exception Processing Transaction #4768

Closed
MysticRyuujin opened this issue Dec 2, 2022 · 22 comments
Closed

Critical Exception Processing Transaction #4768

MysticRyuujin opened this issue Dec 2, 2022 · 22 comments
Labels
TeamChupa GH issues worked on by Chupacabara Team

Comments

@MysticRyuujin
Copy link

MysticRyuujin commented Dec 2, 2022

Description

My Besu node seems to have become corrupt, possibly after a reorg?

I think this is the second time in a couple weeks this happened. I just re-sync a few weeks ago because of a similar or if not the same bug (I didn't look into it that hard, I figured it was fluke)

2022-12-02 18:57:24.300+00:00 | vert.x-worker-thread-0 | INFO  | EngineNewPayload | Imported #16,098,404 / 156 tx / base fee 14.19 gwei / 19,826,119 (66.1%) gas / (0xabc875990fc719c8363fc652c68b84465514a4be0faf57b69e78da016bb1bc2d) in 2.467s. Peers: 17
2022-12-02 18:57:31.013+00:00 | vert.x-eventloop-thread-11 | ERROR | EthStatsService | Failed to reach the ethstats server Failed to resolve 'ethstats.net' after 2 queries 
2022-12-02 18:57:42.724+00:00 | vert.x-eventloop-thread-13 | ERROR | EthStatsService | Failed to reach the ethstats server Failed to resolve 'ethstats.net' after 2 queries 
2022-12-02 18:57:53.796+00:00 | vert.x-eventloop-thread-15 | ERROR | EthStatsService | Failed to reach the ethstats server Failed to resolve 'ethstats.net' after 2 queries 
2022-12-02 18:57:55.394+00:00 | vert.x-worker-thread-0 | WARN  | DefaultBlockchain | Chain Reorganization +9 new / -0 old
       Old - hash: 0xfd2febdf386ce960c55e6dfbbb36027da157e0b78bcbae677cd51c1b4e0cf5e6, height: 16098394
       New - hash: 0x6371917fba3322ba5341b58c20ea6b122fd6071eb9dbd57ad0d28ca5f44b626f, height: 16098403
  Ancestor - hash: 0xfd2febdf386ce960c55e6dfbbb36027da157e0b78bcbae677cd51c1b4e0cf5e6, height: 16098394
2022-12-02 18:57:55.476+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | VALID for fork-choice-update: head: 0x6371917fba3322ba5341b58c20ea6b122fd6071eb9dbd57ad0d28ca5f44b626f, finalized: 0xd585be57185dae288b2308c8360e5b2e3d2d2219c089d7e82e04c1a8f46ed6b6, safeBlockHash: 0xeab7558264de8d37727a07f432424866a7463c2699490073e25f46519f94cb84
2022-12-02 18:57:58.830+00:00 | vert.x-worker-thread-0 | ERROR | MainnetTransactionProcessor | Critical Exception Processing Transaction
org.hyperledger.besu.ethereum.trie.MerkleTrieException: Unable to load trie node value for hash 0x02e481ac0a91359eba51c88ffd254bbef048e6a71c810c38cba58a68146befbb location 0x
	at org.hyperledger.besu.ethereum.trie.StoredNode.lambda$load$0(StoredNode.java:133)
	at java.base/java.util.Optional.orElseThrow(Optional.java:408)
	at org.hyperledger.besu.ethereum.trie.StoredNode.load(StoredNode.java:131)
	at org.hyperledger.besu.ethereum.trie.StoredNode.accept(StoredNode.java:63)
	at org.hyperledger.besu.ethereum.trie.StoredMerklePatriciaTrie.get(StoredMerklePatriciaTrie.java:119)
	at org.hyperledger.besu.ethereum.bonsai.BonsaiWorldStateKeyValueStorage.getStorageValueBySlotHash(BonsaiWorldStateKeyValueStorage.java:199)
	at org.hyperledger.besu.ethereum.bonsai.BonsaiPersistedWorldState.getStorageValueBySlotHash(BonsaiPersistedWorldState.java:421)
	at org.hyperledger.besu.ethereum.bonsai.BonsaiWorldStateUpdater.getStorageValueBySlotHash(BonsaiWorldStateUpdater.java:353)
	at org.hyperledger.besu.ethereum.bonsai.BonsaiWorldStateUpdater.getStorageValue(BonsaiWorldStateUpdater.java:340)
	at org.hyperledger.besu.ethereum.bonsai.BonsaiAccount.getStorageValue(BonsaiAccount.java:208)
	at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
	at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
	at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
	at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
	at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
	at org.hyperledger.besu.evm.operation.SLoadOperation.execute(SLoadOperation.java:58)
	at org.hyperledger.besu.evm.EVM.runToHalt(EVM.java:282)
	at org.hyperledger.besu.evm.processor.AbstractMessageProcessor.codeExecute(AbstractMessageProcessor.java:161)
	at org.hyperledger.besu.evm.processor.AbstractMessageProcessor.process(AbstractMessageProcessor.java:173)
	at org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor.process(MainnetTransactionProcessor.java:492)
	at org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor.processTransaction(MainnetTransactionProcessor.java:404)
	at org.hyperledger.besu.ethereum.mainnet.AbstractBlockProcessor.processBlock(AbstractBlockProcessor.java:104)
	at org.hyperledger.besu.ethereum.mainnet.BlockProcessor.processBlock(BlockProcessor.java:76)
	at org.hyperledger.besu.ethereum.MainnetBlockValidator.processBlock(MainnetBlockValidator.java:205)
	at org.hyperledger.besu.ethereum.MainnetBlockValidator.validateAndProcessBlock(MainnetBlockValidator.java:135)
	at org.hyperledger.besu.consensus.merge.blockcreation.MergeCoordinator.validateBlock(MergeCoordinator.java:440)
	at org.hyperledger.besu.consensus.merge.blockcreation.MergeCoordinator.rememberBlock(MergeCoordinator.java:454)
	at org.hyperledger.besu.consensus.merge.blockcreation.TransitionCoordinator.rememberBlock(TransitionCoordinator.java:141)
	at org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.engine.EngineNewPayload.syncResponse(EngineNewPayload.java:217)
	at org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.ExecutionEngineJsonRpcMethod.lambda$response$0(ExecutionEngineJsonRpcMethod.java:73)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:829)
2022-12-02 18:57:58.831+00:00 | vert.x-worker-thread-0 | INFO  | AbstractBlockProcessor | Block processing error: transaction invalid Internal Error in Besu - org.hyperledger.besu.ethereum.trie.MerkleTrieException: Unable to load trie node value for hash 0x02e481ac0a91359eba51c88ffd254bbef048e6a71c810c38cba58a68146befbb location 0x. Block 0x47d61f6dca45a190d79b2f5fda11c0b8eca83ce1ba2a5c8675e3d37eda836ac1 Transaction 0x7a74c82d2174681c6cd1cc529d685cd76f4fc470967cf107b503a151eecea617
2022-12-02 18:57:58.832+00:00 | vert.x-worker-thread-0 | INFO  | MainnetBlockValidator | Optional[Block processing error: transaction invalid Internal Error in Besu - org.hyperledger.besu.ethereum.trie.MerkleTrieException: Unable to load trie node value for hash 0x02e481ac0a91359eba51c88ffd254bbef048e6a71c810c38cba58a68146befbb location 0x. Block 0x47d61f6dca45a190d79b2f5fda11c0b8eca83ce1ba2a5c8675e3d37eda836ac1 Transaction 0x7a74c82d2174681c6cd1cc529d685cd76f4fc470967cf107b503a151eecea617]. Block 16098405 (0x47d61f6dca45a190d79b2f5fda11c0b8eca83ce1ba2a5c8675e3d37eda836ac1)
2022-12-02 18:57:58.836+00:00 | vert.x-worker-thread-0 | WARN  | EngineNewPayload | Invalid new payload: number: 16098405, hash: 0x47d61f6dca45a190d79b2f5fda11c0b8eca83ce1ba2a5c8675e3d37eda836ac1, parentHash: 0xabc875990fc719c8363fc652c68b84465514a4be0faf57b69e78da016bb1bc2d, latestValidHash: 0xabc875990fc719c8363fc652c68b84465514a4be0faf57b69e78da016bb1bc2d, status: INVALID, validationError: Block processing error: transaction invalid Internal Error in Besu - org.hyperledger.besu.ethereum.trie.MerkleTrieException: Unable to load trie node value for hash 0x02e481ac0a91359eba51c88ffd254bbef048e6a71c810c38cba58a68146befbb location 0x. Block 0x47d61f6dca45a190d79b2f5fda11c0b8eca83ce1ba2a5c8675e3d37eda836ac1 Transaction 0x7a74c82d2174681c6cd1cc529d685cd76f4fc470967cf107b503a151eecea617

Here is the important part of my Docker-Compose:

    image: hyperledger/besu:latest
    command:
      - --data-path=/data
      - --network=MAINNET
      - --data-storage-format=BONSAI
      - --Xbonsai-use-snapshots=true
      - --sync-mode=X_SNAP
      - --p2p-port=30303
      - --pruning-enabled
      - --nat-method=DOCKER
      - --rpc-http-enabled=true
      - --rpc-http-apis=ADMIN,DEBUG,ETH,NET,TRACE,TXPOOL,WEB3
      - --rpc-http-host=0.0.0.0
      - --rpc-http-port=8545
      - --rpc-http-cors-origins=*
      - --host-allowlist=*
      - --rpc-ws-enabled=true
      - --rpc-ws-apis=ADMIN,DEBUG,ETH,NET,TRACE,TXPOOL,WEB3
      - --rpc-ws-host=0.0.0.0
      - --rpc-ws-port=8546
      - --engine-rpc-enabled
      - --engine-rpc-port=8551
      - --engine-jwt-secret=/data/jwtsecret
      - --engine-host-allowlist=*
      - --Xplugin-rocksdb-high-spec-enabled

I also have some of these in my logs from earlier:

2022-12-02 16:49:17.231+00:00 | vert.x-worker-thread-0 | WARN  | EngineNewPayload | Invalid new payload: number: 16098395, hash: 0x3d23c3ff2ab9cdb7dec49c0314660c93c6f65b5607f716f6f15d00798c1a281e, parentHash: 0xfd2febdf386ce960c55e6dfbbb36027da157e0b78bcbae677cd51c1b4e0cf5e6, latestValidHash: 0x0000000000000000000000000000000000000000000000000000000000000000, status: INVALID, validationError: Block already present in bad block manager.
@ladidan
Copy link

ladidan commented Dec 4, 2022

I ran into the same issue on v22.10.2

Setting --Xbonsai-use-snapshots to false and restarting the container resolved this on my end

@non-fungible-nelson
Copy link
Contributor

Thanks for reporting this! Have you tried what was recommended above? We have made some changes to snapshots that are now default as of 22.10.2 (and somewhat conflicted with --Xbonsai-use-snapshots), and this flag might be causing issues.

@MysticRyuujin
Copy link
Author

Sorry, no, I started a resync on the latest release. Are my flags fine as is on latest version or do you recommend changes?

@non-fungible-nelson
Copy link
Contributor

We recommend removing that flag right now. It is still an experimental feature/flag and we are continuing to tweak Bonsai snapshots.

@systemfreund
Copy link

systemfreund commented Jan 29, 2023

I recently switched from erigon to besu, because the former was too unreliable.
Unfortunately I'm now getting the same error, however I don't have this --Xbonsai-use-snapshots=true option set at all.
Any chance to fix this issue without having to do a complete re-sync which takes ~1week on the machine this is running on?

Version: 23.1.0-RC1
sync-mode: X_SNAP
data-storage-format: BONSAI
pruning: disabled

Stacktrace of when it first happened:

2023-01-29 04:12:50.003+01:00 | vert.x-worker-thread-0 | INFO  | AbstractEngineNewPayload | Imported #16.509.716 / 111 tx / base fee 13,43 gwei / 8.642.095 (28,8%) gas / (0x5cae2289086932a7b38054ae5e38d6820170da33cd79399c10aeb1d625>
2023-01-29 04:12:50.806+01:00 | vert.x-worker-thread-0 | INFO  | AbstractEngineForkchoiceUpdated | VALID for fork-choice-update: head: 0x5cae2289086932a7b38054ae5e38d6820170da33cd79399c10aeb1d625bb7dbe, finalized: 0xe414b8bb32bd8c2>
2023-01-29 04:13:06.605+01:00 | vert.x-worker-thread-0 | INFO  | AbstractEngineNewPayload | Imported #16.509.717 / 103 tx / base fee 12,72 gwei / 29.995.807 (100,0%) gas / (0x5027c86ed0721944c0d352dcd17f0d860ea4bcebda27986b2c71cfff>
2023-01-29 04:13:15.288+01:00 | vert.x-worker-thread-0 | ERROR | MainnetTransactionProcessor | Critical Exception Processing Transaction
org.hyperledger.besu.ethereum.trie.MerkleTrieException: Unable to load trie node value for hash 0xbacf82164773dd5e44db5bad9113cb4d50b76ed6103e9211412cc120d9734efe location 0x06020e
        at org.hyperledger.besu.ethereum.trie.StoredNode.lambda$load$0(StoredNode.java:135)
        at java.base/java.util.Optional.orElseThrow(Optional.java:403)
        at org.hyperledger.besu.ethereum.trie.StoredNode.load(StoredNode.java:133)
        at org.hyperledger.besu.ethereum.trie.StoredNode.accept(StoredNode.java:65)
        at org.hyperledger.besu.ethereum.trie.GetVisitor.visit(GetVisitor.java:46)
        at org.hyperledger.besu.ethereum.trie.BranchNode.accept(BranchNode.java:80)
        at org.hyperledger.besu.ethereum.trie.StoredNode.accept(StoredNode.java:66)
        at org.hyperledger.besu.ethereum.trie.GetVisitor.visit(GetVisitor.java:46)
        at org.hyperledger.besu.ethereum.trie.BranchNode.accept(BranchNode.java:80)
        at org.hyperledger.besu.ethereum.trie.StoredNode.accept(StoredNode.java:66)
        at org.hyperledger.besu.ethereum.trie.GetVisitor.visit(GetVisitor.java:46)
        at org.hyperledger.besu.ethereum.trie.BranchNode.accept(BranchNode.java:80)
        at org.hyperledger.besu.ethereum.trie.StoredNode.accept(StoredNode.java:66)
        at org.hyperledger.besu.ethereum.trie.StoredMerklePatriciaTrie.get(StoredMerklePatriciaTrie.java:119)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiWorldStateKeyValueStorage.getStorageValueBySlotHash(BonsaiWorldStateKeyValueStorage.java:202)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiPersistedWorldState.getStorageValueBySlotHash(BonsaiPersistedWorldState.java:426)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiWorldStateUpdater.getStorageValueBySlotHash(BonsaiWorldStateUpdater.java:359)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiWorldStateUpdater.getStorageValue(BonsaiWorldStateUpdater.java:342)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiAccount.getStorageValue(BonsaiAccount.java:208)
        at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
        at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
        at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
        at org.hyperledger.besu.evm.operation.SLoadOperation.execute(SLoadOperation.java:58)
        at org.hyperledger.besu.evm.EVM.runToHalt(EVM.java:280)
        at org.hyperledger.besu.evm.processor.AbstractMessageProcessor.codeExecute(AbstractMessageProcessor.java:161)
        at org.hyperledger.besu.evm.processor.AbstractMessageProcessor.process(AbstractMessageProcessor.java:173)
        at org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor.process(MainnetTransactionProcessor.java:498)
        at org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor.processTransaction(MainnetTransactionProcessor.java:406)

Stacktrace after restarting besu:

2023-01-29 10:11:30.040+01:00 | EthScheduler-Timer-0 | INFO  | BackwardSyncContext | Current backward sync session failed, it will be restarted
2023-01-29 10:11:30.368+01:00 | vert.x-worker-thread-0 | INFO  | BackwardSyncContext | Starting a new backward sync session
2023-01-29 10:11:30.895+01:00 | nioEventLoopGroup-3-10 | INFO  | BackwardSyncStep | Backward sync phase 1 of 2, 99,05% completed, downloaded 524 headers of at least 529. Peers: 2
2023-01-29 10:11:31.593+01:00 | nioEventLoopGroup-3-10 | INFO  | BackwardSyncStep | Backward sync phase 1 of 2 completed, downloaded a total of 726 headers. Peers: 2
2023-01-29 10:12:10.769+01:00 | nioEventLoopGroup-3-4 | ERROR | MainnetTransactionProcessor | Critical Exception Processing Transaction
org.hyperledger.besu.ethereum.trie.MerkleTrieException: Unable to load trie node value for hash 0xbacf82164773dd5e44db5bad9113cb4d50b76ed6103e9211412cc120d9734efe location 0x06020e
        at org.hyperledger.besu.ethereum.trie.StoredNode.lambda$load$0(StoredNode.java:135)
        at java.base/java.util.Optional.orElseThrow(Optional.java:403)
        at org.hyperledger.besu.ethereum.trie.StoredNode.load(StoredNode.java:133)
        at org.hyperledger.besu.ethereum.trie.StoredNode.accept(StoredNode.java:65)
        at org.hyperledger.besu.ethereum.trie.GetVisitor.visit(GetVisitor.java:46)
        at org.hyperledger.besu.ethereum.trie.BranchNode.accept(BranchNode.java:80)
        at org.hyperledger.besu.ethereum.trie.StoredNode.accept(StoredNode.java:66)
        at org.hyperledger.besu.ethereum.trie.GetVisitor.visit(GetVisitor.java:46)
        at org.hyperledger.besu.ethereum.trie.BranchNode.accept(BranchNode.java:80)
        at org.hyperledger.besu.ethereum.trie.StoredNode.accept(StoredNode.java:66)
        at org.hyperledger.besu.ethereum.trie.GetVisitor.visit(GetVisitor.java:46)
        at org.hyperledger.besu.ethereum.trie.BranchNode.accept(BranchNode.java:80)
        at org.hyperledger.besu.ethereum.trie.StoredNode.accept(StoredNode.java:66)
        at org.hyperledger.besu.ethereum.trie.StoredMerklePatriciaTrie.get(StoredMerklePatriciaTrie.java:119)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiWorldStateKeyValueStorage.getStorageValueBySlotHash(BonsaiWorldStateKeyValueStorage.java:202)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiPersistedWorldState.getStorageValueBySlotHash(BonsaiPersistedWorldState.java:426)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiWorldStateUpdater.getStorageValueBySlotHash(BonsaiWorldStateUpdater.java:359)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiWorldStateUpdater.getStorageValue(BonsaiWorldStateUpdater.java:342)
        at org.hyperledger.besu.ethereum.bonsai.BonsaiAccount.getStorageValue(BonsaiAccount.java:208)
        at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
        at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
        at org.hyperledger.besu.evm.worldstate.UpdateTrackingAccount.getStorageValue(UpdateTrackingAccount.java:213)
        at org.hyperledger.besu.evm.operation.SLoadOperation.execute(SLoadOperation.java:58)
        at org.hyperledger.besu.evm.EVM.runToHalt(EVM.java:280)
        at org.hyperledger.besu.evm.processor.AbstractMessageProcessor.codeExecute(AbstractMessageProcessor.java:161)
        at org.hyperledger.besu.evm.processor.AbstractMessageProcessor.process(AbstractMessageProcessor.java:173)
        at org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor.process(MainnetTransactionProcessor.java:498)
        at org.hyperledger.besu.ethereum.mainnet.MainnetTransactionProcessor.processTransaction(MainnetTransactionProcessor.java:406)
        at org.hyperledger.besu.ethereum.mainnet.AbstractBlockProcessor.processBlock(AbstractBlockProcessor.java:104)
        at org.hyperledger.besu.ethereum.mainnet.BlockProcessor.processBlock(BlockProcessor.java:76)
        at org.hyperledger.besu.ethereum.MainnetBlockValidator.processBlock(MainnetBlockValidator.java:205)
        at org.hyperledger.besu.ethereum.MainnetBlockValidator.validateAndProcessBlock(MainnetBlockValidator.java:135)
        at org.hyperledger.besu.ethereum.MainnetBlockValidator.validateAndProcessBlock(MainnetBlockValidator.java:74)
        at org.hyperledger.besu.ethereum.eth.sync.backwardsync.BackwardSyncContext.saveBlock(BackwardSyncContext.java:302)
        at org.hyperledger.besu.ethereum.eth.sync.backwardsync.ForwardSyncStep.saveBlocks(ForwardSyncStep.java:124)
        at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:646)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2179)
        at org.hyperledger.besu.ethereum.eth.manager.task.RetryingGetBlocksFromPeersTask.lambda$executeTaskOnCurrentPeer$0(RetryingGetBlocksFromPeersTask.java:88)

Interestingly, after rebooting my node the exceptions stopped appearing, but now I'm getting these:

2023-01-29 11:18:23.050+01:00 | vert.x-worker-thread-0 | INFO  | BackwardSyncContext | Starting a new backward sync session
2023-01-29 11:18:23.058+01:00 | vert.x-worker-thread-0 | INFO  | BackwardsSyncAlgorithm | Current backward sync session is done
2023-01-29 11:18:23.390+01:00 | vert.x-worker-thread-0 | WARN  | MergeCoordinator | Internal error, backward sync completed but failed to import finalized block 0x1817f8b9fbaaa089f219278bb9cce1cef3bb7fdd73afd6210ee79b753ca6c00c
2023-01-29 11:18:55.053+01:00 | Timer-0 | INFO  | DNSResolver | Resolved 2409 nodes
2023-01-29 11:24:47.023+01:00 | vert.x-worker-thread-0 | WARN  | MergeCoordinator | Internal error, backward sync completed but failed to import finalized block 0x1817f8b9fbaaa089f219278bb9cce1cef3bb7fdd73afd6210ee79b753ca6c00c
2023-01-29 11:31:11.023+01:00 | vert.x-worker-thread-0 | WARN  | MergeCoordinator | Internal error, backward sync completed but failed to import finalized block 0x1817f8b9fbaaa089f219278bb9cce1cef3bb7fdd73afd6210ee79b753ca6c00c
2023-01-29 11:37:35.023+01:00 | vert.x-worker-thread-0 | WARN  | MergeCoordinator | Internal error, backward sync completed but failed to import finalized block 0x1817f8b9fbaaa089f219278bb9cce1cef3bb7fdd73afd6210ee79b753ca6c00c
2023-01-29 11:43:59.025+01:00 | vert.x-worker-thread-0 | WARN  | MergeCoordinator | Internal error, backward sync completed but failed to import finalized block 0x1817f8b9fbaaa089f219278bb9cce1cef3bb7fdd73afd6210ee79b753ca6c00c
2023-01-29 11:50:23.026+01:00 | vert.x-worker-thread-0 | WARN  | MergeCoordinator | Internal error, backward sync completed but failed to import finalized block 0x1817f8b9fbaaa089f219278bb9cce1cef3bb7fdd73afd6210ee79b753ca6c00c
2023-01-29 11:56:47.025+01:00 | vert.x-worker-thread-0 | WARN  | MergeCoordinator | Internal error, backward sync completed but failed to import finalized block 0x1817f8b9fbaaa089f219278bb9cce1cef3bb7fdd73afd6210ee79b753ca6c00c

@non-fungible-nelson
Copy link
Contributor

non-fungible-nelson commented Jan 29, 2023

It seems you have the same issue we are working on for our 23.1.0 release coming in a week or 2. Either you can wait for that release, where we will include a tool to heal existing nodes with this problem, or re-sync. @matkt - maybe we can work with this user's database to test your node healing PR prior to the release?

@systemfreund
Copy link

maybe we can work with this user's database to test your node healing PR prior to the release?

I started a new sync, but I'm keeping the corrupt database around so I can help test the healing feature.

@matkt
Copy link
Contributor

matkt commented Feb 5, 2023

Hi we have a new PR with a auto heal mechanism . it chould fix your problem. since your node is very old it will take time to heal (but possible in my test it was 2 hours, 27 minutes to heal a node that had been inconsistent for a week) and for the next time it will be very fast because it will be instant #4972.

@matkt matkt mentioned this issue Feb 5, 2023
2 tasks
@systemfreund
Copy link

Thanks, I've built your branch and it's currently running on the corrupt database. I'll get back to you when it's done or something goes wrong

@matkt
Copy link
Contributor

matkt commented Feb 6, 2023

Thanks for your help

@systemfreund
Copy link

It managed to repair the database!

@systemfreund
Copy link

systemfreund commented Feb 7, 2023

Update: it's now failing with another error, which appears to be related to #4784 (still running your branch)

2023-02-07 08:02:14.365+01:00 | vert.x-eventloop-thread-1 | ERROR | ExecutionEngineJsonRpcMethod | failed to exec consensus method engine_newPayloadV1                                                                                  java.lang.RuntimeException: java.lang.RuntimeException: org.hyperledger.besu.plugin.services.exception.StorageException: Unable to copy Layered Worldstate for 0x511fe94e5054fe7d44907924a92ff369a6fc2c18ad602dca38f9552e83807c5c               at org.hyperledger.besu.ethereum.MainnetBlockValidator.validateAndProcessBlock(MainnetBlockValidator.java:184)                                                                                                                          at org.hyperledger.besu.consensus.merge.blockcreation.MergeCoordinator.validateBlock(MergeCoordinator.java:477)                                                                                         
        at org.hyperledger.besu.consensus.merge.blockcreation.MergeCoordinator.rememberBlock(MergeCoordinator.java:491)
        at org.hyperledger.besu.consensus.merge.blockcreation.TransitionCoordinator.rememberBlock(TransitionCoordinator.java:157)
        at org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.engine.AbstractEngineNewPayload.syncResponse(AbstractEngineNewPayload.java:235)                                                                                           at org.hyperledger.besu.ethereum.api.jsonrpc.internal.methods.ExecutionEngineJsonRpcMethod.lambda$response$0(ExecutionEngineJsonRpcMethod.java:73)                                                                              
        at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)                                                                                                                                                           
        at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)                                                                                                                                                        
        at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)                                                                                                                                                
        at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)                                                                                                                                                                          
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)          
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)                                                                                                                                    
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)                                                                                                                                        
        at java.base/java.lang.Thread.run(Thread.java:1589)                                                                                                                                                                             
Caused by: java.lang.RuntimeException: org.hyperledger.besu.plugin.services.exception.StorageException: Unable to copy Layered Worldstate for 0x511fe94e5054fe7d44907924a92ff369a6fc2c18ad602dca38f9552e83807c5c                        
        at org.hyperledger.besu.ethereum.bonsai.BonsaiLayeredWorldState.copy(BonsaiLayeredWorldState.java:298)                                                                                                                                  at org.hyperledger.besu.ethereum.MainnetBlockValidator.lambda$validateAndProcessBlock$0(MainnetBlockValidator.java:120)                                                                                                         
        at java.base/java.util.Optional.map(Optional.java:260)                                                                                                                                                                                  at org.hyperledger.besu.ethereum.MainnetBlockValidator.validateAndProcessBlock(MainnetBlockValidator.java:117)                                                                                                                          ... 13 more                                                                                                                                                                                                                     
Caused by: org.hyperledger.besu.plugin.services.exception.StorageException: Unable to copy Layered Worldstate for 0x511fe94e5054fe7d44907924a92ff369a6fc2c18ad602dca38f9552e83807c5c                                                    
        at org.hyperledger.besu.ethereum.bonsai.BonsaiLayeredWorldState.lambda$copy$5(BonsaiLayeredWorldState.java:293)                                                                                                                         at java.base/java.util.Optional.orElseThrow(Optional.java:403)                                                                                                                                                                  
        at org.hyperledger.besu.ethereum.bonsai.BonsaiLayeredWorldState.copy(BonsaiLayeredWorldState.java:290)                                                                                                                                  ... 16 more                                                                                                                                                                                                                     

@matkt
Copy link
Contributor

matkt commented Feb 7, 2023

can you try this latest version ? Thanks for your help #5059

@matkt
Copy link
Contributor

matkt commented Feb 7, 2023

Have you managed to import blocks between the heal and this error?

@matkt
Copy link
Contributor

matkt commented Feb 7, 2023

What is the commit you use to find out if you have Gary's fix?

@systemfreund
Copy link

systemfreund commented Feb 7, 2023

Have you managed to import blocks between the heal and this error?

Yes, after the healing and syncing it did import new blocks sucessfully. Then I went to bed and in the next morning the log was full of the exceptions I've posted above.

The version I ran is the one from this PR #4972 (commit 686a9cc)

@matkt
Copy link
Contributor

matkt commented Feb 7, 2023

I added more update in the pr #5059 If you can try it otherwise I think we should switch to debug logs some packages to understand the problem

@matkt
Copy link
Contributor

matkt commented Feb 9, 2023

It is a regression in the main. My Pr had the main branch. We try to fix this

@matkt
Copy link
Contributor

matkt commented Feb 13, 2023

We just merged a fix for the second bug. Unfortunately no heal for this one. But your new node will have no problem if it contains these last two fixed

@non-fungible-nelson non-fungible-nelson added the TeamChupa GH issues worked on by Chupacabara Team label Mar 7, 2023
@non-fungible-nelson
Copy link
Contributor

Tracking in refactor for #5123 of Bonsai that will address this.

@bharath-123
Copy link

hey @non-fungible-nelson @matkt is there a besu release which includes this fix? I couldn't find whether it was fixed or not in a release in github

@non-fungible-nelson
Copy link
Contributor

Yes - I might update the changelog specifically to reference these issues, but the bonsai refactor #5123, fixes these issues on release 23.1.2.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
TeamChupa GH issues worked on by Chupacabara Team
Projects
None yet
Development

No branches or pull requests

6 participants