search

paradigmxyz / reth

Modular, contributor-friendly and blazing-fast implementation of the Ethereum protocol, in Rust
https://reth.rs/
Apache License 2.0
3.94k stars 1.18k forks source link

write operation CursorInsert failed #7189

Closed dallonby closed 7 months ago

dallonby commented 7 months ago

Describe the bug

Upon restarting reth following upgrading B1 to B2 I received the following error message:

Error: internal database error occurred: write operation CursorInsert failed for key "11fa02ba2c8a25eefadbf303304aa2c8c2b740bbb363189fd4f324a277be6eb4" in table "HeaderNumbers": key/data pair already exists (-30799)

Caused by: write operation CursorInsert failed for key "11fa02ba2c8a25eefadbf303304aa2c8c2b740bbb363189fd4f324a277be6eb4" in table "HeaderNumbers": key/data pair already exists (-30799)

Location: /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/task/poll.rs:255:39

Steps to reproduce

Started reth node

Node logs

2024-03-17T21:00:06.988483Z  INFO reth::cli: Configuration loaded path="/fastStorage/data/reth.v2/reth.toml"
2024-03-17T21:00:06.990092Z  INFO reth::cli: Database opened
2024-03-17T21:00:06.990103Z  INFO reth::cli: Starting metrics endpoint addr=0.0.0.0:9123
2024-03-17T21:00:06.990146Z DEBUG reth::cli: Initializing genesis chain=mainnet genesis=0xd4e56740f876aef8c010b86a40d5f56745a118d0906a34e69aec8c0db1cb8fa3
2024-03-17T21:00:06.990199Z DEBUG reth_node_core::init: Genesis already written, skipping.
2024-03-17T21:00:06.990225Z  INFO reth::cli: Pre-merge hard forks (block based):
- Frontier                         @0
- Homestead                        @1150000
- Dao                              @1920000
- Tangerine                        @2463000
- SpuriousDragon                   @2675000
- Byzantium                        @4370000
- Constantinople                   @7280000
- Petersburg                       @7280000
- Istanbul                         @9069000
- MuirGlacier                      @9200000
- Berlin                           @12244000
- London                           @12965000
- ArrowGlacier                     @13773000
- GrayGlacier                      @15050000
Merge hard forks:
- Paris                            @58750000000000000000000 (network is known to be merged)

Post-merge hard forks (timestamp based):
- Shanghai                         @1681338455
- Cancun                           @1710338135

2024-03-17T21:00:06.990230Z DEBUG reth::cli: Spawning stages metrics listener task
2024-03-17T21:00:06.990654Z DEBUG reth::cli: configured blockchain tree
2024-03-17T21:00:06.990879Z DEBUG reth::cli: creating components
2024-03-17T21:00:06.991086Z DEBUG txpool::blob: Removed blob store directory blob_dir="/fastStorage/data/reth.v2/blobstore"
2024-03-17T21:00:06.991088Z DEBUG txpool::blob: Creating blob store blob_dir="/fastStorage/data/reth.v2/blobstore"
2024-03-17T21:00:07.034754Z  INFO reth::cli: Transaction pool initialized
2024-03-17T21:00:07.034764Z DEBUG reth::cli: Spawned txpool maintenance task
2024-03-17T21:00:07.034787Z  INFO reth::cli: Connecting to P2P network
2024-03-17T21:00:07.034788Z DEBUG reth::cli: Loading p2p key file network_secret_path="/fastStorage/data/reth.v2/discovery-secret"
2024-03-17T21:00:07.035198Z  INFO net::peers: Loading saved peers file=/fastStorage/data/reth.v2/known-peers.json
......
2024-03-17T21:06:04.364381Z DEBUG blockchain_tree: Appending block to canonical chain head=0x971a74bc99259c34bffbe64bc6d862dd9681b961aa633b413d9f9670ea4d9767 parent=(19457007, 0x3fae0168d30c89727fb5c22963ad4335b5f12217261f8e2e2f740211881d77ec)
2024-03-17T21:06:04.459992Z DEBUG disc::dns: No dns entry domain=all.mainnet.ethdisco.net hash="FAVLHT2RC44ICZVG2TE4EY"
2024-03-17T21:06:04.767639Z DEBUG evm: Execution time evm_transact=397.225889ms apply_state=607.415µs apply_post_state=341.721µs merge_transitions=485.202µs receipt_root=897.504µs
2024-03-17T21:06:04.767721Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:04.769156Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:04.769160Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:04.840950Z DEBUG net::session: timed out outgoing request id=1291 remote_peer_id=0x4aeb4ab6c14b23e2c4cfdce879c04b0748a20d8e9b59e25ded2a08143e265c6c25936e74cbc8e641e3312ca288673d91f2f93f8e277de3cfa444ecdaaf982052
2024-03-17T21:06:04.840982Z DEBUG net::session: Received disconnect command for session reason=Some(DisconnectRequested) remote_peer_id=0x4aeb4ab6c14b23e2c4cfdce879c04b0748a20d8e9b59e25ded2a08143e265c6c25936e74cbc8e641e3312ca288673d91f2f93f8e277de3cfa444ecdaaf982052
2024-03-17T21:06:04.934853Z DEBUG evm: Execution time evm_transact=164.370569ms apply_state=237.862µs apply_post_state=1.9µs merge_transitions=247.682µs receipt_root=454.042µs
2024-03-17T21:06:04.934945Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:04.936081Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:04.936085Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:05.081411Z DEBUG evm: Execution time evm_transact=144.212669ms apply_state=244.951µs apply_post_state=1.52µs merge_transitions=256.121µs receipt_root=398.602µs
2024-03-17T21:06:05.081698Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:05.082997Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:05.083001Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:05.270236Z DEBUG evm: Execution time evm_transact=186.022508ms apply_state=290.182µs apply_post_state=2.23µs merge_transitions=281.252µs receipt_root=585.752µs
2024-03-17T21:06:05.270367Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:05.272151Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:05.272156Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:05.476097Z DEBUG evm: Execution time evm_transact=202.056113ms apply_state=486.041µs apply_post_state=2.72µs merge_transitions=386.452µs receipt_root=839.904µs
2024-03-17T21:06:05.476283Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:05.477577Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:05.477581Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:05.582841Z DEBUG evm: Execution time evm_transact=103.870466ms apply_state=270.61µs apply_post_state=1.5µs merge_transitions=216.971µs receipt_root=723.843µs
2024-03-17T21:06:05.582960Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:05.583883Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:05.583886Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:05.609046Z DEBUG evm: Execution time evm_transact=24.871314ms apply_state=66.35µs apply_post_state=1.23µs merge_transitions=53.75µs receipt_root=131.33µs
2024-03-17T21:06:05.609502Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:05.611197Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:05.611200Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:05.840128Z DEBUG evm: Execution time evm_transact=226.682754ms apply_state=542.063µs apply_post_state=2.63µs merge_transitions=589.483µs receipt_root=1.052345ms
2024-03-17T21:06:05.840351Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:05.842387Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:05.842391Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:06.105361Z DEBUG evm: Execution time evm_transact=261.110912ms apply_state=433.901µs apply_post_state=2.55µs merge_transitions=487.543µs receipt_root=757.273µs
2024-03-17T21:06:06.105558Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:06.107489Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:06.107493Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:06.293604Z DEBUG evm: Execution time evm_transact=184.478632ms apply_state=361.942µs apply_post_state=2.39µs merge_transitions=452.382µs receipt_root=751.973µs
2024-03-17T21:06:06.293795Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:06.294538Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:06.294541Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:06.395662Z DEBUG evm: Execution time evm_transact=99.979246ms apply_state=212.702µs apply_post_state=1.66µs merge_transitions=197.931µs receipt_root=449.282µs
2024-03-17T21:06:06.395774Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:06.397038Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:06.397043Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:06.497736Z DEBUG evm: Execution time evm_transact=99.669216ms apply_state=198.14µs apply_post_state=1.63µs merge_transitions=210.391µs receipt_root=383.161µs
2024-03-17T21:06:06.497844Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c
2024-03-17T21:06:06.498859Z DEBUG blockchain_tree: Inserting block into side chain
2024-03-17T21:06:06.498863Z DEBUG blockchain_tree: Appending block to side chain
2024-03-17T21:06:06.624436Z DEBUG evm: Execution time evm_transact=124.412568ms apply_state=232.672µs apply_post_state=1.7µs merge_transitions=282.991µs receipt_root=470.902µs
2024-03-17T21:06:06.624555Z DEBUG blockchain_tree: Inserting block into side chain
........
2024-03-17T21:06:43.273133Z DEBUG providers::db: Inserted block block_number=19457011 actions=[(InsertCanonicalHeaders, 1.36µs), (InsertHeaders, 15.49µs), (InsertHeaderNumbers, 40.71µs), (GetParentTD, 1.16µs), (InsertHeaderTerminalDifficulties, 1.86µs), (GetNextTxNum, 3.89µs), (InsertTransactionSenders, 0ns), (InsertTransactions, 1.648248ms), (InsertTransactionHashNumbers, 85.873034ms), (InsertBlockWithdrawals, 16.311µs), (InsertBlockBodyIndices, 3.16µs), (InsertTransactionBlocks, 3.13µs)]
2024-03-17T21:06:43.363594Z DEBUG providers::db: Inserted block block_number=19457012 actions=[(InsertCanonicalHeaders, 1.31µs), (InsertHeaders, 5.24µs), (InsertHeaderNumbers, 35.61µs), (GetParentTD, 1.11µs), (InsertHeaderTerminalDifficulties, 1.94µs), (GetNextTxNum, 3.57µs), (InsertTransactionSenders, 0ns), (InsertTransactions, 11.309413ms), (InsertTransactionHashNumbers, 79.034562ms), (InsertBlockWithdrawals, 6µs), (InsertBlockBodyIndices, 3.06µs), (InsertTransactionBlocks, 2.84µs)]
2024-03-17T21:06:43.418315Z DEBUG providers::db: Inserted block block_number=19457013 actions=[(InsertCanonicalHeaders, 1.8µs), (InsertHeaders, 4.68µs), (InsertHeaderNumbers, 160.281µs), (GetParentTD, 1.21µs), (InsertHeaderTerminalDifficulties, 1.56µs), (GetNextTxNum, 3.51µs), (InsertTransactionSenders, 0ns), (InsertTransactions, 703.942µs), (InsertTransactionHashNumbers, 53.779609ms), (InsertBlockWithdrawals, 5.86µs), (InsertBlockBodyIndices, 3.48µs), (InsertTransactionBlocks, 3.5µs)]
2024-03-17T21:06:43.441064Z DEBUG providers::db: Inserted block block_number=19457014 actions=[(InsertCanonicalHeaders, 1.47µs), (InsertHeaders, 4.69µs), (InsertHeaderNumbers, 21.27µs), (GetParentTD, 1.29µs), (InsertHeaderTerminalDifficulties, 1.6µs), (GetNextTxNum, 3.98µs), (InsertTransactionSenders, 0ns), (InsertTransactions, 174.5µs), (InsertTransactionHashNumbers, 22.496954ms), (InsertBlockWithdrawals, 5.11µs), (InsertBlockBodyIndices, 2.58µs), (InsertTransactionBlocks, 2.27µs)]
2024-03-17T21:06:43.536695Z DEBUG providers::db: Inserted block block_number=19457015 actions=[(InsertCanonicalHeaders, 1.07µs), (InsertHeaders, 4.48µs), (InsertHeaderNumbers, 21.351µs), (GetParentTD, 1.04µs), (InsertHeaderTerminalDifficulties, 1.56µs), (GetNextTxNum, 2.24µs), (InsertTransactionSenders, 0ns), (InsertTransactions, 1.017003ms), (InsertTransactionHashNumbers, 94.519465ms), (InsertBlockWithdrawals, 5.31µs), (InsertBlockBodyIndices, 3.21µs), (InsertTransactionBlocks, 2.52µs)]
2024-03-17T21:06:43.617940Z DEBUG providers::db: Inserted block block_number=19457016 actions=[(InsertCanonicalHeaders, 1.56µs), (InsertHeaders, 5.53µs), (InsertHeaderNumbers, 54.53µs), (GetParentTD, 1.15µs), (InsertHeaderTerminalDifficulties, 1.52µs), (GetNextTxNum, 3.21µs), (InsertTransactionSenders, 0ns), (InsertTransactions, 1.512754ms), (InsertTransactionHashNumbers, 79.602979ms), (InsertBlockWithdrawals, 5.241µs), (InsertBlockBodyIndices, 2.96µs), (InsertTransactionBlocks, 3.35µs)]
2024-03-17T21:06:43.703413Z DEBUG providers::db: Inserted block block_number=19457017 actions=[(InsertCanonicalHeaders, 1.15µs), (InsertHeaders, 15.29µs), (InsertHeaderNumbers, 36.67µs), (GetParentTD, 900ns), (InsertHeaderTerminalDifficulties, 1.52µs), (GetNextTxNum, 3.7µs), (InsertTransactionSenders, 0ns), (InsertTransactions, 1.888008ms), (InsertTransactionHashNumbers, 83.458714ms), (InsertBlockWithdrawals, 5.51µs), (InsertBlockBodyIndices, 3.14µs), (InsertTransactionBlocks, 2.47µs)]
2024-03-17T21:06:43.740512Z DEBUG providers::db: Inserted block block_number=19457018 actions=[(InsertCanonicalHeaders, 1.28µs), (InsertHeaders, 4.58µs), (InsertHeaderNumbers, 122.6µs), (GetParentTD, 1.07µs), (InsertHeaderTerminalDifficulties, 1.93µs), (GetNextTxNum, 3.29µs), (InsertTransactionSenders, 0ns), (InsertTransactions, 350.722µs), (InsertTransactionHashNumbers, 36.562078ms), (InsertBlockWithdrawals, 9.23µs), (InsertBlockBodyIndices, 2.71µs), (InsertTransactionBlocks, 2.25µs)]
2024-03-17T21:06:43.784133Z DEBUG providers::db: Inserted block block_number=19457019 actions=[(InsertCanonicalHeaders, 1.25µs), (InsertHeaders, 4.05µs), (InsertHeaderNumbers, 19.94µs), (GetParentTD, 890ns), (InsertHeaderTerminalDifficulties, 1.35µs), (GetNextTxNum, 2.72µs), (InsertTransactionSenders, 0ns), (InsertTransactions, 437.801µs), (InsertTransactionHashNumbers, 43.104139ms), (InsertBlockWithdrawals, 9.711µs), (InsertBlockBodyIndices, 3.04µs), (InsertTransactionBlocks, 2.56µs)]
2024-03-17T21:06:43.832957Z DEBUG providers::db: Inserted block block_number=19457020 actions=[(InsertCanonicalHeaders, 1.19µs), (InsertHeaders, 3.98µs), (InsertHeaderNumbers, 43.48µs), (GetParentTD, 1.02µs), (InsertHeaderTerminalDifficulties, 1.74µs), (Get
.......
2024-03-17T21:06:46.708416Z DEBUG connection{remote_addr=127.0.0.1:55282 conn_id=3}: jsonrpsee_server::server: Accepting new connection 2/500
2024-03-17T21:06:47.418809Z DEBUG providers::db: Appended blocks range=19457008..=19457021 actions=[(InsertBlock, 211.386152ms), (InsertBlock, 99.95852ms), (InsertBlock, 77.649537ms), (InsertBlock, 87.683923ms), (InsertBlock, 90.457485ms), (InsertBlock, 54.723482ms), (InsertBlock, 22.742214ms), (InsertBlock, 95.63323ms), (InsertBlock, 81.245534ms), (InsertBlock, 85.474693ms), (InsertBlock, 37.09498ms), (InsertBlock, 43.620701ms), (InsertBlock, 48.822904ms), (InsertBlock, 44.739205ms), (InsertState, 478.394859ms), (InsertHashes, 2.066053561s), (InsertHistoryIndices, 996.530953ms), (UpdatePipelineStages, 121.401µs)]
2024-03-17T21:06:47.901128Z DEBUG storage::db::mdbx: Commit total_duration=482.304478ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 104, audit: 0, write: 0, sync: 31492, ending: 0, whole: 31597, gc_cputime: 0, gc_prof: MDBX_commit_latency__bindgen_ty_1 { wloops: 0, coalescences: 0, wipes: 0, flushes: 0, kicks: 0, work_counter: 0, work_rtime_monotonic: 0, work_xtime_cpu: 0, work_rsteps: 0, work_xpages: 0, work_majflt: 0, self_counter: 0, self_rtime_monotonic: 0, self_xtime_cpu: 0, self_rsteps: 0, self_xpages: 0, self_majflt: 0 } })) is_read_only=false
2024-03-17T21:06:47.901160Z DEBUG blockchain_tree: Canonicalization finished actions=[(CloneOldBlocks, 5.31µs), (FindCanonicalHeader, 3.68µs), (SplitChain, 1.89µs), (SplitChainForks, 1.16µs), (MergeAllChains, 880ns), (UpdateCanonicalIndex, 9.6µs), (RetrieveStateTrieUpdates, 36.050918887s), (CommitCanonicalChainToDatabase, 5.104704582s)]
2024-03-17T21:06:47.901178Z DEBUG consensus::engine: Canonicalized new head hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c number=19457021
2024-03-17T21:06:47.901534Z  INFO reth_node_core::events::node: Canonical chain committed number=19457021 hash=0xb75bbb1724ee3b95da0f3b10810351cf5bf4ca18ed60d3837973962f15383a5c elapsed=41.155672459s
2024-03-17T21:06:47.903989Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0x4f21d13aea40f75f916db2321d62c90644a3347dac23fc2eb6fa13d7096aa4c1
2024-03-17T21:06:47.903998Z DEBUG consensus::engine: Syncing to new target target=0x4f21d13aea40f75f916db2321d62c90644a3347dac23fc2eb6fa13d7096aa4c1
2024-03-17T21:06:47.904019Z  INFO reth_node_core::events::node: Forkchoice updated head_block_hash=0x4f21d13aea40f75f916db2321d62c90644a3347dac23fc2eb6fa13d7096aa4c1 safe_block_hash=0xf8072ecdf6a669657c3900457b439459d5a588ab58b7edbc76c373b74d66dbea finalized_block_hash=0xd04f597fb5e5394f1c72c1df0115b86b84ae610241ee63d2faf7e65b0877f717 status=Syncing
2024-03-17T21:06:47.904429Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0x2db0f4b9b5964b2f373b87f9e07f0edd42d5952c4bab4f4c970e981104ede246
2024-03-17T21:06:47.904435Z DEBUG consensus::engine: Syncing to new target target=0x2db0f4b9b5964b2f373b87f9e07f0edd42d5952c4bab4f4c970e981104ede246
2024-03-17T21:06:47.904454Z  INFO reth_node_core::events::node: Forkchoice updated head_block_hash=0x2db0f4b9b5964b2f373b87f9e07f0edd42d5952c4bab4f4c970e981104ede246 safe_block_hash=0x8e5a2c20d4edeeff3107de9fb0c9c91f659e23a5de94c6e8acf6ea1788fe4ba9 finalized_block_hash=0xf8072ecdf6a669657c3900457b439459d5a588ab58b7edbc76c373b74d66dbea status=Syncing
2024-03-17T21:06:47.904709Z DEBUG blockchain_tree: Block hash not found in block indices block_hash=0x29ca4a11b85d20fad1b5c8cfdd0c557360a6ad30871f2f5bad58db6e20f9f626
2024-03-17T21:06:47.904713Z DEBUG consensus::engine: Syncing to new target target=0x29ca4a11b85d20fad1b5c8cfdd0c557360a6ad30871f2f5bad58db6e20f9f626
2024-03-17T21:06:47.904718Z DEBUG pruner: Minimum pruning interval reached previous_tip_block_number=Some(19457007) tip_block_number=19457021
2024-03-17T21:06:47.904734Z  INFO reth_node_core::events::node: Forkchoice updated head_block_hash=0x29ca4a11b85d20fad1b5c8cfdd0c557360a6ad30871f2f5bad58db6e20f9f626 safe_block_hash=0x21b29083d2ab94ee599ddaa156f96d921de456cd693e08946d590bd8f238e02f finalized_block_hash=0x8e5a2c20d4edeeff3107de9fb0c9c91f659e23a5de94c6e8acf6ea1788fe4ba9 status=Syncing
2024-03-17T21:06:47.904771Z DEBUG consensus::engine::hooks: Polled next hook hook="Prune" result=PolledHook { name: "Prune", event: Started, db_access_level: ReadWrite }
2024-03-17T21:06:47.904808Z DEBUG consensus::engine::hooks: Polled next hook hook="StaticFile" result=PolledHook { name: "StaticFile", event: Started, db_access_level: ReadOnly }
2024-03-17T21:06:47.904811Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-03-17T21:06:47.904813Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-03-17T21:06:47.904963Z  INFO reth_node_core::events::node: Pruner started tip_block_number=19457021
2024-03-17T21:06:47.904944Z DEBUG pruner: Pruner started tip_block_number=19457021
2024-03-17T21:06:47.904989Z  INFO reth_node_core::events::node: Static File Producer started targets=StaticFileTargets { headers: Some(19456929..=19456959), receipts: None, transactions: Some(19456929..=19456959) }
2024-03-17T21:06:47.904974Z DEBUG static_file: StaticFileProducer started targets=StaticFileTargets { headers: Some(19456929..=19456959), receipts: None, transactions: Some(19456929..=19456959) }
2024-03-17T21:06:47.905001Z DEBUG pruner: Segment pruning started segment=Transactions purpose=StaticFile to_block=19456928 prune_mode=Before(19456929)
2024-03-17T21:06:47.905021Z DEBUG static_file: StaticFileProducer segment segment=Transactions block_range=19456929..=19456959
2024-03-17T21:06:47.905029Z DEBUG static_file: StaticFileProducer segment segment=Headers block_range=19456929..=19456959
2024-03-17T21:06:47.905040Z DEBUG pruner: Segment pruning finished segment=Transactions purpose=StaticFile to_block=19456928 prune_mode=Before(19456929) output.pruned=0
2024-03-17T21:06:47.905047Z DEBUG pruner: Segment pruning started segment=Headers purpose=StaticFile to_block=19456928 prune_mode=Before(19456929)
2024-03-17T21:06:47.905050Z DEBUG pruner: Segment pruning finished segment=Headers purpose=StaticFile to_block=19456928 prune_mode=Before(19456929) output.pruned=0
2024-03-17T21:06:47.905051Z DEBUG pruner: Segment pruning started segment=Receipts purpose=User to_block=11052983 prune_mode=Before(11052984)
2024-03-17T21:06:47.905467Z DEBUG pruner: Segment pruning finished segment=Receipts purpose=User to_block=11052983 prune_mode=Before(11052984) output.pruned=0
2024-03-17T21:06:47.905470Z DEBUG pruner: Nothing to prune for the segment segment=ContractLogs purpose=User
2024-03-17T21:06:47.905473Z DEBUG pruner: Segment pruning started segment=SenderRecovery purpose=User to_block=19457021 prune_mode=Full
2024-03-17T21:06:47.906165Z DEBUG txpool: cleaning up blob store finalized_block=19456959
2024-03-17T21:06:47.906188Z DEBUG txpool::blob: Removing blobs from disk num_blobs=0
2024-03-17T21:06:47.909577Z DEBUG static_file: Finished StaticFileProducer segment segment=Headers block_range=19456929..=19456959 elapsed=4.534321ms
2024-03-17T21:06:47.920172Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-03-17T21:06:47.927819Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-03-17T21:06:47.943727Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-03-17T21:06:47.945677Z DEBUG pruner: Segment pruning finished segment=SenderRecovery purpose=User to_block=19457021 prune_mode=Full output.pruned=49000
2024-03-17T21:06:47.947393Z DEBUG storage::db::mdbx: Commit total_duration=1.704038ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 4, audit: 0, write: 0, sync: 106, ending: 0, whole: 110, gc_cputime: 0, gc_prof: MDBX_commit_latency__bindgen_ty_1 { wloops: 0, coalescences: 0, wipes: 0, flushes: 0, kicks: 0, work_counter: 0, work_rtime_monotonic: 0, work_xtime_cpu: 0, work_rsteps: 0, work_xpages: 0, work_majflt: 0, self_counter: 0, self_rtime_monotonic: 0, self_xtime_cpu: 0, self_rsteps: 0, self_xpages: 0, self_majflt: 0 } })) is_read_only=false
2024-03-17T21:06:47.947416Z DEBUG pruner: Pruner finished tip_block_number=19457021 elapsed=42.435575ms delete_limit=0 progress=HasMoreData stats={SenderRecovery: (HasMoreData, 49000)}
2024-03-17T21:06:47.947435Z DEBUG consensus::engine::hooks: Polled running hook with db write access hook="Prune" result=PolledHook { name: "Prune", event: Finished(Ok(())), db_access_level: ReadWrite }
2024-03-17T21:06:47.947449Z  INFO reth_node_core::events::node: Pruner finished tip_block_number=19457021 elapsed=42.435575ms stats={SenderRecovery: (HasMoreData, 49000)}
2024-03-17T21:06:47.947607Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-03-17T21:06:47.958315Z DEBUG consensus::engine::hooks: Next hook is not ready hook="Prune"
2024-03-17T21:06:47.972776Z DEBUG static_file: Finished StaticFileProducer segment segment=Transactions block_range=19456929..=19456959 elapsed=67.734432ms
2024-03-17T21:06:47.976076Z DEBUG provider::static_file: Commit segment=Transactions path="/fastStorage/data/reth.v2/static_files/static_file_transactions_19000000_19499999" duration=3.280205ms
2024-03-17T21:06:47.976780Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-03-17T21:06:47.976825Z DEBUG static_file: StaticFileProducer started targets=StaticFileTargets { headers: Some(19456929..=19457021), receipts: None, transactions: Some(19456960..=19457021) }
2024-03-17T21:06:47.976838Z DEBUG static_file: StaticFileProducer segment segment=Transactions block_range=19456960..=19457021
2024-03-17T21:06:47.976845Z  INFO reth_node_core::events::node: Static File Producer started targets=StaticFileTargets { headers: Some(19456929..=19457021), receipts: None, transactions: Some(19456960..=19457021) }
2024-03-17T21:06:47.976844Z DEBUG static_file: StaticFileProducer segment segment=Headers block_range=19456929..=19457021
2024-03-17T21:06:47.978665Z DEBUG provider::static_file: Commit segment=Headers path="/fastStorage/data/reth.v2/static_files/static_file_headers_19000000_19499999" duration=2.432841ms
2024-03-17T21:06:47.978858Z DEBUG static_file: StaticFileProducer finished targets=StaticFileTargets { headers: Some(19456929..=19456959), receipts: None, transactions: Some(19456929..=19456959) } elapsed=73.85678ms
2024-03-17T21:06:47.978873Z  INFO reth_node_core::events::node: Static File Producer finished targets=StaticFileTargets { headers: Some(19456929..=19456959), receipts: None, transactions: Some(19456929..=19456959) } elapsed=73.85678ms
2024-03-17T21:06:47.979782Z DEBUG static_file: Finished StaticFileProducer segment segment=Headers block_range=19456929..=19457021 elapsed=2.920163ms
2024-03-17T21:06:48.104227Z DEBUG static_file: Finished StaticFileProducer segment segment=Transactions block_range=19456960..=19457021 elapsed=127.382816ms
2024-03-17T21:06:48.108305Z DEBUG provider::static_file: Commit segment=Transactions path="/fastStorage/data/reth.v2/static_files/static_file_transactions_19000000_19499999" duration=4.050098ms
2024-03-17T21:06:48.110965Z DEBUG provider::static_file: Commit segment=Headers path="/fastStorage/data/reth.v2/static_files/static_file_headers_19000000_19499999" duration=2.530991ms
2024-03-17T21:06:48.111123Z DEBUG static_file: StaticFileProducer finished targets=StaticFileTargets { headers: Some(19456929..=19457021), receipts: None, transactions: Some(19456960..=19457021) } elapsed=134.291837ms
2024-03-17T21:06:48.111168Z DEBUG sync::stages::headers: Commencing sync tip=Hash(0x8e5a2c20d4edeeff3107de9fb0c9c91f659e23a5de94c6e8acf6ea1788fe4ba9) head=0xd04f597fb5e5394f1c72c1df0115b86b84ae610241ee63d2faf7e65b0877f717
2024-03-17T21:06:48.111177Z  INFO reth_node_core::events::node: Static File Producer finished targets=StaticFileTargets { headers: Some(19456929..=19457021), receipts: None, transactions: Some(19456960..=19457021) } elapsed=134.291837ms
2024-03-17T21:06:48.160174Z DEBUG sync::stages::headers: Commencing sync tip=Hash(0x8e5a2c20d4edeeff3107de9fb0c9c91f659e23a5de94c6e8acf6ea1788fe4ba9) head=0xd04f597fb5e5394f1c72c1df0115b86b84ae610241ee63d2faf7e65b0877f717
2024-03-17T21:06:48.160205Z  INFO sync::stages::headers: Received headers total=64 from_block=19457054 to_block=19456991
2024-03-17T21:06:48.160314Z  INFO sync::stages::headers: Writing headers total=64
2024-03-17T21:06:48.160323Z  INFO reth_node_core::events::node: Executing stage pipeline_stages=1/12 stage=Headers checkpoint=19457021 target=None
2024-03-17T21:06:48.160582Z  INFO sync::stages::headers: Writing headers progress=9.38%
2024-03-17T21:06:48.160599Z  INFO sync::stages::headers: Writing headers progress=18.75%
2024-03-17T21:06:48.160626Z  INFO sync::stages::headers: Writing headers progress=28.12%
2024-03-17T21:06:48.160640Z  INFO sync::stages::headers: Writing headers progress=37.50%
2024-03-17T21:06:48.160657Z  INFO sync::stages::headers: Writing headers progress=46.88%
2024-03-17T21:06:48.160671Z  INFO sync::stages::headers: Writing headers progress=56.25%
2024-03-17T21:06:48.160690Z  INFO sync::stages::headers: Writing headers progress=65.62%
2024-03-17T21:06:48.160704Z  INFO sync::stages::headers: Writing headers progress=75.00%
2024-03-17T21:06:48.160725Z  INFO sync::stages::headers: Writing headers progress=84.38%
2024-03-17T21:06:48.160739Z  INFO sync::stages::headers: Writing headers progress=93.75%
2024-03-17T21:06:48.160751Z  INFO sync::stages::headers: Writing header hash index total=64
2024-03-17T21:06:48.162115Z ERROR sync::pipeline: Stage encountered a fatal error: internal database error occurred: write operation CursorInsert failed for key "11fa02ba2c8a25eefadbf303304aa2c8c2b740bbb363189fd4f324a277be6eb4" in table "HeaderNumbers": key/data pair already exists (-30799) stage=Headers
2024-03-17T21:06:48.162268Z ERROR reth::cli: shutting down due to error

Platform(s)

Linux (x86)

What version/commit are you on?

reth Version: 0.2.0-beta.2 Commit SHA: 10aeeb02f Build Timestamp: 2024-03-13T07:19:50.526437588Z Build Features: jemalloc Build Profile: release

What database version are you on?

Current database version: 2 Local database version: 2

What type of node are you running?

Full via --full flag

What prune config do you use, if any?

No response

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

RUSTFLAGS="-C target-cpu=native" cargo build --profile maxperf --features jemalloc,asm-keccak

Code of Conduct

shekhirin commented 7 months ago

This is a known issue caused by writing to static files twice. We fixed it in beta.3 that was just released. Please try the following steps to recover your node:

  1. Update to beta.3
  2. Drop Headers and Bodies stages via reth stage drop headers and reth stage drop bodies
  3. Restart Reth. It should start syncing headers and bodies again, recovering the state of static files back to normal.