node broken when syncing with the experimental engine for opBNB

[yutianwu]

Describe the bug

hi, currently we are testing the new engine for opBNB, and we found it will break the node if we sync with the new engine.

Below are the steps to reproduce the issue:

1. Sync to the latest block for the opBNB testnet.
2. Switch to the experimental engine and wait for the below log:

2024-09-18T08:29:30.084838Z  INFO New payload job created id=0x3fba886e4481b47b parent=0x153350161f290041a86195c036ad6608375cef15ca0e6d0defb23e0c12af8088
2024-09-18T08:29:30.090186Z  INFO Canonical chain committed number=39769606 hash=0x59b9df45e950656eb06b1898e6692334f8b375e70f937e0a222f34a6e5fc0c98 elapsed=28.496µs

3. Unwind the node to the previous block 39769500(random pointed one), then it will complain like below:

2024-09-18T08:30:30.346719Z  INFO Verifying storage consistency.
2024-09-18T08:30:30.358165Z  INFO Executing a pipeline unwind. range=39769501..=39769599 highest_static_file_block=39769599
2024-09-18T08:30:30.361223Z  INFO Unwinding{stage=Finish}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.361255Z  INFO Unwinding{stage=Finish}: Stage unwound stage=Finish unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.361581Z  INFO Unwinding{stage=IndexAccountHistory}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.365881Z  INFO Unwinding{stage=IndexAccountHistory}: Stage unwound stage=IndexAccountHistory unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.366452Z  INFO Unwinding{stage=IndexStorageHistory}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.378700Z  INFO Unwinding{stage=IndexStorageHistory}: Stage unwound stage=IndexStorageHistory unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.380137Z  INFO Unwinding{stage=TransactionLookup}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.385869Z  INFO Unwinding{stage=TransactionLookup}: Stage unwound stage=TransactionLookup unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.388696Z  INFO Unwinding{stage=MerkleExecute}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.388722Z  INFO Unwinding{stage=MerkleExecute}: Stage is always skipped
2024-09-18T08:30:30.388730Z  INFO Unwinding{stage=MerkleExecute}: Stage unwound stage=MerkleExecute unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.389133Z  INFO Unwinding{stage=StorageHashing}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.391430Z  INFO Unwinding{stage=StorageHashing}: Stage unwound stage=StorageHashing unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.392642Z  INFO Unwinding{stage=AccountHashing}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.393060Z  INFO Unwinding{stage=AccountHashing}: Stage unwound stage=AccountHashing unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.393553Z  INFO Unwinding{stage=MerkleUnwind}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.408395Z ERROR Unwinding{stage=MerkleUnwind}: Failed to verify block state root! 
Invalid state root error on stage verification!
This is an error that likely requires a report to the reth team with additional information.
Please include the following information in your report:
 * This error message
 * The state root of the block that was rejected
 * The output of `reth db stats --checksum` from the database that was being used. This will take a long time to run!
 * 50-100 lines of logs before and after the first occurrence of the log message with the state root of the block that was rejected.
 * The debug logs from __the same time period__. To find the default location for these logs, run:
   `reth --help | grep -A 4 'log.file.directory'`

Once you have this information, please submit a github issue at https://github.com/paradigmxyz/reth/issues/new
 target_block=39769500 got=0xe0c38e0d5885a7b69968d19d80c1de7aeffadb113fd6fe655421d3e04023161f expected=SealedHeader { hash: 0xa3b00657dbea5365d913890e9426059df025c6289fec3a4b65fc1edb88375883, header: Header { parent_hash: 0xb961a851f130d28901cac90dd9be25166bbef79e5695d0bdd2a3e684a0514000, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x4200000000000000000000000000000000000011, state_root: 0x50971c4b2592bf6a57b60428c1b4f74cdea8dd2497b290938b36c9ed701ecfe0, transactions_root: 0x2b56d9274a39ea846b64dfa71382b0763f391c63e89ee586fc870e077abf721c, receipts_root: 0x90fcb72a8e5f0f5dc0507a86b93b665ae43570ef3587738a685edd70e026bab7, withdrawals_root: Some(0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421), logs_bloom: 0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, difficulty: 0, number: 39769500, gas_limit: 100000000, gas_used: 43851, timestamp: 1726648006, mix_hash: 0x0000000000000000000000000000000000000000000000000000000000000000, nonce: 0, base_fee_per_gas: Some(0), blob_gas_used: Some(0), excess_blob_gas: Some(0), parent_beacon_block_root: Some(0x0000000000000000000000000000000000000000000000000000000000000000), requests_root: None, extra_data: 0x } }
2024-09-18T08:30:30.417302Z ERROR shutting down due to error

So far, this node is broken already since we cannot unwind the node to a previous block, and it cannot pass the storage consistency check.

The cause should be the newpayload API skipped the execution for the payload built by reth.

reth/crates/engine/tree/src/tree/mod.rs

Line 2105 in 5e9f381

return Ok(InsertPayloadOk2::AlreadySeen(BlockStatus2::Valid))

If we don't skip the execution by commenting the below code, it will not have such an issue:

reth/crates/node/builder/src/launch/engine.rs

Line 349 in 5e9f381

eth_service.orchestrator_mut().handler_mut().handler_mut().on_event(EngineApiRequest::InsertExecutedBlock(executed_block).into());

The full log for this case is

2024-09-18T08:29:30.084838Z  INFO New payload job created id=0x3fba886e4481b47b parent=0x153350161f290041a86195c036ad6608375cef15ca0e6d0defb23e0c12af8088
2024-09-18T08:29:30.088630Z  INFO sealed built block block=39769606 header=SealedHeader { hash: 0x59b9df45e950656eb06b1898e6692334f8b375e70f937e0a222f34a6e5fc0c98, header: Header { parent_hash: 0x153350161f290041a86195c036ad6608375cef15ca0e6d0defb23e0c12af8088, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x4200000000000000000000000000000000000011, state_root: 0xdbed6473cb27eb419072c4d231bbd90fb0e67cf6b55c6026ba446e73f18b366d, transactions_root: 0xa519d980da727c41fce988b620bb8452fdc3c62d923b271239f69c825e152da5, receipts_root: 0x7b1837241c45cde64d8de895a7cdb0e33015b400c601949d3a8b9a763c0130f9, withdrawals_root: Some(0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421), logs_bloom: 0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000008000000001000000000000000000000000000000000000000000000000000000000000080000000001100000000000000000000000000000000000000000200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004000000000000000000000000000001000000000000000000000000000000000200000000000, difficulty: 0, number: 39769606, gas_limit: 100000000, gas_used: 86636, timestamp: 1726648112, mix_hash: 0x0000000000000000000000000000000000000000000000000000000000000000, nonce: 0, base_fee_per_gas: Some(0), blob_gas_used: Some(0), excess_blob_gas: Some(0), parent_beacon_block_root: Some(0x0000000000000000000000000000000000000000000000000000000000000000), requests_root: None, extra_data: 0x } }
2024-09-18T08:29:30.090186Z  INFO Canonical chain committed number=39769606 hash=0x59b9df45e950656eb06b1898e6692334f8b375e70f937e0a222f34a6e5fc0c98 elapsed=28.496µs

The additional log is added by me to check the correctness of the state root of built payload. But it's right.

So one of my guess is the issue is caused by the state share to prevent the re-execution of the payload. Can you help confirm that? Thanks a lot.

Since it may caused by us merging the code, we will much appreciate it if you can help confirm that it's not an issue of reth.

This tag is which we tested against: https://github.com/paradigmxyz/reth/releases/tag/v1.0.6

Steps to reproduce

1. Sync to the latest block for the opBNB testnet.
2. Switch to the experimental engine and wait for the below log:

2024-09-18T08:29:30.084838Z  INFO New payload job created id=0x3fba886e4481b47b parent=0x153350161f290041a86195c036ad6608375cef15ca0e6d0defb23e0c12af8088
2024-09-18T08:29:30.090186Z  INFO Canonical chain committed number=39769606 hash=0x59b9df45e950656eb06b1898e6692334f8b375e70f937e0a222f34a6e5fc0c98 elapsed=28.496µs

3. Unwind the node to the previous block 39769500, then it will complain like below:

2024-09-18T08:30:30.346719Z  INFO Verifying storage consistency.
2024-09-18T08:30:30.358165Z  INFO Executing a pipeline unwind. range=39769501..=39769599 highest_static_file_block=39769599
2024-09-18T08:30:30.361223Z  INFO Unwinding{stage=Finish}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.361255Z  INFO Unwinding{stage=Finish}: Stage unwound stage=Finish unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.361581Z  INFO Unwinding{stage=IndexAccountHistory}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.365881Z  INFO Unwinding{stage=IndexAccountHistory}: Stage unwound stage=IndexAccountHistory unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.366452Z  INFO Unwinding{stage=IndexStorageHistory}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.378700Z  INFO Unwinding{stage=IndexStorageHistory}: Stage unwound stage=IndexStorageHistory unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.380137Z  INFO Unwinding{stage=TransactionLookup}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.385869Z  INFO Unwinding{stage=TransactionLookup}: Stage unwound stage=TransactionLookup unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.388696Z  INFO Unwinding{stage=MerkleExecute}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.388722Z  INFO Unwinding{stage=MerkleExecute}: Stage is always skipped
2024-09-18T08:30:30.388730Z  INFO Unwinding{stage=MerkleExecute}: Stage unwound stage=MerkleExecute unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.389133Z  INFO Unwinding{stage=StorageHashing}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.391430Z  INFO Unwinding{stage=StorageHashing}: Stage unwound stage=StorageHashing unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.392642Z  INFO Unwinding{stage=AccountHashing}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.393060Z  INFO Unwinding{stage=AccountHashing}: Stage unwound stage=AccountHashing unwind_to=39769500 progress=39769500 done=true
2024-09-18T08:30:30.393553Z  INFO Unwinding{stage=MerkleUnwind}: Starting unwind from=39769599 to=39769500 bad_block=None
2024-09-18T08:30:30.408395Z ERROR Unwinding{stage=MerkleUnwind}: Failed to verify block state root! 
Invalid state root error on stage verification!
This is an error that likely requires a report to the reth team with additional information.
Please include the following information in your report:
 * This error message
 * The state root of the block that was rejected
 * The output of `reth db stats --checksum` from the database that was being used. This will take a long time to run!
 * 50-100 lines of logs before and after the first occurrence of the log message with the state root of the block that was rejected.
 * The debug logs from __the same time period__. To find the default location for these logs, run:
   `reth --help | grep -A 4 'log.file.directory'`

Once you have this information, please submit a github issue at https://github.com/paradigmxyz/reth/issues/new
 target_block=39769500 got=0xe0c38e0d5885a7b69968d19d80c1de7aeffadb113fd6fe655421d3e04023161f expected=SealedHeader { hash: 0xa3b00657dbea5365d913890e9426059df025c6289fec3a4b65fc1edb88375883, header: Header { parent_hash: 0xb961a851f130d28901cac90dd9be25166bbef79e5695d0bdd2a3e684a0514000, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x4200000000000000000000000000000000000011, state_root: 0x50971c4b2592bf6a57b60428c1b4f74cdea8dd2497b290938b36c9ed701ecfe0, transactions_root: 0x2b56d9274a39ea846b64dfa71382b0763f391c63e89ee586fc870e077abf721c, receipts_root: 0x90fcb72a8e5f0f5dc0507a86b93b665ae43570ef3587738a685edd70e026bab7, withdrawals_root: Some(0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421), logs_bloom: 0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, difficulty: 0, number: 39769500, gas_limit: 100000000, gas_used: 43851, timestamp: 1726648006, mix_hash: 0x0000000000000000000000000000000000000000000000000000000000000000, nonce: 0, base_fee_per_gas: Some(0), blob_gas_used: Some(0), excess_blob_gas: Some(0), parent_beacon_block_root: Some(0x0000000000000000000000000000000000000000000000000000000000000000), requests_root: None, extra_data: 0x } }
2024-09-18T08:30:30.417302Z ERROR shutting down due to error

The full log for this case is

2024-09-18T08:29:30.084838Z  INFO New payload job created id=0x3fba886e4481b47b parent=0x153350161f290041a86195c036ad6608375cef15ca0e6d0defb23e0c12af8088
2024-09-18T08:29:30.088630Z  INFO sealed built block block=39769606 header=SealedHeader { hash: 0x59b9df45e950656eb06b1898e6692334f8b375e70f937e0a222f34a6e5fc0c98, header: Header { parent_hash: 0x153350161f290041a86195c036ad6608375cef15ca0e6d0defb23e0c12af8088, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x4200000000000000000000000000000000000011, state_root: 0xdbed6473cb27eb419072c4d231bbd90fb0e67cf6b55c6026ba446e73f18b366d, transactions_root: 0xa519d980da727c41fce988b620bb8452fdc3c62d923b271239f69c825e152da5, receipts_root: 0x7b1837241c45cde64d8de895a7cdb0e33015b400c601949d3a8b9a763c0130f9, withdrawals_root: Some(0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421), logs_bloom: 0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000008000000001000000000000000000000000000000000000000000000000000000000000080000000001100000000000000000000000000000000000000000200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004000000000000000000000000000001000000000000000000000000000000000200000000000, difficulty: 0, number: 39769606, gas_limit: 100000000, gas_used: 86636, timestamp: 1726648112, mix_hash: 0x0000000000000000000000000000000000000000000000000000000000000000, nonce: 0, base_fee_per_gas: Some(0), blob_gas_used: Some(0), excess_blob_gas: Some(0), parent_beacon_block_root: Some(0x0000000000000000000000000000000000000000000000000000000000000000), requests_root: None, extra_data: 0x } }
2024-09-18T08:29:30.090186Z  INFO Canonical chain committed number=39769606 hash=0x59b9df45e950656eb06b1898e6692334f8b375e70f937e0a222f34a6e5fc0c98 elapsed=28.496µs

Node logs

No response

Platform(s)

Linux (x86)

What version/commit are you on?

v1.0.6

What database version are you on?

v1.0.6

Which chain / network are you on?

opBNB

What type of node are you running?

Archive (default)

What prune config do you use, if any?

No response

If you've built Reth from source, provide the full command you used

No response

Code of Conduct

• I agree to follow the Code of Conduct

[mattsse]

optimistically closing because #10837