winksaville
commented
3 months ago Here is an link to the logs: https://drive.google.com/file/d/1uEwgV3V6dqqnUT7dxu9lfHT88773Uhe3/view?usp=sharing
Open winksaville opened 3 months ago
winksaville
commented
3 months ago Here is an link to the logs: https://drive.google.com/file/d/1uEwgV3V6dqqnUT7dxu9lfHT88773Uhe3/view?usp=sharing
mattsse
commented
3 months ago tysm for all the logs @winksaville !
I think the error originated here
2024-03-26T17:10:51.389084Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0xd6bf93f17c15eef43e4fe34c675ce89d8c7d88ee2b5a341336ec587bfe066bbf, number=1221400, parent_hash=0xb211ed799d6b6fc2acfa9b71da8339127ec7fa397e3921868e0d906fcdbc4773): mismatched block state root: got 0xcdf1b990b63256e10ebd8e53f5e278047ae1b7f81c83f9b371a59e81d002ceb9, expected 0x871f69bf1cc2e24823e4a25f52e6e6af3134d97264bb16d617b4b69fc1114bf1
reth computed the state root incorrectly, preventing progress and on restarts we encountered similar problems @shekhirin @rkrasiuk
winksaville
commented
3 months ago tysm for all the logs @winksaville !
I think the error originated here
2024-03-26T17:10:51.389084Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0xd6bf93f17c15eef43e4fe34c675ce89d8c7d88ee2b5a341336ec587bfe066bbf, number=1221400, parent_hash=0xb211ed799d6b6fc2acfa9b71da8339127ec7fa397e3921868e0d906fcdbc4773): mismatched block state root: got 0xcdf1b990b63256e10ebd8e53f5e278047ae1b7f81c83f9b371a59e81d002ceb9, expected 0x871f69bf1cc2e24823e4a25f52e6e6af3134d97264bb16d617b4b69fc1114bf1
reth computed the state root incorrectly, preventing progress and on restarts we encountered similar problems @shekhirin @rkrasiuk
I see that was the first Failed to insert block but in total there were 266:
kendall@ethel 24-04-02T21:30:28.800Z:~/reth-lighthouse-issues/reth-issue-7430/reth
$ rg 'Failed to insert block' reth.log | wc -l
266
kendall@ethel 24-04-02T21:30:31.941Z:~/reth-lighthouse-issues/reth-issue-7430/rethBut actually it looks like there were only two were different, here is where it switched from the first to the second:
139866:2024-03-26T17:26:36.377010Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0xd6bf93f17c15eef43e4fe34c675ce89d8c7d88ee2b5a341336ec587bfe066bbf, number=1221400, parent_hash=0xb211ed799d6b6fc2acfa9b71da8339127ec7fa397e3921868e0d906fcdbc4773): mismatched block state root: got 0xcdf1b990b63256e10ebd8e53f5e278047ae1b7f81c83f9b371a59e81d002ceb9, expected 0x871f69bf1cc2e24823e4a25f52e6e6af3134d97264bb16d617b4b69fc1114bf1
765042:2024-04-02T05:16:50.721056Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0x168c92f7f36f0d968ee9f0353268af64c0e987e098f0b29d9d99483f1f6e4af2, number=1264353, parent_hash=0x4fe60b1e2aaccc7e25006671727879e2a2535fa087231efaa0424821bf9fa57e): mismatched block state root: got 0xa34bd0e7cebbf20708fbae4423721a00106e19e2fd075818f05d0582df314694, expected 0x4ed32b88c105a497378e0773cf741fcac17ab4474b074f515e0ad7f99dbb4af8What does it mean that the first one stopped being reported, did it get fixed?
Then about 12hrs later a different block was not inserted, was this a second unrelated error?
winksaville
commented
3 months ago After running the appropriate reth stage drop merkle and restarting EL and CL's my holesky node is back attesting:
Apr 02 14:48:45 ethel lighthouse[4919]: Apr 02 21:48:45.471 INFO Previous epoch attestation(s) success validators: ["1624364", "1624363"], epoch: 42165, service: val_mon, service: beacon
Apr 02 14:55:09 ethel lighthouse[4919]: Apr 02 21:55:09.434 INFO Previous epoch attestation(s) success validators: ["1624364", "1624363"], epoch: 42166, service: val_mon, service: beacon
Apr 02 15:01:33 ethel lighthouse[4919]: Apr 02 22:01:33.471 INFO Previous epoch attestation(s) success validators: ["1624364", "1624363"], epoch: 42167, service: val_mon, service: beaconThanks!
winksaville
commented
3 months ago Seeing the weirdness above I looked a little deeper at the output of rg 'Failed to insert block' reth.log. The first "Failed to insert block" error, at 2024-03-26T17:10:51.389084Z, repeats over and over:
2024-03-26T17:26:36.377010Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0xd6bf93f…fe066bbf, number=1221400, parent_hash=0xb211ed7…fcdbc4773): mismatched block state root: got 0xcdf1b990…002ceb9, expected 0x871f69bf…c1114bf1Until a second occurrence at 2024-04-02T05:16:50.721056Z, which has different parameters from the error above. This second error is the real culprit of the restarting loop I reported:
2024-04-02T05:16:50.721056Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0x168c92f7…1f6e4af2, number=1264353, parent_hash=0x4fe60b…f9fa57e): mismatched block state root: got 0xa34bd0e7…f314694, expected 0x4ed32b8…f99dbb4af8The reason there are two errors is because I "fixed" the first one when I stopped reth at 2024-03-27T21:47:55.872852Z and the next day I reth drop db at 2024-03-28T16:45:43.311988Z and restarted reth a few minutes later:
2024-03-27T21:47:55.872852Z ERROR reth::cli: shutting down due to error
2024-03-28T16:45:43.311988Z INFO reth::cli: Dropping database at "/home/kendall/eth2-data/reth/holesky/db"
2024-03-28T16:45:43.312704Z INFO reth::cli: Dropping static files at "/home/kendall/eth2-data/reth/holesky/static_files"
2024-03-28T16:51:42.502064Z INFO reth::cli: Starting reth version="0.2.0-beta.4 (c04dbe6e9)"
2024-03-28T16:51:42.503363Z INFO reth::cli: Opening database path="/home/kendall/eth2-data/reth/holesky/db"
2024-03-28T16:51:42.552262Z INFO reth::cli: Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
2024-03-28T16:51:42.555474Z INFO reth::cli: Database openedAlso, looking at the beacon.journalctl-since-1d.log the beacon chain was Synced up until Apr 02 05:23:06.000 INFO Synced and then at Apr 02 05:23:16.235 INFO Sync state updated it declared new_state: Syncing Head Chain and the old_state: Synced. Unsurprisingly 05:23:16 - 05:16:50 is 6.4 minutes i.e. one Ethereum epoch time later:
Apr 01 22:23:06 ethel lighthouse[1511]: Apr 02 05:23:06.000 INFO Synced slot: 1344415, block: … empty, epoch: 42012, finalized_epoch: 42010, finalized_root: 0x998a…0093, exec_hash: 0x4fe6…a57e (verified), peers: 95, service: slot_notifier
Apr 01 22:23:12 ethel lighthouse[1511]: Apr 02 05:23:12.329 INFO Previous epoch attestation(s) success validators: ["1624364", "1624363"], epoch: 42009, service: val_mon, service: beacon
Apr 01 22:23:12 ethel lighthouse[1511]: Apr 02 05:23:12.601 WARN Invalid execution payload method: new_payload, slot: 1344384, proposer_index: 847546, graffiti: Nethermind, root: 0xf6122f9ac…b65b7b, execution_block_hash: 0x168c92f7…af2, latest_valid_hash: Some(0x4fe60b1e2a…1bf9fa57e), validation_error: Some("mismatched block state root: got 0xa34bd0…2df314694, expected 0x4ed32b8…0ad7f99dbb4af8"), service: beacon
Apr 01 22:23:16 ethel lighthouse[1511]: Apr 02 05:23:16.235 INFO Sync state updated new_state: Syncing Head Chain, old_state: Synced, service: syncSo my holesky node has experienced two "Failed to insert block" and on the second one we have reth, beacon and validator logs. Hopefully this can be useful to in getting closer to the root cause, at a minimum provide direction for adding more logging!
pistomat
commented
3 months ago This keeps happening on beta.5
Apr 08 16:12:57 nuc13 reth[1130934]: 2024-04-08T14:12:57.209728Z WARN Unwinding{stage=MerkleUnwind}: Failed to verify block state root target_block=1296822 got=0xf2d566b1b1759347d8be17c9b20d2f6fba2327dcefabe9b7d900a07c9cba74e0 expected=SealedHeader { hash: 0xc790a1a8911e13ee8a34f25e10daddd017e5192feafe8f9e77b32f806dc01372, header: Header { parent_hash: 0xfd9c77a331e8a5780e5a5f0737e5a258a54d6d37c49a834e7bde859a8467f3ab, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x65fdc9a172746d54a5b05e6ac5130b991abaf079, state_root: 0xf9e860d111dfc70fb2e94ad5238a1dcd81646400bde958dda3b24558fab2902d, transactions_root: 0xaead67959b06e043a23a362f274e60299f486d0b62632069ecca9e4e22ad1bb7, receipts_root: 0xc56a6e63bf09b63776396acebc33a8d301e067923b15697671488619c31c4f1c, withdrawals_root: Some(0x9e69f6583be5b241893bb9eb10ca9f1f130832887b04b4e161cdb61ae42dadb0), logs_bloom: 0x140cbf990854420009c4f14a24c12974c1214e803c6244988400502088805a0d0aca1dc0143e18f5104d0e8018410e3884670c550b725840004f058d1aef2ac04253c0007a80c06484d10c1b4b8081a02b2905286ec4c4031185420b84e2d0250a244004020424558bf002a8822a094100824c348810c6092a8e13bc0cac0906c90b3000392a1644410198252003b341871426388708a0964c8698831d0456880380df99201f3b042080323405082904b80200009030044158f1a30d4288548031588823ce533180095a4005a00d07591a89a107d087206009ab1892d02ae900a0960316ca80d61100000700b04a4000ca5a02034b813500913020c00a906446, difficulty: 0x0_U256, number: 1296822, gas_limit: 30000000, gas_used: 19040642, timestamp: 1712458980, mix_hash: 0xf6e131e8ca4db36b7770b497af97ef9b947c2fe41e25a9eeaf1e6bc505cb33c6, nonce: 0, base_fee_per_gas: Some(215), blob_gas_used: Some(786432), excess_blob_gas: Some(79298560), parent_beacon_block_root: Some(0x41e1c400b6dd2e275f2aee50a28e38695355c279dd14007be86751d5ee9fc8e3), extra_data: 0xd883010d0b846765746888676f312e32312e36856c696e7578 } }
Apr 08 16:12:57 nuc13 reth[1130934]: 2024-04-08T14:12:57.434938Z ERROR shutting down due to error
Apr 08 16:12:57 nuc13 reth[1130934]: Error: stage encountered an error in block #1296822: validation error: mismatched block state root: got 0xf2d566b1b1759347d8be17c9b20d2f6fba2327dcefabe9b7d900a07c9cba74e0, expected 0xf9e860d111dfc70fb2e94ad5238a1dcd81646400bde958dda3b24558fab2902d
Apr 08 16:12:57 nuc13 reth[1130934]: Caused by:
Apr 08 16:12:57 nuc13 reth[1130934]: 0: validation error: mismatched block state root: got 0xf2d566b1b1759347d8be17c9b20d2f6fba2327dcefabe9b7d900a07c9cba74e0, expected 0xf9e860d111dfc70fb2e94ad5238a1dcd81646400bde958dda3b24558fab2902d
Apr 08 16:12:57 nuc13 reth[1130934]: 1: mismatched block state root: got 0xf2d566b1b1759347d8be17c9b20d2f6fba2327dcefabe9b7d900a07c9cba74e0, expected 0xf9e860d111dfc70fb2e94ad5238a1dcd81646400bde958dda3b24558fab2902d
Apr 08 16:12:57 nuc13 reth[1130934]: Location:
Apr 08 16:12:57 nuc13 reth[1130934]: /rustc/7cf61ebde7b22796c69757901dd346d0fe70bd97/library/core/src/task/poll.rs:255:39 $ reth db version
Current database version: 2
Local database is uninitialized
$ reth --version
reth Version: 0.2.0-beta.5
Commit SHA: 54f75cd
Build Timestamp: 2024-04-03T16:25:49.060856881Z
Build Features: jemalloc
Build Profile: maxperfDropping the stage works as a charm, my validator is back up: reth stage drop merkle
Let me know if I should open a new issue.
winksaville
commented
3 months ago I had another "Failed to insert block" resulting in reboot cycle, the latest logs are here. In those logs are files I created with rg 'Failed to insert|Failed to verify|Starting reth' reth.log.1 > reth.log.1.failed-insert.failed-verify-Starting-reth. In that file the first occurrence of this latest failure was at 2024-04-08T10:14:16.306330Z and continued until a "Failed to verify block" at 2024-04-08T14:36:44.531539Z followed by an "Unwindiing" at 2024-04-08T14:36:45.612071Z and rebooting at 2024-04-08T14:36:51.181336Z this rebooting continues until I stop reth, beacon and validators:
2024-04-08T10:14:16.306330Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0x75d33ca50ce5995c5829e318419a0457440a866982c717269d8ab59aa58d9378, number=1305364, parent_hash=0x5c44156fbe0b623395752c0881c6a52ebb7fd33f97307b6964da70fa0be94c65): mismatched block state root: got 0x1f4fa2a54d8d8d028b23247c85a769dbcc0c9b81fc61f5b1fc7a7ab07241d524, expected 0x617aa48146e8cec830faf41f4b8b36f1104e4c496c304ef5b37829bde06ac9df
...
2024-04-08T10:30:26.501308Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0x75d33ca50ce5995c5829e318419a0457440a866982c717269d8ab59aa58d9378, number=1305364, parent_hash=0x5c44156fbe0b623395752c0881c6a52ebb7fd33f97307b6964da70fa0be94c65): mismatched block state root: got 0x1f4fa2a54d8d8d028b23247c85a769dbcc0c9b81fc61f5b1fc7a7ab07241d524, expected 0x617aa48146e8cec830faf41f4b8b36f1104e4c496c304ef5b37829bde06ac9df
2024-04-08T14:36:44.531539Z WARN sync::stages::merkle: Failed to verify block state root target_block=1305405 got=0x242a10a082135c30a0770efc198044112cece4af507fd8921260b31aed21216f expected=SealedHeader { hash: 0xf10c5efb5f9d7d47755a0329b2c86e7359af20252deb226fc6775bebea02469d, header: Header { parent_hash: 0xb1363e28fed60bb3a11a0c9789a1d263012002f99849530c3f45dcfb9d7e9028, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0xc6e2459991bfe27cca6d86722f35da23a1e4cb97, state_root: 0x1dfb052ec0aa4bb0896d52a5606e604a6798dcbd3991ca0939d622e08a4e27db, transactions_root: 0xc0955e38f8357fcce03d2b3351b632d571b95821f93dbd6cc74141a623b9b1fe, receipts_root: 0xd2542a83a6e3f8aad75299701ab4b49e5568648d314a8f919be1976cf316ab12, withdrawals_root: Some(0x21cfff1cf5c78d9d0b932f16162c3c11b44132ac223e46ac8b95ad53f293742a), logs_bloom: 0x34000010000002200100000000001004000040004000008000000000000000020010010000000000000400000000010000000010000000000000000000640000000280000080c004080008880000000008000000000400010002040008080020110060001200000100800080000008000400000040000000800000100500000000000002000000000000000000000010001000000008109000040001004000000200000000004000000200004400000000000008000000100000000000000000b01000020010900a08400080080402000801000000c0004000080000000060000010000000000404004204000000000100000109020000040000084000000000, difficulty: 0x0_U256, number: 1305405, gas_limit: 30000000, gas_used: 2097742, timestamp: 1712571840, mix_hash: 0x83e28916a9383bb856400b934dde5450f04366930e6189081ac0c39607128c0d, nonce: 0, base_fee_per_gas: Some(8), blob_gas_used: Some(786432), excess_blob_gas: Some(42991616), parent_beacon_block_root: Some(0x32f971bdedbbfd1974c3451c44436c3dfffbc8411abc1390beef06fe62bddb4d), extra_data: 0xd883010d0e846765746888676f312e32312e36856c696e7578 } }
2024-04-08T14:36:45.612071Z WARN Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::stages::merkle: Failed to verify block state root target_block=1305363 got=0x85bf1516e35a3cf6026b39b0480640adbfcfe3ea0df3f357fbbf94768d7a0ce4 expected=SealedHeader { hash: 0x5c44156fbe0b623395752c0881c6a52ebb7fd33f97307b6964da70fa0be94c65, header: Header { parent_hash: 0x8204f073080b1e1d09140a1aaf4faaf925c7294251bd8842b1fe601d230cbc84, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0xc473d412dc52e349862209924c8981b2ee420768, state_root: 0x35bbf434a0a3aeda9ca3bb315e67b2b9f6fba16f1c040bdffb6a32af00d18437, transactions_root: 0x04ed6a4ee080689a26e827ccb40c0d8f48e6fb01c28a966d5490a8f5d0b24b84, receipts_root: 0xcbe95b5aa94512e05a494f9d1fa8ee02a02a6329add2720079c8f3e6d312a259, withdrawals_root: Some(0xe6ac311ba3c1c62b8d16c7497db0523852e43078990be3f7d7c81cb8f4217ac5), logs_bloom: 0x00000090000000002100800000050004010000004420018042000004011040000308018000020200000000810000000000808810080000020042040008700100001690000020d0000090088900000001000000006080000140840011200001210002000002000000000000800400090080000c2000404008040000100000004008088000100200002800000000010004009000000000009000860000140004010308820020000000a08000100000800020000000040008080800800000814080100400028010180000400004800402404c01020000a0204000000100008071040430000a800004402000040200000000005200010200a0c00000000000001000, difficulty: 0x0_U256, number: 1305363, gas_limit: 30000000, gas_used: 2002842, timestamp: 1712571240, mix_hash: 0x9022e457218d6d867160c20dffa486aa7a9bf3880417ffdbe3f48f2f9bfa9de0, nonce: 0, base_fee_per_gas: Some(15), blob_gas_used: Some(786432), excess_blob_gas: Some(32505856), parent_beacon_block_root: Some(0x37518849b748b2c62681a386e74f4bea96d0ddbe3373d531bedbbf877c605264), extra_data: 0x4e65746865726d696e64 } }
2024-04-08T14:36:51.181336Z INFO reth::cli: Starting reth version="0.2.0-beta.5 (54f75cdcc)"Hopefully these logs help narrow down the problem.
winksaville
commented
3 months ago @DaniPopes the current title is related to the symptom I saw, rebooting. Should the title of this be changed to reflect it's related to failing to insert a block into a Merkle-Patricia trie?
DaniPopes
commented
3 months ago It does look like that, cc @mattsse
winksaville
commented
3 months ago Note: After a little less that and hour my node was successfully attesting after I reth stage drop merkle and restarting the node.
winksaville
commented
3 months ago I'm impatient and decided I try something, I came up with adding a panic! to the code where the "Failed to insert block" gets printed and set RUST_BACKTRACE=1 environment variable:
impl std::fmt::Display for InsertBlockErrorData {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
//write!(
// f,
// "Failed to insert block (hash={}, number={}, parent_hash={}): {}",
// self.block.hash(),
// self.block.number,
// self.block.parent_hash,
// self.kind
//)
panic!("Wink: Failed to insert block, {self:?}")
}
}That way we might know which routine caused the error, maybe you already know and this is dumb, but it's something I can try :)
pistomat
commented
3 months ago This happened to me again today, dropping the stage again helped.
Do you want me to post any more info?
Rjected
commented
3 months ago This happened to me again today, dropping the stage again helped.
Do you want me to post any more info?
Hi! Do you mind sending the output of reth db stats when you run into this?
Rjected
commented
3 months ago I'm impatient and decided I try something, I came up with adding a
panic!to the code where the "Failed to insert block" gets printed and setRUST_BACKTRACE=1environment variable:impl std::fmt::Display for InsertBlockErrorData { fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { //write!( // f, // "Failed to insert block (hash={}, number={}, parent_hash={}): {}", // self.block.hash(), // self.block.number, // self.block.parent_hash, // self.kind //) panic!("Wink: Failed to insert block, {self:?}") } }That way we might know which routine caused the error, maybe you already know and this is dumb, but it's something I can try :)
Same thing w.r.t. reth db stats, @winksaville if you run into an invalid block error or merkle root mismatch, could you give us the full output of reth db stats and some more logs before running reth stage drop merkle?
winksaville
commented
2 months ago Pisomat, I don't see content of this email on GitHub in issue 7430. But actually I think it would be better in your issue, 7619 and I don't see it there either.
On Sat, Apr 13, 2024, 01:24 pistomat @.***> wrote:
So it happened again, posting all the logs I get before crash
Apr 13 10:20:08 nuc13 systemd[1]: reth.service: Failed with result 'exit-code'. Apr 13 10:20:08 nuc13 systemd[1]: reth.service: Consumed 3.017s CPU time. Apr 13 10:20:12 nuc13 systemd[1]: reth.service: Scheduled restart job, restart counter is at 68. Apr 13 10:20:12 nuc13 systemd[1]: Stopped Reth Execution Layer Client service. Apr 13 10:20:12 nuc13 systemd[1]: reth.service: Consumed 3.017s CPU time. Apr 13 10:20:12 nuc13 systemd[1]: Started Reth Execution Layer Client service. Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.046588Z INFO Starting reth version="0.2.0-beta.5 (54f75cd)" Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.047198Z INFO Opening database path="/var/lib/reth/db" Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.052176Z INFO Configuration loaded path="/var/lib/reth/reth.toml" Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.053362Z INFO Database opened Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.053375Z INFO Starting metrics endpoint addr=127.0.0.1:9001 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.053499Z INFO Apr 13 10:20:12 nuc13 reth[424081]: Pre-merge hard forks (block based): Apr 13 10:20:12 nuc13 reth[424081]: - Frontier @0 Apr 13 10:20:12 nuc13 reth[424081]: - Homestead @0 Apr 13 10:20:12 nuc13 reth[424081]: - Dao @0 Apr 13 10:20:12 nuc13 reth[424081]: - Tangerine @0 Apr 13 10:20:12 nuc13 reth[424081]: - SpuriousDragon @0 Apr 13 10:20:12 nuc13 reth[424081]: - Byzantium @0 Apr 13 10:20:12 nuc13 reth[424081]: - Constantinople @0 Apr 13 10:20:12 nuc13 reth[424081]: - Petersburg @0 Apr 13 10:20:12 nuc13 reth[424081]: - Istanbul @0 Apr 13 10:20:12 nuc13 reth[424081]: - MuirGlacier @0 Apr 13 10:20:12 nuc13 reth[424081]: - Berlin @0 Apr 13 10:20:12 nuc13 reth[424081]: - London @0 Apr 13 10:20:12 nuc13 reth[424081]: Merge hard forks: Apr 13 10:20:12 nuc13 reth[424081]: - Paris @0 (network is known to be merged) Apr 13 10:20:12 nuc13 reth[424081]: Post-merge hard forks (timestamp based): Apr 13 10:20:12 nuc13 reth[424081]: - Shanghai @1696000704 Apr 13 10:20:12 nuc13 reth[424081]: - Cancun @1707305664 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.113651Z INFO Transaction pool initialized Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.113704Z INFO Connecting to P2P network Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.113781Z INFO Loading saved peers file=/var/lib/reth/known-peers.json Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.114732Z INFO StaticFileProducer initialized Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.114827Z INFO Pruner initialized prune_config=PruneConfig { block_interval: 5, segments: PruneModes { sender_recovery: Some(Full), transaction_lookup: None, receipts: Some(Before(0)), account_history: Some(Distance(10064)), storage_history: Some(Distance(10064)), receipts_log_filter: ReceiptsLogPruneConfig({0x4242424242424242424242424242424242424242: Before(0)}) } } Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.114891Z INFO Consensus engine initialized Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.114913Z INFO Engine API handler initialized Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116410Z INFO RPC auth server started url=127.0.0.1:8551 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116487Z INFO RPC IPC server started url=/tmp/reth.ipc Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116491Z INFO RPC HTTP server started url=127.0.0.1:8545 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116494Z INFO RPC WS server started url=127.0.0.1:8546 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116502Z INFO Starting consensus engine Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116877Z INFO Preparing stage pipeline_stages=1/12 stage=Headers checkpoint=1337139 target=None Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116877Z INFO Target block already reached checkpoint=1337139 target=Hash(0x9bf31af3ca41a421cf05a682936a23c50c86865c1451ef8f5a87074a50849ee2) Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116903Z INFO Executing stage pipeline_stages=1/12 stage=Headers checkpoint=1337139 target=None Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116964Z INFO Finished stage pipeline_stages=1/12 stage=Headers checkpoint=1337139 target=None stage_progress=100.00% Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116991Z INFO Preparing stage pipeline_stages=2/12 stage=Bodies checkpoint=1337139 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.116999Z INFO Executing stage pipeline_stages=2/12 stage=Bodies checkpoint=1337139 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117005Z INFO Finished stage pipeline_stages=2/12 stage=Bodies checkpoint=1337139 target=1337139 stage_progress=100.00% Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117011Z INFO Preparing stage pipeline_stages=3/12 stage=SenderRecovery checkpoint=1337139 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117017Z INFO Executing stage pipeline_stages=3/12 stage=SenderRecovery checkpoint=1337139 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117023Z INFO Finished stage pipeline_stages=3/12 stage=SenderRecovery checkpoint=1337139 target=1337139 stage_progress=99.99% Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117029Z INFO Preparing stage pipeline_stages=4/12 stage=Execution checkpoint=1337139 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117034Z INFO Executing stage pipeline_stages=4/12 stage=Execution checkpoint=1337139 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117040Z INFO Finished stage pipeline_stages=4/12 stage=Execution checkpoint=1337139 target=1337139 stage_progress=100.00% Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117045Z INFO Stage is always skipped Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117046Z INFO Preparing stage pipeline_stages=5/12 stage=MerkleUnwind checkpoint=1337139 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117052Z INFO Executing stage pipeline_stages=5/12 stage=MerkleUnwind checkpoint=1337139 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117058Z INFO Finished stage pipeline_stages=5/12 stage=MerkleUnwind checkpoint=1337139 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117063Z INFO Preparing stage pipeline_stages=6/12 stage=AccountHashing checkpoint=1336931 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.117069Z INFO Executing stage pipeline_stages=6/12 stage=AccountHashing checkpoint=1336931 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.186597Z INFO Finished stage pipeline_stages=6/12 stage=AccountHashing checkpoint=1337139 target=1337139 stage_progress=100.00% Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.208333Z INFO Preparing stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1336931 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.208361Z INFO Executing stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1336931 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.367460Z INFO Finished stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1337139 target=1337139 stage_progress=100.00% Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.412500Z INFO Preparing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1336931 target=1337139 Apr 13 10:20:12 nuc13 reth[424081]: 2024-04-13T08:20:12.412527Z INFO Executing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1336931 target=1337139 Apr 13 10:20:13 nuc13 reth[424081]: 2024-04-13T08:20:13.809540Z WARN Failed to verify block state root target_block=1337139 got=0xf339af638c6c2a6e696d2cda9a5aa0a260b9d0fa4ec226d5c0e76db91c5a15b0 expected=SealedHeader { hash: 0x9bf31af3ca41a421cf05a682936a23c50c86865c1451ef8f5a87074a50849ee2, header: Header { parent_hash: 0xe64cc71cfbe21248128c756dcc47a79d34ea852895f2ea2908da19394fc0fa04, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x9baa3244565d51d9c7897c0eb6679ed4890e536e, state_root: 0x5c0071282a49ca27c45cd289cd6c33445820a63443257042102da8148e59f32e, transactions_root: 0xb8ad7a2f77c04094acfe35ef317dcbef813bad3a67af4c567f0cf1325b400942, receipts_root: 0x044da19b6bbd09905977a0c407e0d8613aedfc0ec796257006fe6f6f1122f7dc, withdrawals_root: Some(0x14ee52cf9f3b680a40d42ff502e2994e75039cbaa67ae0953d65fab47e71150d), logs_bloom: 0x15001000094002002000030000004dd4e1c108248600008044ae20244011c4eb2019710501882220021c204824822604182e221db10344022a340188222d100c0006c23240b1020510070c195400081061038500780c1100749746190a9040205001001846a140c20c050c857424090e441893800220d921000042141020044480001668048010f20080541c800048a14810b0090b000490301580010123162003a2a80047041500502015211d8018023f220e2050a4c818b48000260c14028c321884438000b5000d01808201cc1f0008602913009000002518310009c5602a401000240805ed0c2350098380098990ce0c800c0280a150043056105200c420, difficulty: 0x0_U256, number: 1337139, gas_limit: 30000000, gas_used: 15146437, timestamp: 1712994228, mix_hash: 0x14bdaa6b4d5ce5ca4803aaf2c42dc7f53e8e165d133b438588cea025b5aef9f3, nonce: 0, base_fee_per_gas: Some(1555332838), blob_gas_used: Some(524288), excess_blob_gas: Some(79560704), parent_beacon_block_root: Some(0x5dd523643cca358a3b1797a8dd5a6301c8ad9d8d5ae71462363ab1590b9aba42), extra_data: 0x } } Apr 13 10:20:13 nuc13 reth[424081]: 2024-04-13T08:20:13.809744Z ERROR Stage encountered a validation error: mismatched block state root: got 0xf339af638c6c2a6e696d2cda9a5aa0a260b9d0fa4ec226d5c0e76db91c5a15b0, expected 0x5c0071282a49ca27c45cd289cd6c33445820a63443257042102da8148e59f32e stage=MerkleExecute bad_block=1337139 Apr 13 10:20:13 nuc13 reth[424081]: 2024-04-13T08:20:13.893943Z INFO Unwinding{stage=StorageHashing}: Stage unwound stage=StorageHashing unwind_to=1336931 progress=1336931 done=true Apr 13 10:20:14 nuc13 reth[424081]: 2024-04-13T08:20:14.057641Z INFO Unwinding{stage=AccountHashing}: Stage unwound stage=AccountHashing unwind_to=1336931 progress=1336931 done=true Apr 13 10:20:14 nuc13 reth[424081]: 2024-04-13T08:20:14.895316Z WARN Unwinding{stage=MerkleUnwind}: Failed to verify block state root target_block=1336931 got=0x4c58076e9e0493c26848041376e88e9501a114d2f431e599467577146df56272 expected=SealedHeader { hash: 0xb6031d3ce90a8dd0eddc0928020523803cf2b2bf4c427d239f5faf0e90c985b9, header: Header { parent_hash: 0xd176f3b9cc5ae0ecbd96827765ac1a0edea8fded71f97e2ef52af7af9f68e003, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0xbcff060f601684a0dbf5b0ea48d8dcc112f4ff2f, state_root: 0x6fd8c329f6f8bdc3ede9da9f3caa36fbb1e93cdd9189efcfdbe99510a47fc29c, transactions_root: 0x95553b12c5e475c65ce0dc1fa83cce131eadddb01d5bd353c9d5a1191935e71c, receipts_root: 0x087be94c62d2f77a0bdc41d3323474f8b4d286366e5bf90ef5d1d46963f58ea2, withdrawals_root: Some(0x6e6c4888df701671e97110acfa69b3a1f533db28d9bda4dd6b0da52adefbee4a), logs_bloom: 0x0810025008020200108001810a1000524080c0620440d0881484080c504041281c00452100010200908d20a208080100220020492047100062948300a03e2a000000808c2410020141830d0d0e00d40143010020200050c000454459a0e090002c4000000a00040080c0034500104c0012000820000390280040101f00a000c080000108e0000080008000400009813006002100040100102806018140a014048b001b090000840006c04108078800102804003048490000980081a4010000810208041a02202c0108a8408481944598010100221c98384040199844500230200233a08a11022400200051022109a100883480000001010031aa080840802400, difficulty: 0x0_U256, number: 1336931, gas_limit: 30000000, gas_used: 19086161, timestamp: 1712991396, mix_hash: 0x8d0c50f1399ff1fbcd41999ac7a57b5591edaee3cf1fe8ee2676eafd0241832f, nonce: 0, base_fee_per_gas: Some(635436827), blob_gas_used: Some(655360), excess_blob_gas: Some(79298560), parent_beacon_block_root: Some(0x96a0450222350089ec0aa80ca8a1616b89a9f3664e6565673571ea0fee41759d), extra_data: 0xd883010d0b846765746888676f312e32312e36856c696e7578 } } Apr 13 10:20:14 nuc13 reth[424081]: 2024-04-13T08:20:14.901982Z ERROR shutting down due to error Apr 13 10:20:14 nuc13 reth[424081]: Error: stage encountered an error in block #1336931: validation error: mismatched block state root: got 0x4c58076e9e0493c26848041376e88e9501a114d2f431e599467577146df56272, expected 0x6fd8c329f6f8bdc3ede9da9f3caa36fbb1e93cdd9189efcfdbe99510a47fc29c Apr 13 10:20:14 nuc13 reth[424081]: Caused by: Apr 13 10:20:14 nuc13 reth[424081]: 0: validation error: mismatched block state root: got 0x4c58076e9e0493c26848041376e88e9501a114d2f431e599467577146df56272, expected 0x6fd8c329f6f8bdc3ede9da9f3caa36fbb1e93cdd9189efcfdbe99510a47fc29c Apr 13 10:20:14 nuc13 reth[424081]: 1: mismatched block state root: got 0x4c58076e9e0493c26848041376e88e9501a114d2f431e599467577146df56272, expected 0x6fd8c329f6f8bdc3ede9da9f3caa36fbb1e93cdd9189efcfdbe99510a47fc29c Apr 13 10:20:14 nuc13 reth[424081]: Location: Apr 13 10:20:14 nuc13 reth[424081]: /rustc/7cf61ebde7b22796c69757901dd346d0fe70bd97/library/core/src/task/poll.rs:255:39 Apr 13 10:20:14 nuc13 reth[424081]: 2024-04-13T08:20:14.902240Z INFO Wrote network peers to file peers_file="/var/lib/reth/known-peers.json" Apr 13 10:20:14 nuc13 systemd[1]: reth.service: Main process exited, code=exited, status=1/FAILURE Apr 13 10:20:14 nuc13 systemd[1]: reth.service: Failed with result 'exit-code'. Apr 13 10:20:14 nuc13 systemd[1]: reth.service: Consumed 2.980s CPU time.
And the db stats
$ sudo reth db stats --datadir /var/lib/reth/ Segment Block Range Transaction Range Shape (columns x rows) Data Size Index Size Offsets Size Config Size Total Size Headers 0..=499999 N/A 3 x 500000 163.1 MiB 0 B 11.4 MiB 75 B 174.6 MiB Headers 500000..=999999 N/A 3 x 500000 220.9 MiB 0 B 11.4 MiB 75 B 232.3 MiB Headers 1000000..=1337139 N/A 3 x 337140 187 MiB 0 B 7.7 MiB 75 B 194.7 MiB Transactions 0..=499999 0..=1903501 1 x 1903502 664.1 MiB 0 B 14.5 MiB 87 B 678.7 MiB Transactions 500000..=999999 1903502..=30681966 1 x 28778465 10.9 GiB 0 B 219.6 MiB 87 B 11.1 GiB Transactions 1000000..=1337139 30681967..=42160680 1 x 11478714 16.8 GiB 0 B 87.6 MiB 87 B 16.9 GiB ------------ ----------------- ------------------- ---------------------- --------- ---------- ------------ ----------- ---------- Total 28.9 GiB 0 B 352.3 MiB 486 B 29.3 GiB
Table Name # Entries Branch Pages Leaf Pages Overflow Pages Total Size AccountChangeSets 983378 2826 12730 0 60.8 MiB AccountsHistory 500708 642 43420 97 172.5 MiB AccountsTrie 2283883 803 160208 0 628.9 MiB BlockBodyIndices 1337140 36 7813 0 30.7 MiB BlockOmmers 0 0 0 0 0 B BlockWithdrawals 1327487 848 189585 0 743.9 MiB Bytecodes 59739 49 3470 123767 497.2 MiB CanonicalHeaders 71 1 2 0 12 KiB HashedAccounts 30286653 12544 794984 0 3.1 GiB HashedStorages 54452243 21935 1135072 0 4.4 GiB HeaderNumbers 1337140 425 31272 0 123.8 MiB HeaderTerminalDifficulties 71 0 1 0 4 KiB Headers 71 1 13 0 56 KiB PlainAccountState 30286653 5689 564568 0 2.2 GiB PlainStorageState 54452243 19815 995605 0 3.9 GiB PruneCheckpoints 5 0 1 0 4 KiB Receipts 3500578 653 145808 76044 869.2 MiB StageCheckpointProgresses 1 0 1 0 4 KiB StageCheckpoints 12 0 1 0 4 KiB StorageChangeSets 12212336 24866 181513 0 806.2 MiB StoragesHistory 1150638 4697 91452 83 375.9 MiB StoragesTrie 4382940 44864 375497 0 1.6 GiB TransactionBlocks 1164184 35 7463 0 29.3 MiB TransactionHashNumbers 42151036 14319 968999 0 3.8 GiB TransactionSenders 9645 1 91 0 368 KiB Transactions 3293 3 202 1195 5.5 MiB VersionHistory 2 0 1 0 4 KiB -------------------------- --------- ------------ ---------- -------------- ---------- Tables 23.1 GiB Freelist 361053 1.4 GiB — Reply to this email directly, view it on GitHub https://github.com/paradigmxyz/reth/issues/7430#issuecomment-2053570983, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAH2CHBGKCTNVUSRH2XP4OTY5DTVRAVCNFSM6AAAAABFUBABCSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDANJTGU3TAOJYGM . You are receiving this because you were mentioned.Message ID: @.***>
winksaville
commented
2 months ago @Rjected, txs for answering my question in the state root war room, I wanted to get some additional clarification, but Telegram doesn't handle long lines of "code" as well as GitHub so I'm asking the clarification here where I'm referring
to I had another "Failed to insert block" above. The file I mention here is reth.log.1 in the link to the logs in that comment.
The "2024-04-08T10:14:16.306330Z WARN .. Failed to insert block .." I now see has the "mismatched block state root" (I missed that previously).
I then looked at various logs before "2024-04-08T14:36:51.181336Z INFO .. Starting reth .." that mention "state root". and I've listed them below. The one you pointed out, that also has "mismatched block state root", is "2024-04-08T14:36:44.532056Z ERROR sync::pipeline: Stage encountered ..".
But another log entry that looked interesting was "2024-04-08T14:36:45.612071Z WARN Unwinding ..". It has "expected=SealedHeader { hash: 0x5c44156fbe0b623395752c0881c6a52ebb7fd33f97307b6964da70fa0be94c65" and that hash matches the "parent_hash=0x5c44156fbe0b623395752c0881c6a52ebb7fd33f97307b6964da70fa0be94c6" in the "Failed to insert block". To my mind that makes for a stronger correlation than "2024-04-08T14:36:44.532056Z ERROR sync::pipeline: Stage encountered ... mismatched block state root".
Your opinion?
Also, do you agree that the whatever is causing this "state root" problem happened before "2024-04-08T10:14:16.306330Z WARN .. Failed to insert block .."?
2024-04-08T10:14:16.306330Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0x75d33ca50ce5995c5829e318419a0457440a866982c717269d8ab59aa58d9378, number=1305364, parent_hash=0x5c44156fbe0b623395752c0881c6a52ebb7fd33f97307b6964da70fa0be94c65): mismatched block state root: got 0x1f4fa2a54d8d8d028b23247c85a769dbcc0c9b81fc61f5b1fc7a7ab07241d524, expected 0x617aa48146e8cec830faf41f4b8b36f1104e4c496c304ef5b37829bde06ac9df
..
2024-04-08T14:36:44.531539Z WARN sync::stages::merkle: Failed to verify block state root target_block=1305405 got=0x242a10a082135c30a0770efc198044112cece4af507fd8921260b31aed21216f expected=SealedHeader { hash: 0xf10c5efb5f9d7d47755a0329b2c86e7359af20252deb226fc6775bebea02469d, header: Header { parent_hash: 0xb1363e28fed60bb3a11a0c9789a1d263012002f99849530c3f45dcfb9d7e9028, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0xc6e2459991bfe27cca6d86722f35da23a1e4cb97, state_root: 0x1dfb052ec0aa4bb0896d52a5606e604a6798dcbd3991ca0939d622e08a4e27db, transactions_root: 0xc0955e38f8357fcce03d2b3351b632d571b95821f93dbd6cc74141a623b9b1fe, receipts_root: 0xd2542a83a6e3f8aad75299701ab4b49e5568648d314a8f919be1976cf316ab12, withdrawals_root: Some(0x21cfff1cf5c78d9d0b932f16162c3c11b44132ac223e46ac8b95ad53f293742a), logs_bloom: 0x34000010000002200100000000001004000040004000008000000000000000020010010000000000000400000000010000000010000000000000000000640000000280000080c004080008880000000008000000000400010002040008080020110060001200000100800080000008000400000040000000800000100500000000000002000000000000000000000010001000000008109000040001004000000200000000004000000200004400000000000008000000100000000000000000b01000020010900a08400080080402000801000000c0004000080000000060000010000000000404004204000000000100000109020000040000084000000000, difficulty: 0x0_U256, number: 1305405, gas_limit: 30000000, gas_used: 2097742, timestamp: 1712571840, mix_hash: 0x83e28916a9383bb856400b934dde5450f04366930e6189081ac0c39607128c0d, nonce: 0, base_fee_per_gas: Some(8), blob_gas_used: Some(786432), excess_blob_gas: Some(42991616), parent_beacon_block_root: Some(0x32f971bdedbbfd1974c3451c44436c3dfffbc8411abc1390beef06fe62bddb4d), extra_data: 0xd883010d0e846765746888676f312e32312e36856c696e7578 } }
2024-04-08T14:36:44.532056Z ERROR sync::pipeline: Stage encountered a validation error: mismatched block state root: got 0x242a10a082135c30a0770efc198044112cece4af507fd8921260b31aed21216f, expected 0x1dfb052ec0aa4bb0896d52a5606e604a6798dcbd3991ca0939d622e08a4e27db stage=MerkleExecute bad_block=1305405
..
2024-04-08T14:36:45.612071Z WARN Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::stages::merkle: Failed to verify block state root target_block=1305363 got=0x85bf1516e35a3cf6026b39b0480640adbfcfe3ea0df3f357fbbf94768d7a0ce4 expected=SealedHeader { hash: 0x5c44156fbe0b623395752c0881c6a52ebb7fd33f97307b6964da70fa0be94c65, header: Header { parent_hash: 0x8204f073080b1e1d09140a1aaf4faaf925c7294251bd8842b1fe601d230cbc84, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0xc473d412dc52e349862209924c8981b2ee420768, state_root: 0x35bbf434a0a3aeda9ca3bb315e67b2b9f6fba16f1c040bdffb6a32af00d18437, transactions_root: 0x04ed6a4ee080689a26e827ccb40c0d8f48e6fb01c28a966d5490a8f5d0b24b84, receipts_root: 0xcbe95b5aa94512e05a494f9d1fa8ee02a02a6329add2720079c8f3e6d312a259, withdrawals_root: Some(0xe6ac311ba3c1c62b8d16c7497db0523852e43078990be3f7d7c81cb8f4217ac5), logs_bloom: 0x00000090000000002100800000050004010000004420018042000004011040000308018000020200000000810000000000808810080000020042040008700100001690000020d0000090088900000001000000006080000140840011200001210002000002000000000000800400090080000c2000404008040000100000004008088000100200002800000000010004009000000000009000860000140004010308820020000000a08000100000800020000000040008080800800000814080100400028010180000400004800402404c01020000a0204000000100008071040430000a800004402000040200000000005200010200a0c00000000000001000, difficulty: 0x0_U256, number: 1305363, gas_limit: 30000000, gas_used: 2002842, timestamp: 1712571240, mix_hash: 0x9022e457218d6d867160c20dffa486aa7a9bf3880417ffdbe3f48f2f9bfa9de0, nonce: 0, base_fee_per_gas: Some(15), blob_gas_used: Some(786432), excess_blob_gas: Some(32505856), parent_beacon_block_root: Some(0x37518849b748b2c62681a386e74f4bea96d0ddbe3373d531bedbbf877c605264), extra_data: 0x4e65746865726d696e64 } }
2024-04-08T14:36:45.625892Z ERROR reth::cli: shutting down due to error
2024-04-08T14:36:51.181336Z INFO reth::cli: Starting reth version="0.2.0-beta.5 (54f75cdcc)"The "state root" issued happened again, as I expected. There are two differences:
This has my panic code
when there is a "Failed to insert block". Because of the panic reth shutdowns and restarts immediately. Sadly there was
no stack frame emitted. But there is a little more information because I printed self with debug output.
The other difference, it took about a week before it failed. Previously it was 4 days or less, so the other difference was after 5 days or so I turned off promethesus and grafana. Note; promethesus and grafana were running on my dev computer so the metrics were being collected over my LAN.
So there is a possibility that with the metrics gathering turned off the state root error occurs "more quickly". Maybe a race condition is less likely to occur with metrics on? I suggest you turning off metrics gathering on one or more of your nodes and see if you can reproduce the problem locally. Also note, this is on holesky!.
Here is the first and second "Failed to insert block":
2024-04-14T23:07:28.186586Z ERROR reth_tasks: Critical task `consensus engine` panicked: `Wink: Failed to insert block, InsertBlockError { error: Consensus(BodyStateRootDiff(GotExpected { got: 0xcc20874ee3667b49a5f7d8437de617eebeee5df120760121685667962cba08e2, expected: 0x4b3e9ba36ca754c4102c666ee5c1fa4f273aa54981648e72d66bb59f13e1d76e })), hash: 0xe607ef334a988dff381bedd5e6c75139abf375baae9563b2ad691f8d1c27cef6, number: 1347945, parent_hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, num_txs: 39, .. }`
2024-04-14T23:07:28.189527Z ERROR reth::cli: shutting down due to error
2024-04-14T23:07:33.715168Z INFO reth::cli: Starting reth version="0.2.0-beta.5-dev (cd1c2bf99)"
2024-04-14T23:07:33.715812Z INFO reth::cli: Opening database path="/home/kendall/eth2-data/reth/holesky/db"
2024-04-14T23:07:33.741551Z INFO reth::cli: Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
2024-04-14T23:07:33.744058Z INFO reth::cli: Database opened
2024-04-14T23:07:33.744076Z INFO reth::cli: Starting metrics endpoint addr=0.0.0.0:9001
2024-04-14T23:07:33.744152Z DEBUG reth::cli: Initializing genesis chain=holesky genesis=0xb5f7f912443c940f21fd611f12828d75b534364ed9e95ca4e307729a4661bde4
2024-04-14T23:07:33.744791Z DEBUG reth_node_core::init: Genesis already written, skipping.
2024-04-14T23:07:33.744831Z INFO reth::cli:
Pre-merge hard forks (block based):
- Frontier @0
- Homestead @0
- Dao @0
- Tangerine @0
- SpuriousDragon @0
- Byzantium @0
- Constantinople @0
- Petersburg @0
- Istanbul @0
- MuirGlacier @0
- Berlin @0
- London @0
Merge hard forks:
- Paris @0 (network is known to be merged)
Post-merge hard forks (timestamp based):
- Shanghai @1696000704
- Cancun @1707305664
2024-04-14T23:07:33.744851Z DEBUG reth::cli: Spawning stages metrics listener task
2024-04-14T23:07:33.745350Z DEBUG reth::cli: configured blockchain tree
2024-04-14T23:07:33.745416Z DEBUG reth::cli: creating components
2024-04-14T23:07:33.753365Z DEBUG txpool::blob: Removed blob store directory blob_dir="/home/kendall/eth2-data/reth/holesky/blobstore"
2024-04-14T23:07:33.753389Z DEBUG txpool::blob: Creating blob store blob_dir="/home/kendall/eth2-data/reth/holesky/blobstore"
2024-04-14T23:07:33.814665Z INFO reth::cli: Transaction pool initialized
2024-04-14T23:07:33.814685Z DEBUG reth::cli: Spawned txpool maintenance task
2024-04-14T23:07:33.814690Z INFO reth::cli: Connecting to P2P network
2024-04-14T23:07:33.814692Z DEBUG reth::cli: Loading p2p key file network_secret_path="/home/kendall/eth2-data/reth/holesky/discovery-secret"
2024-04-14T23:07:33.818716Z INFO net::peers: Loading saved peers file=/home/kendall/eth2-data/reth/holesky/known-peers.json
2024-04-14T23:07:33.824603Z DEBUG discv4: pinging boot node record=NodeRecord { address: 178.128.136.233, tcp_port: 30303, udp_port: 30303, id: 0xa3435a0155a3e837c02f5e7f5662a2f1fbc25b48e4dc232016e1c51b544cb5b4510ef633ea3278c0e970fa8ad8141e2d4d0f9f95456c537ff05fdf9b31c15072 }
2024-04-14T23:07:33.824802Z DEBUG discv4: pinging boot node record=NodeRecord { address: 146.190.13.128, tcp_port: 30303, udp_port: 30303, id: 0xac906289e4b7f12df423d654c5a962b6ebe5b3a74cc9e06292a85221f9a64a6f1cfdd6b714ed6dacef51578f92b34c60ee91e9ede9c7f8fadc4d347326d95e2b }
2024-04-14T23:07:33.826530Z DEBUG discv4: pinging boot node record=NodeRecord { address: 178.128.136.233, tcp_port: 30303, udp_port: 30303, id: 0xa3435a0155a3e837c02f5e7f5662a2f1fbc25b48e4dc232016e1c51b544cb5b4510ef633ea3278c0e970fa8ad8141e2d4d0f9f95456c537ff05fdf9b31c15072 }
2024-04-14T23:07:33.826598Z DEBUG discv4: pinging boot node record=NodeRecord { address: 146.190.13.128, tcp_port: 30303, udp_port: 30303, id: 0xac906289e4b7f12df423d654c5a962b6ebe5b3a74cc9e06292a85221f9a64a6f1cfdd6b714ed6dacef51578f92b34c60ee91e9ede9c7f8fadc4d347326d95e2b }
2024-04-14T23:07:33.826663Z DEBUG igd_next::aio::tokio: sending broadcast request to: 239.255.255.250:1900 on interface: Ok(0.0.0.0:54186)
2024-04-14T23:07:33.827269Z DEBUG reth::cli: calling on_component_initialized hook
2024-04-14T23:07:33.827456Z INFO reth::cli: StaticFileProducer initialized
2024-04-14T23:07:33.828927Z INFO reth::cli: Pruner initialized prune_config=PruneConfig { block_interval: 5, segments: PruneModes { sender_recovery: Some(Full), transaction_lookup: None, receipts: Some(Before(0)), account_history: Some(Distance(10064)), storage_history: Some(Distance(10064)), receipts_log_filter: ReceiptsLogPruneConfig({0x4242424242424242424242424242424242424242: Before(0)}) } }
2024-04-14T23:07:33.829298Z INFO reth::cli: Consensus engine initialized
2024-04-14T23:07:33.829352Z INFO reth::cli: Engine API handler initialized
2024-04-14T23:07:33.829356Z DEBUG reth::cli: Reading JWT auth secret file user_path="/home/kendall/eth2-data/secrets/jwtsecret"
2024-04-14T23:07:33.830197Z DEBUG reth::cli: Using RPC module config http=Some(Selection([Admin, Eth, Web3, Net])) ws=Some(Selection([Eth, Net, Web3]))
2024-04-14T23:07:33.833765Z INFO reth::cli: RPC auth server started url=127.0.0.1:8551
2024-04-14T23:07:33.833794Z INFO reth::cli: RPC IPC server started url=/tmp/reth.ipc
2024-04-14T23:07:33.833800Z INFO reth::cli: RPC HTTP server started url=0.0.0.0:8545
2024-04-14T23:07:33.833806Z INFO reth::cli: RPC WS server started url=127.0.0.1:8546
2024-04-14T23:07:33.833818Z INFO reth::cli: Starting consensus engine
2024-04-14T23:07:33.834199Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-04-14T23:07:33.864558Z DEBUG disc::dns: Failed to lookup entry err=invalid child hash in branch: domain=all.holesky.ethdisco.net hash="FDXN3SN67NA5DKA4J2GOK7BVQI"
2024-04-14T23:07:33.919139Z DEBUG connection{[3mremote_addr[0m[2m=[0m127.0.0.1:34162 [3mconn_id[0m[2m=[0m0}: jsonrpsee_server::server: Accepting new connection 1/500
2024-04-14T23:07:36.830902Z INFO reth::cli: Status connected_peers=0 freelist=12127 latest_block=1347944
2024-04-14T23:07:38.853283Z DEBUG net: Session established remote_addr=146.190.13.128:30303 client_version=Geth/v1.13.14-stable-2bd6bd01/linux-amd64/go1.21.7 peer_id=0xac906289e4b7f12df423d654c5a962b6ebe5b3a74cc9e06292a85221f9a64a6f1cfdd6b714ed6dacef51578f92b34c60ee91e9ede9c7f8fadc4d347326d95e2b total_active=1 kind=outgoing peer_enode=enode://ac906289e4b7f12df423d654c5a962b6ebe5b3a74cc9e06292a85221f9a64a6f1cfdd6b714ed6dacef51578f92b34c60ee91e9ede9c7f8fadc4d347326d95e2b@146.190.13.128:30303
2024-04-14T23:07:39.281717Z DEBUG net: Session established remote_addr=178.128.136.233:30303 client_version=Geth/v1.13.14-stable-2bd6bd01/linux-amd64/go1.21.7 peer_id=0xa3435a0155a3e837c02f5e7f5662a2f1fbc25b48e4dc232016e1c51b544cb5b4510ef633ea3278c0e970fa8ad8141e2d4d0f9f95456c537ff05fdf9b31c15072 total_active=2 kind=outgoing peer_enode=enode://a3435a0155a3e837c02f5e7f5662a2f1fbc25b48e4dc232016e1c51b544cb5b4510ef633ea3278c0e970fa8ad8141e2d4d0f9f95456c537ff05fdf9b31c15072@178.128.136.233:30303
2024-04-14T23:07:42.260797Z DEBUG blockchain_tree: Appending block to canonical chain head=0xe607ef334a988dff381bedd5e6c75139abf375baae9563b2ad691f8d1c27cef6 parent=(1347944, 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822)
2024-04-14T23:07:42.318983Z DEBUG evm: Execution time evm_transact=46.273355ms apply_state=741.745µs apply_post_state=3.357µs merge_transitions=749.003µs receipt_root=2.355841ms
2024-04-14T23:07:42.320521Z DEBUG trie::parallel_state_root: pre-calculating storage roots len=368
2024-04-14T23:07:42.585550Z ERROR reth_tasks: Critical task `consensus engine` panicked: `Wink: Failed to insert block, InsertBlockError { error: Consensus(BodyStateRootDiff(GotExpected { got: 0xcc20874ee3667b49a5f7d8437de617eebeee5df120760121685667962cba08e2, expected: 0x4b3e9ba36ca754c4102c666ee5c1fa4f273aa54981648e72d66bb59f13e1d76e })), hash: 0xe607ef334a988dff381bedd5e6c75139abf375baae9563b2ad691f8d1c27cef6, number: 1347945, parent_hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, num_txs: 39, .. }`
2024-04-14T23:07:42.585619Z ERROR reth::cli: shutting down due to error
2024-04-14T23:07:47.957976Z INFO reth::cli: Starting reth version="0.2.0-beta.5-dev (cd1c2bf99)"
2024-04-14T23:07:48.058795Z INFO reth::cli: Opening database path="/home/kendall/eth2-data/reth/holesky/db"
2024-04-14T23:07:48.076789Z INFO reth::cli: Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
2024-04-14T23:07:48.078019Z INFO reth::cli: Database opened
2024-04-14T23:07:48.078078Z INFO reth::cli: Starting metrics endpoint addr=0.0.0.0:9001
2024-04-14T23:07:48.078153Z DEBUG reth::cli: Initializing genesis chain=holesky genesis=0xb5f7f912443c940f21fd611f12828d75b534364ed9e95ca4e307729a4661bde4
2024-04-14T23:07:48.078270Z DEBUG reth_node_core::init: Genesis already written, skipping.
2024-04-14T23:07:48.078318Z INFO reth::cli:
Pre-merge hard forks (block based):
- Frontier @0
- Homestead @0
- Dao @0
- Tangerine @0
- SpuriousDragon @0That rebooting from the panic continued until:
2024-04-14T23:24:54.923178Z ERROR reth_tasks: Critical task `consensus engine` panicked: `Wink: Failed to insert block, InsertBlockError { error: Consensus(BodyStateRootDiff(GotExpected { got: 0xcc20874ee3667b49a5f7d8437de617eebeee5df120760121685667962cba08e2, expected: 0x4b3e9ba36ca754c4102c666ee5c1fa4f273aa54981648e72d66bb59f13e1d76e })), hash: 0xe607ef334a988dff381bedd5e6c75139abf375baae9563b2ad691f8d1c27cef6, number: 1347945, parent_hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, num_txs: 39, .. }`
2024-04-14T23:24:54.923207Z ERROR reth::cli: shutting down due to error
2024-04-14T23:25:00.165545Z INFO reth::cli: Starting reth version="0.2.0-beta.5-dev (cd1c2bf99)"
2024-04-14T23:25:00.166211Z INFO reth::cli: Opening database path="/home/kendall/eth2-data/reth/holesky/db"
2024-04-14T23:25:00.184547Z INFO reth::cli: Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
2024-04-14T23:25:00.185750Z INFO reth::cli: Database opened
2024-04-14T23:25:00.185783Z INFO reth::cli: Starting metrics endpoint addr=0.0.0.0:9001
2024-04-14T23:25:00.185878Z DEBUG reth::cli: Initializing genesis chain=holesky genesis=0xb5f7f912443c940f21fd611f12828d75b534364ed9e95ca4e307729a4661bde4
2024-04-14T23:25:00.185993Z DEBUG reth_node_core::init: Genesis already written, skipping.
2024-04-14T23:25:00.186045Z INFO reth::cli:
Pre-merge hard forks (block based):
- Frontier @0
- Homestead @0It then started rebooting because "Failed to verify block state root":
2024-04-14T23:30:55.715564Z WARN Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::stages::merkle: Failed to verify block state root target_block=1347944 got=0xd0dd1d687b5905b40e8bdddd6a0c1ecb33de07d74c821d24d61a7ece53e7b5ae expected=SealedHeader { hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, header: Header { parent_hash: 0x9378e27ff4b30650e8e561d3a954c8b1afb1720dca999cbf57a0c7d9c1e33a6c, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x942a3c0644ed50e3fbc1136f7bffdc505306bde0, state_root: 0xd01ad853ea1a1cc46eaee8d4a72dd46fffc912568dce5a0a9b66eef3af2b4576, transactions_root: 0x5949e0f8a6a9cdb92b863493f423dca1fc5ef8f99c6f8795a0fe3c911ec5c938, receipts_root: 0x92ed0214a8df3cb2070ffe7a231e548cedeedf211e5d96ded41fb0f1b66e5d16, withdrawals_root: Some(0x9bb70698fb705cdb948c74a1a5d5f346f334baeb5b5afb22571be2d78ad7054a), logs_bloom: 0x0002000a48480040208005864000153042a10801040464910e020220007072c36028138040200a00202424a00822408801020001901310068864b58280280f456022820a0065014060000809140000c409088050030401220814301b2489425158160506036010404500008528800c404800c0400818413008492010002040818100000001021810050903418840081a100c221408808210000500850000048193008c080465d02021a8061285830400280a1008c00641049031880680800c80000912c20410005040480000f08485120028001284286a08628ad0040200b81000501048100201102008459240088001b8353000806235081201000211c04534, difficulty: 0x0_U256, number: 1347944, gas_limit: 30000000, gas_used: 10051505, timestamp: 1713136032, mix_hash: 0xc7f8b6cc90b59bfc9da7d11884a7460495b75546c39032a787a55855ba3681dd, nonce: 0, base_fee_per_gas: Some(2807217650), blob_gas_used: Some(786432), excess_blob_gas: Some(79167488), parent_beacon_block_root: Some(0xc3e6acf8bc5c151afe191348a7ccd8624d433c1e94f8a51a6ad7c64463db7f7a), extra_data: 0x4e65746865726d696e64 } }
2024-04-14T23:30:55.716864Z ERROR reth::cli: shutting down due to error
2024-04-14T23:31:00.903028Z INFO reth::cli: Starting reth version="0.2.0-beta.5-dev (cd1c2bf99)"
2024-04-14T23:31:00.903633Z INFO reth::cli: Opening database path="/home/kendall/eth2-data/reth/holesky/db"
2024-04-14T23:31:00.943247Z INFO reth::cli: Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
2024-04-14T23:31:00.944423Z INFO reth::cli: Database opened
2024-04-14T23:31:00.944457Z INFO reth::cli: Starting metrics endpoint addr=0.0.0.0:9001
2024-04-14T23:31:00.944582Z DEBUG reth::cli: Initializing genesis chain=holesky genesis=0xb5f7f912443c940f21fd611f12828d75b534364ed9e95ca4e307729a4661bde4
2024-04-14T23:31:00.944721Z DEBUG reth_node_core::init: Genesis already written, skipping.
2024-04-14T23:31:00.944789Z INFO reth::cli:
Pre-merge hard forks (block based):
- Frontier @0
- Homestead @0
- Dao @0
- Tangerine @0
- SpuriousDragon @0
- Byzantium @0
- Constantinople @0
- Petersburg @0
- Istanbul @0
- MuirGlacier @0
- Berlin @0
- London @0
Merge hard forks:
- Paris @0 (network is known to be merged)
Post-merge hard forks (timestamp based):
- Shanghai @1696000704
- Cancun @1707305664
2024-04-14T23:31:00.944817Z DEBUG reth::cli: Spawning stages metrics listener task
2024-04-14T23:31:00.945343Z DEBUG reth::cli: configured blockchain tree
2024-04-14T23:31:00.945393Z DEBUG reth::cli: creating components
2024-04-14T23:31:00.945519Z DEBUG txpool::blob: Removed blob store directory blob_dir="/home/kendall/eth2-data/reth/holesky/blobstore"
2024-04-14T23:31:00.945534Z DEBUG txpool::blob: Creating blob store blob_dir="/home/kendall/eth2-data/reth/holesky/blobstore"
2024-04-14T23:31:01.004389Z INFO reth::cli: Transaction pool initialized
2024-04-14T23:31:01.004404Z DEBUG reth::cli: Spawned txpool maintenance task
2024-04-14T23:31:01.004409Z INFO reth::cli: Connecting to P2P network
2024-04-14T23:31:01.004411Z DEBUG reth::cli: Loading p2p key file network_secret_path="/home/kendall/eth2-data/reth/holesky/discovery-secret"
2024-04-14T23:31:01.004560Z INFO net::peers: Loading saved peers file=/home/kendall/eth2-data/reth/holesky/known-peers.json
2024-04-14T23:31:01.005690Z DEBUG discv4: pinging boot node record=NodeRecord { address: 178.128.136.233, tcp_port: 30303, udp_port: 30303, id: 0xa3435a0155a3e837c02f5e7f5662a2f1fbc25b48e4dc232016e1c51b544cb5b4510ef633ea3278c0e970fa8ad8141e2d4d0f9f95456c537ff05fdf9b31c15072 }
2024-04-14T23:31:01.005799Z DEBUG discv4: pinging boot node record=NodeRecord { address: 146.190.13.128, tcp_port: 30303, udp_port: 30303, id: 0xac906289e4b7f12df423d654c5a962b6ebe5b3a74cc9e06292a85221f9a64a6f1cfdd6b714ed6dacef51578f92b34c60ee91e9ede9c7f8fadc4d347326d95e2b }
2024-04-14T23:31:01.006103Z DEBUG reth::cli: calling on_component_initialized hook
2024-04-14T23:31:01.006095Z DEBUG discv4: pinging boot node record=NodeRecord { address: 178.128.136.233, tcp_port: 30303, udp_port: 30303, id: 0xa3435a0155a3e837c02f5e7f5662a2f1fbc25b48e4dc232016e1c51b544cb5b4510ef633ea3278c0e970fa8ad8141e2d4d0f9f95456c537ff05fdf9b31c15072 }
2024-04-14T23:31:01.006113Z DEBUG discv4: pinging boot node record=NodeRecord { address: 146.190.13.128, tcp_port: 30303, udp_port: 30303, id: 0xac906289e4b7f12df423d654c5a962b6ebe5b3a74cc9e06292a85221f9a64a6f1cfdd6b714ed6dacef51578f92b34c60ee91e9ede9c7f8fadc4d347326d95e2b }
2024-04-14T23:31:01.006157Z INFO reth::cli: StaticFileProducer initialized
2024-04-14T23:31:01.006153Z DEBUG igd_next::aio::tokio: sending broadcast request to: 239.255.255.250:1900 on interface: Ok(0.0.0.0:54703)
2024-04-14T23:31:01.006327Z INFO reth::cli: Pruner initialized prune_config=PruneConfig { block_interval: 5, segments: PruneModes { sender_recovery: Some(Full), transaction_lookup: None, receipts: Some(Before(0)), account_history: Some(Distance(10064)), storage_history: Some(Distance(10064)), receipts_log_filter: ReceiptsLogPruneConfig({0x4242424242424242424242424242424242424242: Before(0)}) } }
2024-04-14T23:31:01.006439Z DEBUG consensus::engine: Pipeline sync progress is inconsistent first_stage_checkpoint=1347968 inconsistent_stage_id=AccountHashing inconsistent_stage_checkpoint=1347944
2024-04-14T23:31:01.006459Z INFO reth::cli: Consensus engine initialized
2024-04-14T23:31:01.006493Z INFO reth::cli: Engine API handler initialized
2024-04-14T23:31:01.006498Z DEBUG reth::cli: Reading JWT auth secret file user_path="/home/kendall/eth2-data/secrets/jwtsecret"
2024-04-14T23:31:01.006583Z DEBUG reth::cli: Using RPC module config http=Some(Selection([Admin, Eth, Web3, Net])) ws=Some(Selection([Eth, Net, Web3]))
2024-04-14T23:31:01.008384Z INFO reth::cli: RPC auth server started url=127.0.0.1:8551
2024-04-14T23:31:01.008440Z INFO reth::cli: RPC IPC server started url=/tmp/reth.ipc
2024-04-14T23:31:01.008449Z INFO reth::cli: RPC HTTP server started url=0.0.0.0:8545
2024-04-14T23:31:01.008457Z INFO reth::cli: RPC WS server started url=127.0.0.1:8546
2024-04-14T23:31:01.008467Z INFO reth::cli: Starting consensus engine
2024-04-14T23:31:01.008778Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-04-14T23:31:01.009051Z INFO sync::stages::headers: Target block already reached checkpoint=1347968 target=Hash(0x8d457ec320dd9eb3c7be0ca55b0d227d0680bbe53076e2b7b0a910e3c933a50f)
2024-04-14T23:31:01.009055Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=1/12 stage=Headers checkpoint=1347968 target=None
2024-04-14T23:31:01.009074Z INFO reth_node_core::events::node: Executing stage pipeline_stages=1/12 stage=Headers checkpoint=1347968 target=None
2024-04-14T23:31:01.009140Z INFO reth_node_core::events::node: Finished stage pipeline_stages=1/12 stage=Headers checkpoint=1347968 target=None stage_progress=100.00%
2024-04-14T23:31:01.009127Z DEBUG storage::db::mdbx: Commit total_duration=10.808µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-14T23:31:01.009192Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=2/12 stage=Bodies checkpoint=1347968 target=1347968
2024-04-14T23:31:01.009208Z DEBUG storage::db::mdbx: Commit total_duration=12.131µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-14T23:31:01.009217Z INFO reth_node_core::events::node: Executing stage pipeline_stages=2/12 stage=Bodies checkpoint=1347968 target=1347968
2024-04-14T23:31:01.009227Z INFO reth_node_core::events::node: Finished stage pipeline_stages=2/12 stage=Bodies checkpoint=1347968 target=1347968 stage_progress=100.00%
2024-04-14T23:31:01.009236Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=3/12 stage=SenderRecovery checkpoint=1347968 target=1347968
2024-04-14T23:31:01.009244Z INFO reth_node_core::events::node: Executing stage pipeline_stages=3/12 stage=SenderRecovery checkpoint=1347968 target=1347968
2024-04-14T23:31:01.009253Z INFO reth_node_core::events::node: Finished stage pipeline_stages=3/12 stage=SenderRecovery checkpoint=1347968 target=1347968 stage_progress=99.99%
2024-04-14T23:31:01.009258Z DEBUG storage::db::mdbx: Commit total_duration=12.181µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-14T23:31:01.009292Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=4/12 stage=Execution checkpoint=1347968 target=1347968
2024-04-14T23:31:01.009307Z INFO reth_node_core::events::node: Executing stage pipeline_stages=4/12 stage=Execution checkpoint=1347968 target=1347968
2024-04-14T23:31:01.009305Z DEBUG storage::db::mdbx: Commit total_duration=10.783µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-14T23:31:01.009322Z INFO reth_node_core::events::node: Finished stage pipeline_stages=4/12 stage=Execution checkpoint=1347968 target=1347968 stage_progress=100.00%
2024-04-14T23:31:01.009334Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=5/12 stage=MerkleUnwind checkpoint=1347968 target=1347968
2024-04-14T23:31:01.009338Z INFO sync::stages::merkle::unwind: Stage is always skipped
2024-04-14T23:31:01.009346Z INFO reth_node_core::events::node: Executing stage pipeline_stages=5/12 stage=MerkleUnwind checkpoint=1347968 target=1347968
2024-04-14T23:31:01.009359Z INFO reth_node_core::events::node: Finished stage pipeline_stages=5/12 stage=MerkleUnwind checkpoint=1347968 target=1347968
2024-04-14T23:31:01.009369Z DEBUG storage::db::mdbx: Commit total_duration=22.945µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-14T23:31:01.009403Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=6/12 stage=AccountHashing checkpoint=1347944 target=1347968
2024-04-14T23:31:01.009419Z INFO reth_node_core::events::node: Executing stage pipeline_stages=6/12 stage=AccountHashing checkpoint=1347944 target=1347968
2024-04-14T23:31:01.034886Z DEBUG disc::dns: Failed to lookup entry err=invalid child hash in branch: domain=all.holesky.ethdisco.net hash="FDXN3SN67NA5DKA4J2GOK7BVQI"
2024-04-14T23:31:01.044551Z INFO reth_node_core::events::node: Finished stage pipeline_stages=6/12 stage=AccountHashing checkpoint=1347968 target=1347968 stage_progress=100.00%
2024-04-14T23:31:01.124132Z DEBUG storage::db::mdbx: Commit total_duration=79.633873ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 6, audit: 0, write: 0, sync: 5206, ending: 0, whole: 5213, 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-04-14T23:31:01.124304Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1347944 target=1347968
2024-04-14T23:31:01.124319Z INFO reth_node_core::events::node: Executing stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1347944 target=1347968
2024-04-14T23:31:01.186028Z INFO reth_node_core::events::node: Finished stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1347968 target=1347968 stage_progress=100.00%
2024-04-14T23:31:01.338141Z DEBUG storage::db::mdbx: Commit total_duration=152.135188ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 15, audit: 0, write: 0, sync: 9950, ending: 0, whole: 9966, 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-04-14T23:31:01.338309Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1347944 target=1347968
2024-04-14T23:31:01.338340Z INFO reth_node_core::events::node: Executing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1347944 target=1347968
2024-04-14T23:31:01.338351Z DEBUG sync::stages::merkle::exec: Updating trie current=1347944 target=1347968
2024-04-14T23:31:01.338386Z DEBUG trie::loader: incremental state root range=1347945..=1347968
2024-04-14T23:31:01.585884Z DEBUG connection{[3mremote_addr[0m[2m=[0m127.0.0.1:53292 [3mconn_id[0m[2m=[0m0}: jsonrpsee_server::server: Accepting new connection 1/500
2024-04-14T23:31:01.882706Z DEBUG connection{[3mremote_addr[0m[2m=[0m127.0.0.1:53296 [3mconn_id[0m[2m=[0m1}: jsonrpsee_server::server: Accepting new connection 2/500
2024-04-14T23:31:02.040348Z WARN sync::stages::merkle: Failed to verify block state root target_block=1347968 got=0xe87da9fa2117d2479c121daeb04b01c8be5c0f5ec7e9434571a0b156e6a7048d expected=SealedHeader { hash: 0x8d457ec320dd9eb3c7be0ca55b0d227d0680bbe53076e2b7b0a910e3c933a50f, header: Header { parent_hash: 0xf233c10ab77755d9b81a91a38240ce38bdebe19ca12a09d6e5a4f6f7fe4cb52b, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x8668b0181b08037079b5c05d53c51361e5b8bd7c, state_root: 0x32b03893c8f80d977556622605c8a5fd4cae36edb98e229dfe4107b4f00b25c0, transactions_root: 0xb3eff2c04b05b07fcf6f89e8ce63a17df9684ff70e37324e07cd3f6c388507d7, receipts_root: 0x4129317a458629f545d09391c07af791a524bfd8bbd8b8248b7e342617e68c1e, withdrawals_root: Some(0x2383c79d88357dcf09c17c7e5f9077c384b697d11b7b98ef1fc6e8b7bc46378a), logs_bloom: 0x0429000008083820000089100005120070410022060ac210048302a4441044080089491510200000944426c804e80200100038259347042860a41104202d1900300843d2802042d40005400bb440802409271822800401206004221b08d12100040e42100a040008200482423018090820805a000a0842300042409020a204c0008062490020400048801841002000cc02c1e4001804400428101211000004200300cc020001040230220801850f0c08a20a10004444402010000026006c828c433820820020150108001020804205001181085a22410008049b14022100e014001040440210041830180510c00841829c058468880023484052000230800500, difficulty: 0x0_U256, number: 1347968, gas_limit: 30000000, gas_used: 16934330, timestamp: 1713136320, mix_hash: 0x31a95cf04136b4cac1391059b30ef5fadcbcae51a36dbe0765b1bdd7d4be1b93, nonce: 0, base_fee_per_gas: Some(2236729849), blob_gas_used: Some(131072), excess_blob_gas: Some(79560704), parent_beacon_block_root: Some(0xc4de1633830f5c99d232378c8b37b51fe408060b4468fee6484ac8be8c1c950c), extra_data: 0x706170696368756c6f } }
2024-04-14T23:31:02.045797Z ERROR sync::pipeline: Stage encountered a validation error: mismatched block state root: got 0xe87da9fa2117d2479c121daeb04b01c8be5c0f5ec7e9434571a0b156e6a7048d, expected 0x32b03893c8f80d977556622605c8a5fd4cae36edb98e229dfe4107b4f00b25c0 stage=MerkleExecute bad_block=1347968
2024-04-14T23:31:02.045888Z DEBUG storage::db::mdbx: Commit total_duration=12.806µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-14T23:31:02.045965Z DEBUG Unwinding{[3mstage[0m[2m=[0mFinish}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-14T23:31:02.046011Z DEBUG Unwinding{[3mstage[0m[2m=[0mIndexAccountHistory}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-14T23:31:02.046049Z DEBUG Unwinding{[3mstage[0m[2m=[0mIndexStorageHistory}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-14T23:31:02.046085Z DEBUG Unwinding{[3mstage[0m[2m=[0mTransactionLookup}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-14T23:31:02.046121Z DEBUG Unwinding{[3mstage[0m[2m=[0mMerkleExecute}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-14T23:31:02.046158Z DEBUG Unwinding{[3mstage[0m[2m=[0mStorageHashing}: sync::pipeline: Starting unwind from=1347968 to=1347944 bad_block=Some(1347968)
2024-04-14T23:31:02.099022Z INFO Unwinding{[3mstage[0m[2m=[0mStorageHashing}: sync::pipeline: Stage unwound stage=StorageHashing unwind_to=1347944 progress=1347944 done=true
2024-04-14T23:31:02.441987Z DEBUG Unwinding{[3mstage[0m[2m=[0mStorageHashing}: storage::db::mdbx: Commit total_duration=342.879127ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 6, audit: 0, write: 0, sync: 22462, ending: 0, whole: 22469, 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-04-14T23:31:02.442117Z DEBUG Unwinding{[3mstage[0m[2m=[0mAccountHashing}: sync::pipeline: Starting unwind from=1347968 to=1347944 bad_block=Some(1347968)
2024-04-14T23:31:02.454124Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-04-14T23:31:02.476490Z INFO Unwinding{[3mstage[0m[2m=[0mAccountHashing}: sync::pipeline: Stage unwound stage=AccountHashing unwind_to=1347944 progress=1347944 done=true
2024-04-14T23:31:02.551478Z DEBUG Unwinding{[3mstage[0m[2m=[0mAccountHashing}: storage::db::mdbx: Commit total_duration=74.929752ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 5, audit: 0, write: 0, sync: 4856, ending: 0, whole: 4862, 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-04-14T23:31:02.551544Z DEBUG Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::pipeline: Starting unwind from=1347968 to=1347944 bad_block=Some(1347968)
2024-04-14T23:31:02.551562Z DEBUG Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: trie::loader: incremental state root range=1347945..=1347968
2024-04-14T23:31:02.749695Z INFO reth_node_core::events::node: Received forkchoice updated message when syncing head_block_hash=0x4e221b3e7a9280d2e3e8e464150d54e63d04f4119e7072b373988bd5db07a59e safe_block_hash=0x2198e29036aab109a2c2ed4d536ced836afd0f9353f844a9d39fcf62994704e5 finalized_block_hash=0x8d457ec320dd9eb3c7be0ca55b0d227d0680bbe53076e2b7b0a910e3c933a50f
2024-04-14T23:31:02.846313Z WARN Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::stages::merkle: Failed to verify block state root target_block=1347944 got=0xd0dd1d687b5905b40e8bdddd6a0c1ecb33de07d74c821d24d61a7ece53e7b5ae expected=SealedHeader { hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, header: Header { parent_hash: 0x9378e27ff4b30650e8e561d3a954c8b1afb1720dca999cbf57a0c7d9c1e33a6c, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x942a3c0644ed50e3fbc1136f7bffdc505306bde0, state_root: 0xd01ad853ea1a1cc46eaee8d4a72dd46fffc912568dce5a0a9b66eef3af2b4576, transactions_root: 0x5949e0f8a6a9cdb92b863493f423dca1fc5ef8f99c6f8795a0fe3c911ec5c938, receipts_root: 0x92ed0214a8df3cb2070ffe7a231e548cedeedf211e5d96ded41fb0f1b66e5d16, withdrawals_root: Some(0x9bb70698fb705cdb948c74a1a5d5f346f334baeb5b5afb22571be2d78ad7054a), logs_bloom: 0x0002000a48480040208005864000153042a10801040464910e020220007072c36028138040200a00202424a00822408801020001901310068864b58280280f456022820a0065014060000809140000c409088050030401220814301b2489425158160506036010404500008528800c404800c0400818413008492010002040818100000001021810050903418840081a100c221408808210000500850000048193008c080465d02021a8061285830400280a1008c00641049031880680800c80000912c20410005040480000f08485120028001284286a08628ad0040200b81000501048100201102008459240088001b8353000806235081201000211c04534, difficulty: 0x0_U256, number: 1347944, gas_limit: 30000000, gas_used: 10051505, timestamp: 1713136032, mix_hash: 0xc7f8b6cc90b59bfc9da7d11884a7460495b75546c39032a787a55855ba3681dd, nonce: 0, base_fee_per_gas: Some(2807217650), blob_gas_used: Some(786432), excess_blob_gas: Some(79167488), parent_beacon_block_root: Some(0xc3e6acf8bc5c151afe191348a7ccd8624d433c1e94f8a51a6ad7c64463db7f7a), extra_data: 0x4e65746865726d696e64 } }
2024-04-14T23:31:02.847475Z ERROR reth::cli: shutting down due to error
2024-04-14T23:31:08.160225Z INFO reth::cli: Starting reth version="0.2.0-beta.5-dev (cd1c2bf99)"
2024-04-14T23:31:08.160860Z INFO reth::cli: Opening database path="/home/kendall/eth2-data/reth/holesky/db"
2024-04-14T23:31:08.202257Z INFO reth::cli: Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
2024-04-14T23:31:08.203377Z INFO reth::cli: Database opened
2024-04-14T23:31:08.203385Z INFO reth::cli: Starting metrics endpoint addr=0.0.0.0:9001
2024-04-14T23:31:08.203457Z DEBUG reth::cli: Initializing genesis chain=holesky genesis=0xb5f7f912443c940f21fd611f12828d75b534364ed9e95ca4e307729a4661bde4
2024-04-14T23:31:08.203527Z DEBUG reth_node_core::init: Genesis already written, skipping.
2024-04-14T23:31:08.203556Z INFO reth::cli:
Pre-merge hard forks (block based):
- Frontier @0
- Homestead @0
- Dao @0
- Tangerine @0And that continued until I manually stopped EL and CL:
2024-04-15T04:07:58.909266Z WARN Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::stages::merkle: Failed to verify block state root target_block=1347944 got=0xd0dd1d687b5905b40e8bdddd6a0c1ecb33de07d74c821d24d61a7ece53e7b5ae expected=SealedHeader { hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, header: Header { parent_hash: 0x9378e27ff4b30650e8e561d3a954c8b1afb1720dca999cbf57a0c7d9c1e33a6c, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x942a3c0644ed50e3fbc1136f7bffdc505306bde0, state_root: 0xd01ad853ea1a1cc46eaee8d4a72dd46fffc912568dce5a0a9b66eef3af2b4576, transactions_root: 0x5949e0f8a6a9cdb92b863493f423dca1fc5ef8f99c6f8795a0fe3c911ec5c938, receipts_root: 0x92ed0214a8df3cb2070ffe7a231e548cedeedf211e5d96ded41fb0f1b66e5d16, withdrawals_root: Some(0x9bb70698fb705cdb948c74a1a5d5f346f334baeb5b5afb22571be2d78ad7054a), logs_bloom: 0x0002000a48480040208005864000153042a10801040464910e020220007072c36028138040200a00202424a00822408801020001901310068864b58280280f456022820a0065014060000809140000c409088050030401220814301b2489425158160506036010404500008528800c404800c0400818413008492010002040818100000001021810050903418840081a100c221408808210000500850000048193008c080465d02021a8061285830400280a1008c00641049031880680800c80000912c20410005040480000f08485120028001284286a08628ad0040200b81000501048100201102008459240088001b8353000806235081201000211c04534, difficulty: 0x0_U256, number: 1347944, gas_limit: 30000000, gas_used: 10051505, timestamp: 1713136032, mix_hash: 0xc7f8b6cc90b59bfc9da7d11884a7460495b75546c39032a787a55855ba3681dd, nonce: 0, base_fee_per_gas: Some(2807217650), blob_gas_used: Some(786432), excess_blob_gas: Some(79167488), parent_beacon_block_root: Some(0xc3e6acf8bc5c151afe191348a7ccd8624d433c1e94f8a51a6ad7c64463db7f7a), extra_data: 0x4e65746865726d696e64 } }
2024-04-15T04:07:58.910802Z ERROR reth::cli: shutting down due to error
2024-04-15T04:08:04.194790Z INFO reth::cli: Starting reth version="0.2.0-beta.5-dev (cd1c2bf99)"
2024-04-15T04:08:04.218781Z INFO reth::cli: Opening database path="/home/kendall/eth2-data/reth/holesky/db"
2024-04-15T04:08:04.311840Z INFO reth::cli: Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
2024-04-15T04:08:04.337892Z INFO reth::cli: Database opened
2024-04-15T04:08:04.337922Z INFO reth::cli: Starting metrics endpoint addr=0.0.0.0:9001
2024-04-15T04:08:04.338049Z DEBUG reth::cli: Initializing genesis chain=holesky genesis=0xb5f7f912443c940f21fd611f12828d75b534364ed9e95ca4e307729a4661bde4
2024-04-15T04:08:04.338174Z DEBUG reth_node_core::init: Genesis already written, skipping.
2024-04-15T04:08:04.338228Z INFO reth::cli:
Pre-merge hard forks (block based):
- Frontier @0
- Homestead @0
- Dao @0
- Tangerine @0
- SpuriousDragon @0
- Byzantium @0
- Constantinople @0
- Petersburg @0
- Istanbul @0
- MuirGlacier @0
- Berlin @0
- London @0
Merge hard forks:
- Paris @0 (network is known to be merged)
Post-merge hard forks (timestamp based):
- Shanghai @1696000704
- Cancun @1707305664
2024-04-15T04:08:04.338249Z DEBUG reth::cli: Spawning stages metrics listener task
2024-04-15T04:08:04.338812Z DEBUG reth::cli: configured blockchain tree
2024-04-15T04:08:04.340505Z DEBUG reth::cli: creating components
2024-04-15T04:08:04.340671Z DEBUG txpool::blob: Removed blob store directory blob_dir="/home/kendall/eth2-data/reth/holesky/blobstore"
2024-04-15T04:08:04.340679Z DEBUG txpool::blob: Creating blob store blob_dir="/home/kendall/eth2-data/reth/holesky/blobstore"
2024-04-15T04:08:04.503106Z INFO reth::cli: Transaction pool initialized
2024-04-15T04:08:04.503129Z DEBUG reth::cli: Spawned txpool maintenance task
2024-04-15T04:08:04.503149Z INFO reth::cli: Connecting to P2P network
2024-04-15T04:08:04.503153Z DEBUG reth::cli: Loading p2p key file network_secret_path="/home/kendall/eth2-data/reth/holesky/discovery-secret"
2024-04-15T04:08:04.503277Z INFO net::peers: Loading saved peers file=/home/kendall/eth2-data/reth/holesky/known-peers.json
2024-04-15T04:08:04.505257Z DEBUG reth::cli: calling on_component_initialized hook
2024-04-15T04:08:04.505746Z DEBUG discv4: pinging boot node record=NodeRecord { address: 178.128.136.233, tcp_port: 30303, udp_port: 30303, id: 0xa3435a0155a3e837c02f5e7f5662a2f1fbc25b48e4dc232016e1c51b544cb5b4510ef633ea3278c0e970fa8ad8141e2d4d0f9f95456c537ff05fdf9b31c15072 }
2024-04-15T04:08:04.505852Z DEBUG discv4: pinging boot node record=NodeRecord { address: 146.190.13.128, tcp_port: 30303, udp_port: 30303, id: 0xac906289e4b7f12df423d654c5a962b6ebe5b3a74cc9e06292a85221f9a64a6f1cfdd6b714ed6dacef51578f92b34c60ee91e9ede9c7f8fadc4d347326d95e2b }
2024-04-15T04:08:04.506291Z INFO reth::cli: StaticFileProducer initialized
2024-04-15T04:08:04.506431Z INFO reth::cli: Pruner initialized prune_config=PruneConfig { block_interval: 5, segments: PruneModes { sender_recovery: Some(Full), transaction_lookup: None, receipts: Some(Before(0)), account_history: Some(Distance(10064)), storage_history: Some(Distance(10064)), receipts_log_filter: ReceiptsLogPruneConfig({0x4242424242424242424242424242424242424242: Before(0)}) } }
2024-04-15T04:08:04.506511Z DEBUG consensus::engine: Pipeline sync progress is inconsistent first_stage_checkpoint=1347968 inconsistent_stage_id=AccountHashing inconsistent_stage_checkpoint=1347944
2024-04-15T04:08:04.506532Z INFO reth::cli: Consensus engine initialized
2024-04-15T04:08:04.506577Z INFO reth::cli: Engine API handler initialized
2024-04-15T04:08:04.506581Z DEBUG reth::cli: Reading JWT auth secret file user_path="/home/kendall/eth2-data/secrets/jwtsecret"
2024-04-15T04:08:04.506684Z DEBUG reth::cli: Using RPC module config http=Some(Selection([Admin, Eth, Web3, Net])) ws=Some(Selection([Eth, Net, Web3]))
2024-04-15T04:08:04.508691Z INFO reth::cli: RPC auth server started url=127.0.0.1:8551
2024-04-15T04:08:04.508933Z DEBUG discv4: pinging boot node record=NodeRecord { address: 178.128.136.233, tcp_port: 30303, udp_port: 30303, id: 0xa3435a0155a3e837c02f5e7f5662a2f1fbc25b48e4dc232016e1c51b544cb5b4510ef633ea3278c0e970fa8ad8141e2d4d0f9f95456c537ff05fdf9b31c15072 }
2024-04-15T04:08:04.508990Z DEBUG discv4: pinging boot node record=NodeRecord { address: 146.190.13.128, tcp_port: 30303, udp_port: 30303, id: 0xac906289e4b7f12df423d654c5a962b6ebe5b3a74cc9e06292a85221f9a64a6f1cfdd6b714ed6dacef51578f92b34c60ee91e9ede9c7f8fadc4d347326d95e2b }
2024-04-15T04:08:04.509036Z DEBUG igd_next::aio::tokio: sending broadcast request to: 239.255.255.250:1900 on interface: Ok(0.0.0.0:43516)
2024-04-15T04:08:04.509201Z INFO reth::cli: RPC IPC server started url=/tmp/reth.ipc
2024-04-15T04:08:04.509209Z INFO reth::cli: RPC HTTP server started url=0.0.0.0:8545
2024-04-15T04:08:04.509215Z INFO reth::cli: RPC WS server started url=127.0.0.1:8546
2024-04-15T04:08:04.509227Z INFO reth::cli: Starting consensus engine
2024-04-15T04:08:04.534959Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"
2024-04-15T04:08:04.539461Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=1/12 stage=Headers checkpoint=1347968 target=None
2024-04-15T04:08:04.539548Z INFO sync::stages::headers: Target block already reached checkpoint=1347968 target=Hash(0x8d457ec320dd9eb3c7be0ca55b0d227d0680bbe53076e2b7b0a910e3c933a50f)
2024-04-15T04:08:04.539585Z INFO reth_node_core::events::node: Executing stage pipeline_stages=1/12 stage=Headers checkpoint=1347968 target=None
2024-04-15T04:08:04.545496Z INFO reth_node_core::events::node: Finished stage pipeline_stages=1/12 stage=Headers checkpoint=1347968 target=None stage_progress=100.00%
2024-04-15T04:08:04.550715Z DEBUG storage::db::mdbx: Commit total_duration=5.163692ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-15T04:08:04.550840Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=2/12 stage=Bodies checkpoint=1347968 target=1347968
2024-04-15T04:08:04.550882Z INFO reth_node_core::events::node: Executing stage pipeline_stages=2/12 stage=Bodies checkpoint=1347968 target=1347968
2024-04-15T04:08:04.552076Z DEBUG disc::dns: Failed to lookup entry err=invalid child hash in branch: domain=all.holesky.ethdisco.net hash="FDXN3SN67NA5DKA4J2GOK7BVQI"
2024-04-15T04:08:04.553626Z INFO reth_node_core::events::node: Finished stage pipeline_stages=2/12 stage=Bodies checkpoint=1347968 target=1347968 stage_progress=100.00%
2024-04-15T04:08:04.553691Z DEBUG storage::db::mdbx: Commit total_duration=42.855µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-15T04:08:04.553742Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=3/12 stage=SenderRecovery checkpoint=1347968 target=1347968
2024-04-15T04:08:04.553778Z INFO reth_node_core::events::node: Executing stage pipeline_stages=3/12 stage=SenderRecovery checkpoint=1347968 target=1347968
2024-04-15T04:08:04.553904Z INFO reth_node_core::events::node: Finished stage pipeline_stages=3/12 stage=SenderRecovery checkpoint=1347968 target=1347968 stage_progress=99.99%
2024-04-15T04:08:04.553965Z DEBUG storage::db::mdbx: Commit total_duration=42.709µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-15T04:08:04.554010Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=4/12 stage=Execution checkpoint=1347968 target=1347968
2024-04-15T04:08:04.554040Z INFO reth_node_core::events::node: Executing stage pipeline_stages=4/12 stage=Execution checkpoint=1347968 target=1347968
2024-04-15T04:08:04.554147Z INFO reth_node_core::events::node: Finished stage pipeline_stages=4/12 stage=Execution checkpoint=1347968 target=1347968 stage_progress=100.00%
2024-04-15T04:08:04.554200Z DEBUG storage::db::mdbx: Commit total_duration=31.576µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-15T04:08:04.554243Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=5/12 stage=MerkleUnwind checkpoint=1347968 target=1347968
2024-04-15T04:08:04.554274Z INFO reth_node_core::events::node: Executing stage pipeline_stages=5/12 stage=MerkleUnwind checkpoint=1347968 target=1347968
2024-04-15T04:08:04.554345Z INFO sync::stages::merkle::unwind: Stage is always skipped
2024-04-15T04:08:04.554388Z INFO reth_node_core::events::node: Finished stage pipeline_stages=5/12 stage=MerkleUnwind checkpoint=1347968 target=1347968
2024-04-15T04:08:04.554448Z DEBUG storage::db::mdbx: Commit total_duration=39.72µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-15T04:08:04.554495Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=6/12 stage=AccountHashing checkpoint=1347944 target=1347968
2024-04-15T04:08:04.554526Z INFO reth_node_core::events::node: Executing stage pipeline_stages=6/12 stage=AccountHashing checkpoint=1347944 target=1347968
2024-04-15T04:08:04.628341Z INFO reth_node_core::events::node: Finished stage pipeline_stages=6/12 stage=AccountHashing checkpoint=1347968 target=1347968 stage_progress=100.00%
2024-04-15T04:08:04.738409Z DEBUG storage::db::mdbx: Commit total_duration=110.031148ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 8, audit: 0, write: 0, sync: 6675, ending: 0, whole: 6684, 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-04-15T04:08:04.738517Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1347944 target=1347968
2024-04-15T04:08:04.738568Z INFO reth_node_core::events::node: Executing stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1347944 target=1347968
2024-04-15T04:08:04.841253Z INFO reth_node_core::events::node: Finished stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1347968 target=1347968 stage_progress=100.00%
2024-04-15T04:08:04.990317Z DEBUG storage::db::mdbx: Commit total_duration=149.02702ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 15, audit: 0, write: 0, sync: 9224, ending: 0, whole: 9239, 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-04-15T04:08:04.990423Z INFO reth_node_core::events::node: Preparing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1347944 target=1347968
2024-04-15T04:08:04.990470Z INFO reth_node_core::events::node: Executing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1347944 target=1347968
2024-04-15T04:08:04.990534Z DEBUG sync::stages::merkle::exec: Updating trie current=1347944 target=1347968
2024-04-15T04:08:04.990554Z DEBUG trie::loader: incremental state root range=1347945..=1347968
2024-04-15T04:08:05.789365Z WARN sync::stages::merkle: Failed to verify block state root target_block=1347968 got=0xe87da9fa2117d2479c121daeb04b01c8be5c0f5ec7e9434571a0b156e6a7048d expected=SealedHeader { hash: 0x8d457ec320dd9eb3c7be0ca55b0d227d0680bbe53076e2b7b0a910e3c933a50f, header: Header { parent_hash: 0xf233c10ab77755d9b81a91a38240ce38bdebe19ca12a09d6e5a4f6f7fe4cb52b, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x8668b0181b08037079b5c05d53c51361e5b8bd7c, state_root: 0x32b03893c8f80d977556622605c8a5fd4cae36edb98e229dfe4107b4f00b25c0, transactions_root: 0xb3eff2c04b05b07fcf6f89e8ce63a17df9684ff70e37324e07cd3f6c388507d7, receipts_root: 0x4129317a458629f545d09391c07af791a524bfd8bbd8b8248b7e342617e68c1e, withdrawals_root: Some(0x2383c79d88357dcf09c17c7e5f9077c384b697d11b7b98ef1fc6e8b7bc46378a), logs_bloom: 0x0429000008083820000089100005120070410022060ac210048302a4441044080089491510200000944426c804e80200100038259347042860a41104202d1900300843d2802042d40005400bb440802409271822800401206004221b08d12100040e42100a040008200482423018090820805a000a0842300042409020a204c0008062490020400048801841002000cc02c1e4001804400428101211000004200300cc020001040230220801850f0c08a20a10004444402010000026006c828c433820820020150108001020804205001181085a22410008049b14022100e014001040440210041830180510c00841829c058468880023484052000230800500, difficulty: 0x0_U256, number: 1347968, gas_limit: 30000000, gas_used: 16934330, timestamp: 1713136320, mix_hash: 0x31a95cf04136b4cac1391059b30ef5fadcbcae51a36dbe0765b1bdd7d4be1b93, nonce: 0, base_fee_per_gas: Some(2236729849), blob_gas_used: Some(131072), excess_blob_gas: Some(79560704), parent_beacon_block_root: Some(0xc4de1633830f5c99d232378c8b37b51fe408060b4468fee6484ac8be8c1c950c), extra_data: 0x706170696368756c6f } }
2024-04-15T04:08:05.789443Z ERROR sync::pipeline: Stage encountered a validation error: mismatched block state root: got 0xe87da9fa2117d2479c121daeb04b01c8be5c0f5ec7e9434571a0b156e6a7048d, expected 0x32b03893c8f80d977556622605c8a5fd4cae36edb98e229dfe4107b4f00b25c0 stage=MerkleExecute bad_block=1347968
2024-04-15T04:08:05.789547Z DEBUG storage::db::mdbx: Commit total_duration=17.357µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-15T04:08:05.789601Z DEBUG Unwinding{[3mstage[0m[2m=[0mFinish}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-15T04:08:05.789613Z DEBUG Unwinding{[3mstage[0m[2m=[0mIndexAccountHistory}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-15T04:08:05.789617Z DEBUG Unwinding{[3mstage[0m[2m=[0mIndexStorageHistory}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-15T04:08:05.789621Z DEBUG Unwinding{[3mstage[0m[2m=[0mTransactionLookup}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-15T04:08:05.789624Z DEBUG Unwinding{[3mstage[0m[2m=[0mMerkleExecute}: sync::pipeline: Starting unwind from=1347944 to=1347944 bad_block=Some(1347968)
2024-04-15T04:08:05.789628Z DEBUG Unwinding{[3mstage[0m[2m=[0mStorageHashing}: sync::pipeline: Starting unwind from=1347968 to=1347944 bad_block=Some(1347968)
2024-04-15T04:08:05.828254Z INFO Unwinding{[3mstage[0m[2m=[0mStorageHashing}: sync::pipeline: Stage unwound stage=StorageHashing unwind_to=1347944 progress=1347944 done=true
2024-04-15T04:08:06.184898Z DEBUG Unwinding{[3mstage[0m[2m=[0mStorageHashing}: storage::db::mdbx: Commit total_duration=356.610415ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 9, audit: 0, write: 0, sync: 23356, ending: 0, whole: 23366, 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-04-15T04:08:06.184970Z DEBUG Unwinding{[3mstage[0m[2m=[0mAccountHashing}: sync::pipeline: Starting unwind from=1347968 to=1347944 bad_block=Some(1347968)
2024-04-15T04:08:06.208125Z INFO Unwinding{[3mstage[0m[2m=[0mAccountHashing}: sync::pipeline: Stage unwound stage=AccountHashing unwind_to=1347944 progress=1347944 done=true
2024-04-15T04:08:06.282679Z DEBUG Unwinding{[3mstage[0m[2m=[0mAccountHashing}: storage::db::mdbx: Commit total_duration=74.517682ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 6, audit: 0, write: 0, sync: 4872, ending: 0, whole: 4879, 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-04-15T04:08:06.282816Z DEBUG Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::pipeline: Starting unwind from=1347968 to=1347944 bad_block=Some(1347968)
2024-04-15T04:08:06.282833Z DEBUG Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: trie::loader: incremental state root range=1347945..=1347968
2024-04-15T04:08:06.504810Z WARN Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::stages::merkle: Failed to verify block state root target_block=1347944 got=0xd0dd1d687b5905b40e8bdddd6a0c1ecb33de07d74c821d24d61a7ece53e7b5ae expected=SealedHeader { hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, header: Header { parent_hash: 0x9378e27ff4b30650e8e561d3a954c8b1afb1720dca999cbf57a0c7d9c1e33a6c, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x942a3c0644ed50e3fbc1136f7bffdc505306bde0, state_root: 0xd01ad853ea1a1cc46eaee8d4a72dd46fffc912568dce5a0a9b66eef3af2b4576, transactions_root: 0x5949e0f8a6a9cdb92b863493f423dca1fc5ef8f99c6f8795a0fe3c911ec5c938, receipts_root: 0x92ed0214a8df3cb2070ffe7a231e548cedeedf211e5d96ded41fb0f1b66e5d16, withdrawals_root: Some(0x9bb70698fb705cdb948c74a1a5d5f346f334baeb5b5afb22571be2d78ad7054a), logs_bloom: 0x0002000a48480040208005864000153042a10801040464910e020220007072c36028138040200a00202424a00822408801020001901310068864b58280280f456022820a0065014060000809140000c409088050030401220814301b2489425158160506036010404500008528800c404800c0400818413008492010002040818100000001021810050903418840081a100c221408808210000500850000048193008c080465d02021a8061285830400280a1008c00641049031880680800c80000912c20410005040480000f08485120028001284286a08628ad0040200b81000501048100201102008459240088001b8353000806235081201000211c04534, difficulty: 0x0_U256, number: 1347944, gas_limit: 30000000, gas_used: 10051505, timestamp: 1713136032, mix_hash: 0xc7f8b6cc90b59bfc9da7d11884a7460495b75546c39032a787a55855ba3681dd, nonce: 0, base_fee_per_gas: Some(2807217650), blob_gas_used: Some(786432), excess_blob_gas: Some(79167488), parent_beacon_block_root: Some(0xc3e6acf8bc5c151afe191348a7ccd8624d433c1e94f8a51a6ad7c64463db7f7a), extra_data: 0x4e65746865726d696e64 } }
2024-04-15T04:08:06.505889Z ERROR reth::cli: shutting down due to error
2024-04-15T04:31:17.867179Z INFO reth::commands::db::stats: Calculating checksum for table: CanonicalHeaders
2024-04-15T04:31:17.867275Z INFO reth::commands::db::checksum: Hashed 0 entries.
2024-04-15T04:31:17.867307Z INFO reth::commands::db::stats: Calculating checksum for table: HeaderTerminalDifficulties
2024-04-15T04:31:17.867331Z INFO reth::commands::db::checksum: Hashed 0 entries.
2024-04-15T04:31:17.867344Z INFO reth::commands::db::stats: Calculating checksum for table: HeaderNumbers
2024-04-15T04:31:17.867920Z INFO reth::commands::db::checksum: Hashed 0 entries.
2024-04-15T04:31:18.265298Z INFO reth::commands::db::checksum: Hashed 100000 entries.
2024-04-15T04:31:18.654737Z INFO reth::commands::db::checksum: Hashed 200000 entries.
2024-04-15T04:31:19.042902Z INFO reth::commands::db::checksum: Hashed 300000 entries.
2024-04-15T04:31:19.421433Z INFO reth::commands::db::checksum: Hashed 400000 entries.
2024-04-15T04:31:19.799381Z INFO reth::commands::db::checksum: Hashed 500000 entries.
2024-04-15T04:31:20.176105Z INFO reth::commands::db::checksum: Hashed 600000 entries.
2024-04-15T04:31:20.571049Z INFO reth::commands::db::checksum: Hashed 700000 entries.Here are the logs for reth-issue-7430.2024-04-15. Here is a shu256sum of the above tar.gz file.
Finally here is the --checksum:
2024-04-15T04:48:54.037172Z INFO Calculating checksum for table: TransactionSenders
2024-04-15T04:48:54.037405Z INFO Hashed 0 entries.
2024-04-15T04:48:54.037857Z INFO Calculating checksum for table: StageCheckpoints
2024-04-15T04:48:54.037869Z INFO Hashed 0 entries.
2024-04-15T04:48:54.037875Z INFO Calculating checksum for table: StageCheckpointProgresses
2024-04-15T04:48:54.037881Z INFO Hashed 0 entries.
2024-04-15T04:48:54.037885Z INFO Calculating checksum for table: PruneCheckpoints
2024-04-15T04:48:54.037891Z INFO Hashed 0 entries.
2024-04-15T04:48:54.037895Z INFO Calculating checksum for table: VersionHistory
2024-04-15T04:48:54.038096Z INFO Hashed 0 entries.
| Table | Checksum | Elapsed |
|----------------------------|------------------|-----------------|
| CanonicalHeaders | 4c1ea4e80d047850 | 30.706µs |
| HeaderTerminalDifficulties | 171f11aa213c31c3 | 16.765µs |
| HeaderNumbers | 61e192235f44094e | 5.264605596s |
| Headers | 5efd255180ad7cad | 730.562µs |
| BlockBodyIndices | b676857529f2cd83 | 1.418812608s |
| BlockOmmers | c4a662e6571c2822 | 451ns |
| BlockWithdrawals | 4c97271cfac8ca66 | 16.456802256s |
| Transactions | 92a3e3481718cd1d | 59.254157ms |
| TransactionHashNumbers | 934608dfc9e80989 | 175.704863261s |
| TransactionBlocks | 2e2c08d5d9962419 | 1.359447083s |
| Receipts | a7a2bbfa2b5cab37 | 23.32384986s |
| Bytecodes | dfff3749f17404f1 | 22.408482352s |
| PlainAccountState | 9c073f0b730bf9ed | 101.222956602s |
| PlainStorageState | f10f881275082a15 | 176.406347742s |
| AccountsHistory | 2bdd4421e91ae748 | 7.643388769s |
| StoragesHistory | 82c8b9494638c109 | 36.425433792s |
| AccountChangeSets | b55e2bb63b93fa0e | 2.695699342s |
| StorageChangeSets | 48d12da1245e6a47 | 19.5965801s |
| HashedAccounts | e00b568c42be9670 | 151.113926859s |
| HashedStorages | c0c04e969197b0f6 | 210.458380033s |
| AccountsTrie | 75acbff021d6c11e | 29.461375055s |
| StoragesTrie | 6d1df86833ba2980 | 75.138795734s |
| TransactionSenders | a8aa3266a6c1ff34 | 448.132µs |
| StageCheckpoints | 59f914f5247732d5 | 4.459µs |
| StageCheckpointProgresses | 39cdebf3977ba1de | 3.354µs |
| PruneCheckpoints | 9ef893840836d8e6 | 3.461µs |
| VersionHistory | ca2d5479de2935d0 | 7.851µs |
| -------------------------- | ---------------- | -------------- |
| Total elapsed | | 1056.160246942s |
| Segment | Block Range | Transaction Range | Shape (columns x rows) | Data Size | Index Size | Offsets Size | Config Size | Total Size |
|--------------|-------------------|---------------------|------------------------|-----------|------------|--------------|-------------|------------|
| Headers | 0..=499999 | N/A | 3 x 500000 | 163.1 MiB | 0 B | 11.4 MiB | 75 B | 174.6 MiB |
| Headers | 500000..=999999 | N/A | 3 x 500000 | 220.9 MiB | 0 B | 11.4 MiB | 75 B | 232.3 MiB |
| Headers | 1000000..=1347968 | N/A | 3 x 347969 | 193.3 MiB | 0 B | 8 MiB | 75 B | 201.2 MiB |
| Transactions | 0..=499999 | 0..=1903501 | 1 x 1903502 | 664.1 MiB | 0 B | 14.5 MiB | 87 B | 678.7 MiB |
| Transactions | 500000..=999999 | 1903502..=30681966 | 1 x 28778465 | 10.9 GiB | 0 B | 219.6 MiB | 87 B | 11.1 GiB |
| Transactions | 1000000..=1347968 | 30681967..=42680068 | 1 x 11998102 | 17.4 GiB | 0 B | 91.5 MiB | 87 B | 17.5 GiB |
| ------------ | ----------------- | ------------------- | ---------------------- | --------- | ---------- | ------------ | ----------- | ---------- |
| Total | | | | 29.5 GiB | 0 B | 356.5 MiB | 486 B | 29.9 GiB |
| Table Name | # Entries | Branch Pages | Leaf Pages | Overflow Pages | Total Size |
|----------------------------|-----------|--------------|------------|----------------|------------|
| AccountChangeSets | 886850 | 3184 | 12276 | 0 | 60.4 MiB |
| AccountsHistory | 397982 | 856 | 43755 | 101 | 174.7 MiB |
| AccountsTrie | 2315428 | 783 | 174210 | 0 | 683.6 MiB |
| BlockBodyIndices | 1347969 | 37 | 7877 | 0 | 30.9 MiB |
| BlockOmmers | 0 | 0 | 0 | 0 | 0 B |
| BlockWithdrawals | 1338314 | 855 | 191130 | 0 | 749.9 MiB |
| Bytecodes | 60004 | 50 | 3502 | 124344 | 499.6 MiB |
| CanonicalHeaders | 67 | 1 | 2 | 0 | 12 KiB |
| HashedAccounts | 30640888 | 11694 | 895438 | 0 | 3.5 GiB |
| HashedStorages | 55585338 | 23272 | 1243234 | 0 | 4.8 GiB |
| HeaderNumbers | 1347969 | 344 | 30542 | 0 | 120.6 MiB |
| HeaderTerminalDifficulties | 67 | 0 | 1 | 0 | 4 KiB |
| Headers | 67 | 1 | 12 | 0 | 52 KiB |
| PlainAccountState | 30641764 | 5684 | 575989 | 0 | 2.2 GiB |
| PlainStorageState | 55587736 | 20444 | 1010320 | 0 | 3.9 GiB |
| PruneCheckpoints | 5 | 0 | 1 | 0 | 4 KiB |
| Receipts | 2482742 | 470 | 104743 | 42156 | 575.7 MiB |
| StageCheckpointProgresses | 1 | 0 | 1 | 0 | 4 KiB |
| StageCheckpoints | 12 | 0 | 1 | 0 | 4 KiB |
| StorageChangeSets | 7589469 | 12318 | 113319 | 0 | 490.8 MiB |
| StoragesHistory | 5626146 | 6076 | 205108 | 437 | 826.6 MiB |
| StoragesTrie | 4482341 | 45847 | 408580 | 0 | 1.7 GiB |
| TransactionBlocks | 1174910 | 35 | 7532 | 0 | 29.6 MiB |
| TransactionHashNumbers | 42678810 | 13007 | 999759 | 0 | 3.9 GiB |
| TransactionSenders | 1259 | 1 | 12 | 0 | 52 KiB |
| Transactions | 3677 | 3 | 212 | 1153 | 5.3 MiB |
| VersionHistory | 1 | 0 | 1 | 0 | 4 KiB |
| -------------------------- | --------- | ------------ | ---------- | -------------- | ---------- |
| Tables | | | | | 24.2 GiB |
| Freelist | 12378 | | | | 48.4 MiB |I will not be restarting the node, so if necessary I can provide the database files.
winksaville
commented
2 months ago The stack trace was captured, it was in the system logs and I've uploaded to reth.log.journalctl.tar.gz:
$ sudo journalctl -u reth.panic-on-insertblockerror.service > reth.log.journalctl
[sudo] password for kendall:
kendall@ethel 24-04-15T13:44:12.154Z:~/reth-lighthouse-issues/reth-issue-7430.2024-04-15/rethAnd here are the first two stack traces:
Apr 14 16:06:53 ethel reth.panic-on-insertblockerror[284376]: 2024-04-14T23:06:53.215353Z INFO Canonical chain committed number=1347942 hash=0x38b2f4648990de830699f6c671a67f0f3d959dcc5b9466a79c88d106bf325adc elapsed=541.861593ms
Apr 14 16:07:02 ethel reth.panic-on-insertblockerror[284376]: 2024-04-14T23:07:02.330563Z INFO Block added to canonical chain number=1347943 hash=0x9378e27ff4b30650e8e561d3a954c8b1afb1720dca999cbf57a0c7d9c1e33a6c peers=16 txs=87 mgas=19.071 full=63.6% base_fee=2.72gwei blobs=5 excess_blobs=602 elapsed=234.497971ms
Apr 14 16:07:02 ethel reth.panic-on-insertblockerror[284376]: 2024-04-14T23:07:02.330711Z INFO Pruner started tip_block_number=1347942
Apr 14 16:07:02 ethel reth.panic-on-insertblockerror[284376]: 2024-04-14T23:07:02.487211Z INFO Pruner finished tip_block_number=1347942 elapsed=156.369661ms stats={AccountHistory: (Finished, 249)}
Apr 14 16:07:02 ethel reth.panic-on-insertblockerror[284376]: 2024-04-14T23:07:02.872524Z INFO Canonical chain committed number=1347943 hash=0x9378e27ff4b30650e8e561d3a954c8b1afb1720dca999cbf57a0c7d9c1e33a6c elapsed=241.694458ms
Apr 14 16:07:13 ethel reth.panic-on-insertblockerror[284376]: 2024-04-14T23:07:13.745224Z INFO Block added to canonical chain number=1347944 hash=0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822 peers=16 txs=59 mgas=10.052 full=33.5% base_fee=2.81gwei blobs=6 excess_blobs=604 elapsed=172.021947ms
Apr 14 16:07:14 ethel reth.panic-on-insertblockerror[284376]: 2024-04-14T23:07:14.227063Z INFO Canonical chain committed number=1347944 hash=0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822 elapsed=185.840803ms
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: thread 'tokio-runtime-worker' panicked at crates/interfaces/src/blockchain_tree/error.rs:166:9:
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: Wink: Failed to insert block, InsertBlockError { error: Consensus(BodyStateRootDiff(GotExpected { got: 0xcc20874ee3667b49a5f7d8437de617eebeee5df120760121685667962cba08e2, expected: 0x4b3e9ba36ca754c4102c666ee5c1fa4f273aa54981648e72d66bb59f13e1d76e })), hash: 0xe607ef334a988dff381bedd5e6c75139abf375baae9563b2ad691f8d1c27cef6, number: 1347945, parent_hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, num_txs: 39, .. }
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: stack backtrace:
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 0: rust_begin_unwind
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 1: core::panicking::panic_fmt
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 2: <reth_interfaces::blockchain_tree::error::InsertBlockError as core::fmt::Display>::fmt
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 3: <tracing_core::field::DisplayValue<T> as core::fmt::Debug>::fmt
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 4: core::fmt::write
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 5: <tracing_subscriber::fmt::format::DefaultVisitor as tracing_core::field::Visit>::record_debug
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 6: <tracing_subscriber::fmt::format::Format<tracing_subscriber::fmt::format::Full,T> as tracing_subscriber::fmt::format::FormatEvent<S,N>>::format_event
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 7: <tracing_subscriber::fmt::fmt_layer::Layer<S,N,E,W> as tracing_subscriber::layer::Layer<S>>::on_event
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 8: <tracing_subscriber::layer::layered::Layered<L,S> as tracing_core::subscriber::Subscriber>::event
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 9: reth_beacon_consensus::engine::BeaconConsensusEngine<DB,BT,Client,EngineT>::on_new_payload::{{closure}}
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 10: <reth_beacon_consensus::engine::BeaconConsensusEngine<DB,BT,Client,EngineT> as core::future::future::Future>::poll
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 11: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::future::future::Future>::poll
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 12: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 13: <tracing_futures::Instrumented<T> as core::future::future::Future>::poll
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 14: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 15: tokio::runtime::context::blocking::BlockingRegionGuard::block_on
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 16: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 17: tokio::runtime::task::core::Core<T,S>::poll
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 18: tokio::runtime::task::harness::Harness<T,S>::poll
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 19: tokio::runtime::blocking::pool::Inner::run
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 2024-04-14T23:07:28.085053Z WARN Error while processing payload error=2024-04-14T23:07:28.186575Z ERROR Critical task `consensus engine` panicked: `Wink: Failed to insert block, InsertBlockError { error: Consensus(BodyStateRootDiff(GotExpected { got: 0xcc20874ee3667b49a5f7d8437de617eebeee5df120760121685667962cba08e2, expected: 0x4b3e9ba36ca754c4102c666ee5c1fa4f273aa54981648e72d66bb59f13e1d76e })), hash: 0xe607ef334a988dff381bedd5e6c75139abf375baae9563b2ad691f8d1c27cef6, number: 1347945, parent_hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, num_txs: 39, .. }`
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: 2024-04-14T23:07:28.189201Z ERROR shutting down due to error
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: shutting down due to error
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: Error: channel closed
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: Location:
Apr 14 16:07:28 ethel reth.panic-on-insertblockerror[284376]: /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/convert/mod.rs:757:9
Apr 14 16:07:28 ethel systemd[1]: reth.panic-on-insertblockerror.service: Main process exited, code=exited, status=1/FAILURE
Apr 14 16:07:28 ethel systemd[1]: reth.panic-on-insertblockerror.service: Failed with result 'exit-code'.
Apr 14 16:07:28 ethel systemd[1]: reth.panic-on-insertblockerror.service: Consumed 15h 13min 21.561s CPU time.
Apr 14 16:07:31 ethel systemd[1]: reth.panic-on-insertblockerror.service: Scheduled restart job, restart counter is at 3.
Apr 14 16:07:31 ethel systemd[1]: Stopped reth eth2 service.
Apr 14 16:07:31 ethel systemd[1]: reth.panic-on-insertblockerror.service: Consumed 15h 13min 21.561s CPU time.
Apr 14 16:07:31 ethel systemd[1]: Starting reth eth2 service...
Apr 14 16:07:33 ethel systemd[1]: Started reth eth2 service.
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.715129Z INFO Starting reth version="0.2.0-beta.5-dev (cd1c2bf99)"
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.715800Z INFO Opening database path="/home/kendall/eth2-data/reth/holesky/db"
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.741534Z INFO Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.744048Z INFO Database opened
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.744067Z INFO Starting metrics endpoint addr=0.0.0.0:9001
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.744808Z INFO
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: Pre-merge hard forks (block based):
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Frontier @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Homestead @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Dao @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Tangerine @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - SpuriousDragon @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Byzantium @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Constantinople @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Petersburg @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Istanbul @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - MuirGlacier @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Berlin @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - London @0
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: Merge hard forks:
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Paris @0 (network is known to be merged)
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: Post-merge hard forks (timestamp based):
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Shanghai @1696000704
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: - Cancun @1707305664
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.814652Z INFO Transaction pool initialized
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.814687Z INFO Connecting to P2P network
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.818656Z INFO Loading saved peers file=/home/kendall/eth2-data/reth/holesky/known-peers.json
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.827435Z INFO StaticFileProducer initialized
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.828526Z INFO Pruner initialized prune_config=PruneConfig { block_interval: 5, segments: PruneModes { sender_recovery: Some(Full), transaction_lookup: None, receipts: Some(Before(0)), account_history: Some(Distance(10064)), storage_history: Some(Distance(10064)), receipts_log_filter: ReceiptsLogPruneConfig({0x4242424242424242424242424242424242424242: Before(0)}) } }
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.829283Z INFO Consensus engine initialized
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.829345Z INFO Engine API handler initialized
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.833742Z INFO RPC auth server started url=127.0.0.1:8551
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.833787Z INFO RPC IPC server started url=/tmp/reth.ipc
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.833796Z INFO RPC HTTP server started url=0.0.0.0:8545
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.833802Z INFO RPC WS server started url=127.0.0.1:8546
Apr 14 16:07:33 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:33.833813Z INFO Starting consensus engine
Apr 14 16:07:36 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:36.830822Z INFO Status connected_peers=0 freelist=12127 latest_block=1347944
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: thread 'tokio-runtime-worker' panicked at crates/interfaces/src/blockchain_tree/error.rs:166:9:
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: Wink: Failed to insert block, InsertBlockError { error: Consensus(BodyStateRootDiff(GotExpected { got: 0xcc20874ee3667b49a5f7d8437de617eebeee5df120760121685667962cba08e2, expected: 0x4b3e9ba36ca754c4102c666ee5c1fa4f273aa54981648e72d66bb59f13e1d76e })), hash: 0xe607ef334a988dff381bedd5e6c75139abf375baae9563b2ad691f8d1c27cef6, number: 1347945, parent_hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, num_txs: 39, .. }
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: stack backtrace:
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 0: rust_begin_unwind
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 1: core::panicking::panic_fmt
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 2: <reth_interfaces::blockchain_tree::error::InsertBlockError as core::fmt::Display>::fmt
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 3: <tracing_core::field::DisplayValue<T> as core::fmt::Debug>::fmt
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 4: core::fmt::write
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 5: <tracing_subscriber::fmt::format::DefaultVisitor as tracing_core::field::Visit>::record_debug
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 6: <tracing_subscriber::fmt::format::Format<tracing_subscriber::fmt::format::Full,T> as tracing_subscriber::fmt::format::FormatEvent<S,N>>::format_event
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 7: <tracing_subscriber::fmt::fmt_layer::Layer<S,N,E,W> as tracing_subscriber::layer::Layer<S>>::on_event
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 8: <tracing_subscriber::layer::layered::Layered<L,S> as tracing_core::subscriber::Subscriber>::event
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 9: reth_beacon_consensus::engine::BeaconConsensusEngine<DB,BT,Client,EngineT>::on_new_payload::{{closure}}
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 10: <reth_beacon_consensus::engine::BeaconConsensusEngine<DB,BT,Client,EngineT> as core::future::future::Future>::poll
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 11: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::future::future::Future>::poll
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 12: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 13: <tracing_futures::Instrumented<T> as core::future::future::Future>::poll
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 14: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 15: tokio::runtime::context::blocking::BlockingRegionGuard::block_on
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 16: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 17: tokio::runtime::task::core::Core<T,S>::poll
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 18: tokio::runtime::task::harness::Harness<T,S>::poll
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 19: tokio::runtime::blocking::pool::Inner::run
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:42.510824Z WARN Error while processing payload error=2024-04-14T23:07:42.585535Z ERROR Critical task `consensus engine` panicked: `Wink: Failed to insert block, InsertBlockError { error: Consensus(BodyStateRootDiff(GotExpected { got: 0xcc20874ee3667b49a5f7d8437de617eebeee5df120760121685667962cba08e2, expected: 0x4b3e9ba36ca754c4102c666ee5c1fa4f273aa54981648e72d66bb59f13e1d76e })), hash: 0xe607ef334a988dff381bedd5e6c75139abf375baae9563b2ad691f8d1c27cef6, number: 1347945, parent_hash: 0x1898bc1d8c13ecd936b0e59257ae849dba9da88acef5b15731ad508733cdc822, num_txs: 39, .. }`
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: 2024-04-14T23:07:42.585586Z ERROR shutting down due to error
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: shutting down due to error
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: Error: channel closed
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: Location:
Apr 14 16:07:42 ethel reth.panic-on-insertblockerror[379547]: /rustc/07dca489ac2d933c78d3c5158e3f43beefeb02ce/library/core/src/convert/mod.rs:757:9
Apr 14 16:07:42 ethel systemd[1]: reth.panic-on-insertblockerror.service: Main process exited, code=exited, status=1/FAILURE
Apr 14 16:07:42 ethel systemd[1]: reth.panic-on-insertblockerror.service: Failed with result 'exit-code'.
Apr 14 16:07:42 ethel systemd[1]: reth.panic-on-insertblockerror.service: Consumed 2.202s CPU time.
Apr 14 16:07:45 ethel systemd[1]: reth.panic-on-insertblockerror.service: Scheduled restart job, restart counter is at 4.
Apr 14 16:07:45 ethel systemd[1]: Stopped reth eth2 service.
Apr 14 16:07:45 ethel systemd[1]: reth.panic-on-insertblockerror.service: Consumed 2.202s CPU time.
Apr 14 16:07:45 ethel systemd[1]: Starting reth eth2 service...
Apr 14 16:07:47 ethel systemd[1]: Started reth eth2 service.
Apr 14 16:07:47 ethel reth.panic-on-insertblockerror[379579]: 2024-04-14T23:07:47.957937Z INFO Starting reth version="0.2.0-beta.5-dev (cd1c2bf99)"
Apr 14 16:07:48 ethel reth.panic-on-insertblockerror[379579]: 2024-04-14T23:07:48.058759Z INFO Opening database path="/home/kendall/eth2-data/reth/holesky/db"Uploaded reth-issue-7340.2024-04-15.database the contents of that directory are:
$ ls -lh
total 58G
-rw-r--r-- 1 wink users 29G Apr 15 13:50 db.tar
-rw-r--r-- 1 wink users 73 Apr 15 14:28 db.tar.sha256sum
-rw-r--r-- 1 wink users 30G Apr 15 13:55 static_files.tar
-rw-r--r-- 1 wink users 83 Apr 15 14:33 static_files.tar.sha256sum
gakonst
commented
2 months ago Fixed in #7753.
winksaville
commented
2 months ago The "state root" problem occurred again on my holesky node, Ethel. The links are to db & logs tar file [1] and sha256sum [2].
[1] https://drive.google.com/file/d/19OVLAnypj0Pif59e74vJtClaF0UKCVNX/view?usp=drive_link [2] https://drive.google.com/file/d/11aVzslUgBVOeQW3w9PJaxMX9Wp9Gujdm/view?usp=drive_link
In reth.log.1 here is the first ERROR:
2024-04-25T05:31:04.427510Z ERROR sync::pipeline: Stage encountered a validation error: mismatched block state root: got 0x2ee674c65266e5124e85f5a62642e2451d3bdfff629d1f166de531f9fc2a079d, expected 0xfd8a69059b6db1818baf48d8be521c22ec9fb3f687a298094ab2d824929461ec stage=MerkleExecute bad_block=1414478The first shutdown and reboot, note the node is running beta6
2024-04-25T05:31:10.709226Z INFO reth::cli: Starting reth version="0.2.0-beta.6-dev (ac29b4b73)"
2024-04-25T05:31:04.427510Z ERROR sync::pipeline: Stage encountered a validation error: mismatched block state root: got 0x2ee674c65266e5124e85f5a62642e2451d3bdfff629d1f166de531f9fc2a079d, expected 0xfd8a69059b6db1818baf48d8be521c22ec9fb3f687a298094ab2d824929461ec stage=MerkleExecute bad_block=1414478
2024-04-25T05:31:04.431634Z DEBUG provider::static_file: Commit segment=Headers path="/home/kendall/eth2-data/reth/holesky/static_files/static_file_headers_1000000_1499999" duration=4.043746ms
2024-04-25T05:31:04.436691Z DEBUG provider::static_file: Commit segment=Transactions path="/home/kendall/eth2-data/reth/holesky/static_files/static_file_transactions_1000000_1499999" duration=4.929643ms
2024-04-25T05:31:04.436849Z DEBUG storage::db::mdbx: Commit total_duration=21.156µs commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 0, audit: 0, write: 0, sync: 0, ending: 0, whole: 1, 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-04-25T05:31:04.437118Z DEBUG Unwinding{[3mstage[0m[2m=[0mFinish}: sync::pipeline: Starting unwind from=1414469 to=1414469 bad_block=Some(1414478)
2024-04-25T05:31:04.437485Z DEBUG Unwinding{[3mstage[0m[2m=[0mIndexAccountHistory}: sync::pipeline: Starting unwind from=1414469 to=1414469 bad_block=Some(1414478)
2024-04-25T05:31:04.437495Z DEBUG Unwinding{[3mstage[0m[2m=[0mIndexStorageHistory}: sync::pipeline: Starting unwind from=1414469 to=1414469 bad_block=Some(1414478)
2024-04-25T05:31:04.437502Z DEBUG Unwinding{[3mstage[0m[2m=[0mTransactionLookup}: sync::pipeline: Starting unwind from=1414469 to=1414469 bad_block=Some(1414478)
2024-04-25T05:31:04.437508Z DEBUG Unwinding{[3mstage[0m[2m=[0mMerkleExecute}: sync::pipeline: Starting unwind from=1414469 to=1414469 bad_block=Some(1414478)
2024-04-25T05:31:04.437514Z DEBUG Unwinding{[3mstage[0m[2m=[0mStorageHashing}: sync::pipeline: Starting unwind from=1414478 to=1414469 bad_block=Some(1414478)
2024-04-25T05:31:04.456169Z INFO Unwinding{[3mstage[0m[2m=[0mStorageHashing}: sync::pipeline: Stage unwound stage=StorageHashing unwind_to=1414469 progress=1414469 done=true
2024-04-25T05:31:04.460829Z DEBUG Unwinding{[3mstage[0m[2m=[0mStorageHashing}: provider::static_file: Commit segment=Headers path="/home/kendall/eth2-data/reth/holesky/static_files/static_file_headers_1000000_1499999" duration=4.613428ms
2024-04-25T05:31:04.465924Z DEBUG Unwinding{[3mstage[0m[2m=[0mStorageHashing}: provider::static_file: Commit segment=Transactions path="/home/kendall/eth2-data/reth/holesky/static_files/static_file_transactions_1000000_1499999" duration=4.967019ms
2024-04-25T05:31:04.769180Z DEBUG Unwinding{[3mstage[0m[2m=[0mStorageHashing}: storage::db::mdbx: Commit total_duration=303.114743ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 3, audit: 0, write: 0, sync: 19858, ending: 0, whole: 19862, 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-04-25T05:31:04.769269Z DEBUG Unwinding{[3mstage[0m[2m=[0mAccountHashing}: sync::pipeline: Starting unwind from=1414478 to=1414469 bad_block=Some(1414478)
2024-04-25T05:31:04.780843Z INFO Unwinding{[3mstage[0m[2m=[0mAccountHashing}: sync::pipeline: Stage unwound stage=AccountHashing unwind_to=1414469 progress=1414469 done=true
2024-04-25T05:31:04.811143Z DEBUG Unwinding{[3mstage[0m[2m=[0mAccountHashing}: provider::static_file: Commit segment=Headers path="/home/kendall/eth2-data/reth/holesky/static_files/static_file_headers_1000000_1499999" duration=30.259169ms
2024-04-25T05:31:04.842890Z DEBUG Unwinding{[3mstage[0m[2m=[0mAccountHashing}: provider::static_file: Commit segment=Transactions path="/home/kendall/eth2-data/reth/holesky/static_files/static_file_transactions_1000000_1499999" duration=31.560565ms
2024-04-25T05:31:04.912822Z DEBUG Unwinding{[3mstage[0m[2m=[0mAccountHashing}: storage::db::mdbx: Commit total_duration=69.748296ms commit_latency=Some(CommitLatency(MDBX_commit_latency { preparation: 0, gc_wallclock: 5, audit: 0, write: 0, sync: 4563, ending: 0, whole: 4568, 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-04-25T05:31:04.912969Z DEBUG Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::pipeline: Starting unwind from=1414478 to=1414469 bad_block=Some(1414478)
2024-04-25T05:31:04.913039Z DEBUG Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: trie::loader: incremental state root range=1414470..=1414478
2024-04-25T05:31:04.921859Z DEBUG net::session: pending session timed out remote_addr=194.180.19.126:38000 direction=Outgoing(0xb3f561eefe85ecb05719f26d3b99d3d2ffd66dc0f14c707f1709fc41120e4c73718daf47632e88dacc9e56ecad3fa2a39a33f5a1921e424735564cc4cfba4839)
2024-04-25T05:31:05.113267Z WARN Unwinding{[3mstage[0m[2m=[0mMerkleUnwind}: sync::stages::merkle: Failed to verify block state root target_block=1414469 got=0x80df9c09300cc33dc101991e841dcae68cba162c36993fc8669c3b31cadfa0a8 expected=SealedHeader { hash: 0xfc685c336c57b5153837f3b2ceb9c39054113c872cfac225c5b1939ce46e1f94, header: Header { parent_hash: 0x82bf41871024274c7c4979754f5368a47bd561f8a597f8d793dd424e6f996e12, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x8fc558a2b0352f9e03488986679374c961a599bb, state_root: 0x076a83408d306ff755956318ad51e4ef8785bef7e861f1377194ec862601a6ed, transactions_root: 0x4d3d68fc63c53ffcad86317983f1a2a06d1869f1bc694f49a4dc57790a8b46ed, receipts_root: 0xd7387d72f54b9f3b346903dcbb812d66ae7a43d555157723d43d49fd08b14c57, withdrawals_root: Some(0x4ab3a335bfedf1974ba035e033ac205b96f4ede8c02d13228d920715e479388f), logs_bloom: 0x04080800080000100000800000000002600800040400008004100200000040000000010000000000100520000080040010403001800000000004001001210000000002000000080000240009000000010100000200000000600400090c88104000400810020000a08000010080040800010000000002042000104030182000200000104000200000000000000000000000043000900000000400000030000400030008000004000000100011050008080200000000042010100000060000080402180002000801001000000000000d00000100120000001000089800010020000410080200000408081101008008300008008001602001200000800008002000, difficulty: 0x0_U256, number: 1414469, gas_limit: 30000000, gas_used: 9065197, timestamp: 1714022100, mix_hash: 0xa563061ebe8fc2671f5f90bd0e39bd39c1c2a368934d195f02a0dbc53d1f1c7c, nonce: 0, base_fee_per_gas: Some(2321611840), blob_gas_used: Some(655360), excess_blob_gas: Some(79036416), parent_beacon_block_root: Some(0x285ce5d058e18329e24b377e88d5946728cf94074b524c892d4e929e6bf42502), extra_data: 0x } }
2024-04-25T05:31:05.126095Z ERROR reth::cli: shutting down due to error
2024-04-25T05:31:10.709226Z INFO reth::cli: Starting reth version="0.2.0-beta.6-dev (ac29b4b73)"
2024-04-25T05:31:10.709918Z INFO reth::cli: Opening database path="/home/kendall/eth2-data/reth/holesky/db"
2024-04-25T05:31:10.866993Z INFO reth::cli: Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
2024-04-25T05:31:10.923565Z INFO reth::cli: Database opened
2024-04-25T05:31:10.923614Z INFO reth::cli: Starting metrics endpoint addr=0.0.0.0:9001
2024-04-25T05:31:10.931620Z DEBUG reth::cli: Initializing genesis chain=holesky genesis=0xb5f7f912443c940f21fd611f12828d75b534364ed9e95ca4e307729a4661bde4
2024-04-25T05:31:10.939542Z DEBUG reth_node_core::init: Genesis already written, skipping.
2024-04-25T05:31:10.939600Z INFO reth::cli:
Pre-merge hard forks (block based):
- Frontier @0
- Homestead @0
- Dao @0
rkrasiuk
commented
2 months ago @winksaville doesn't seem like links are working
winksaville
commented
2 months ago @winksaville doesn't seem like links are working
Fixed now
winksaville
commented
2 months ago After some discussion on the Reth State Root Debugging Warroom, the feeling is my database might be corrupted because I didn't resync or drop the merkle tree before I started testing beta.6.
I've removed all files using rm -rf ~/eth2-data/reth/holesky/* and in reth.service I've changed Restart to no:
kendall@ethel 24-04-26T19:26:45.289Z:~
$ cat -n /etc/systemd/system/reth.service
1 # The ethereum service (part of systemd)
2 # file: /etc/systemd/system/eth1.service
3
4 [Unit]
5 Description = reth eth2 service
6 Requires = network-online.target
7 After = network-online.target
8
9 [Service]
10 User = kendall
11 ExecStartPre = /bin/sleep 2
12 ExecStart = \
13 /home/kendall/bin/reth node \
14 --full \
15 --chain holesky \
16 --instance 1 \
17 --max-outbound-peers 16 \
18 --max-inbound-peers 16 \
19 --http \
20 --http.addr 0.0.0.0 \
21 --ws \
22 --http.api admin,eth,web3,net \
23 --datadir /home/kendall/eth2-data/reth/holesky \
24 --authrpc.addr 127.0.0.1 \
25 --authrpc.port 8551 \
26 --authrpc.jwtsecret /home/kendall/eth2-data/secrets/jwtsecret \
27 --log.file.format terminal \
28 --log.file.filter debug \
29 --log.file.directory /home/kendall/eth2-data/reth \
30 --log.file.max-size 200 \
31 --log.file.max-files 5 \
32 --log.journald \
33 --log.journald.filter error \
34 --color auto \
35 --metrics 0.0.0.0:9001 \
36
37 Restart = no
38 RestartSec = 3
39 TimeoutSec = 300
40
41 [Install]
42 WantedBy = multi-user.target
kendall@ethel 24-04-26T19:35:21.813Z:~I've now restarted the CLs and reth, here is the initial log lines from reth:
Apr 25 19:32:21 ethel systemd[1]: Stopped reth eth2 service.
Apr 26 12:25:39 ethel systemd[1]: Starting reth eth2 service...
Apr 26 12:25:41 ethel systemd[1]: Started reth eth2 service.
Apr 26 12:25:41 ethel reth[526219]: 2024-04-26T19:25:41.588190Z INFO Starting reth version="0.2.0-beta.6-dev (ac29b4b73)"
Apr 26 12:25:41 ethel reth[526219]: 2024-04-26T19:25:41.588834Z INFO Opening database path="/home/kendall/eth2-data/reth/holesky/db"
Apr 26 12:25:43 ethel reth[526219]: 2024-04-26T19:25:43.965992Z INFO Configuration loaded path="/home/kendall/eth2-data/reth/holesky/reth.toml"
Apr 26 12:25:43 ethel reth[526219]: 2024-04-26T19:25:43.967005Z INFO Database opened
Apr 26 12:25:43 ethel reth[526219]: 2024-04-26T19:25:43.967019Z INFO Starting metrics endpoint addr=0.0.0.0:9001
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.020355Z INFO
Apr 26 12:25:44 ethel reth[526219]: Pre-merge hard forks (block based):
Apr 26 12:25:44 ethel reth[526219]: - Frontier @0
Apr 26 12:25:44 ethel reth[526219]: - Homestead @0
Apr 26 12:25:44 ethel reth[526219]: - Dao @0
Apr 26 12:25:44 ethel reth[526219]: - Tangerine @0
Apr 26 12:25:44 ethel reth[526219]: - SpuriousDragon @0
Apr 26 12:25:44 ethel reth[526219]: - Byzantium @0
Apr 26 12:25:44 ethel reth[526219]: - Constantinople @0
Apr 26 12:25:44 ethel reth[526219]: - Petersburg @0
Apr 26 12:25:44 ethel reth[526219]: - Istanbul @0
Apr 26 12:25:44 ethel reth[526219]: - MuirGlacier @0
Apr 26 12:25:44 ethel reth[526219]: - Berlin @0
Apr 26 12:25:44 ethel reth[526219]: - London @0
Apr 26 12:25:44 ethel reth[526219]: Merge hard forks:
Apr 26 12:25:44 ethel reth[526219]: - Paris @0 (network is known to be merged)
Apr 26 12:25:44 ethel reth[526219]: Post-merge hard forks (timestamp based):
Apr 26 12:25:44 ethel reth[526219]: - Shanghai @1696000704
Apr 26 12:25:44 ethel reth[526219]: - Cancun @1707305664
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.116715Z INFO Transaction pool initialized
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.116758Z INFO Connecting to P2P network
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.118847Z INFO StaticFileProducer initialized
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.118964Z INFO Pruner initialized prune_config=PruneConfig { block_interval: 5, segments: PruneModes { sender_recovery: Some(Full), transaction_lookup: None, receipts: Some(Before(0)), account_history: Some(Distance(10064)), storage_history: Some(Distance(10064)), receipts_log_filter: ReceiptsLogPruneConfig({0x4242424242424242424242424242424242424242: Before(0)}) } }
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.119085Z INFO Consensus engine initialized
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.119150Z INFO Engine API handler initialized
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.120523Z INFO RPC auth server started url=127.0.0.1:8551
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.120616Z INFO RPC IPC server started url=/tmp/reth.ipc
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.120624Z INFO RPC HTTP server started url=0.0.0.0:8545
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.120628Z INFO RPC WS server started url=127.0.0.1:8546
Apr 26 12:25:44 ethel reth[526219]: 2024-04-26T19:25:44.120636Z INFO Starting consensus engine
Apr 26 12:25:47 ethel reth[526219]: 2024-04-26T19:25:47.119561Z INFO Status connected_peers=0 freelist=2 latest_block=0
Apr 26 12:26:12 ethel reth[526219]: 2024-04-26T19:26:12.119659Z INFO Status connected_peers=0 freelist=2 latest_block=0
Apr 26 12:26:37 ethel reth[526219]: 2024-04-26T19:26:37.120268Z INFO Status connected_peers=0 freelist=2 latest_block=0
Apr 26 12:27:02 ethel reth[526219]: 2024-04-26T19:27:02.119534Z INFO Status connected_peers=0 freelist=2 latest_block=0
Apr 26 12:27:27 ethel reth[526219]: 2024-04-26T19:27:27.120355Z INFO Status connected_peers=3 freelist=2 latest_block=0
Apr 26 12:27:32 ethel reth[526219]: 2024-04-26T19:27:32.586460Z INFO Live sync in progress, downloading blocks remaining_blocks=1 target_block_hash=0x6ae9a9f176b783a98d766b51f740f05730975099f7908f12c9892d1c04e8a045
Apr 26 12:27:32 ethel reth[526219]: 2024-04-26T19:27:32.586518Z INFO Received forkchoice updated message when syncing head_block_hash=0x15b77c5741dd1b251745081ad6a98b4b8aca739eb48da9c16ba1952f33ffa52c safe_block_hash=0x6ae9a9f176b783a98d766b51f740f05730975099f7908f12c9892d1c04e8a045 finalized_block_hash=0xa5bf1ecf708fb85c7907e20e0b37a47ff2e78253ce400f2421c3d208bf9248a9
Apr 26 12:27:32 ethel reth[526219]: 2024-04-26T19:27:32.586542Z INFO Live sync in progress, downloading blocks remaining_blocks=1 target_block_hash=0x15b77c5741dd1b251745081ad6a98b4b8aca739eb48da9c16ba1952f33ffa52c
Apr 26 12:27:33 ethel reth[526219]: 2024-04-26T19:27:33.108582Z INFO Static File Producer started targets=StaticFileTargets { headers: None, receipts: None, transactions: Some(0..=0) }
Apr 26 12:27:33 ethel reth[526219]: 2024-04-26T19:27:33.137838Z INFO Static File Producer finished targets=StaticFileTargets { headers: None, receipts: None, transactions: Some(0..=0) } elapsed=29.157575ms
Apr 26 12:27:33 ethel reth[526219]: 2024-04-26T19:27:33.137904Z INFO Preparing stage pipeline_stages=1/12 stage=Headers checkpoint=0 target=None
Apr 26 12:27:36 ethel reth[526219]: 2024-04-26T19:27:36.016193Z INFO Received headers total=10000 from_block=1420305 to_block=1410306
Apr 26 12:27:38 ethel reth[526219]: 2024-04-26T19:27:38.520677Z INFO Received headers total=10000 from_block=1410305 to_block=1400306
Apr 26 12:27:40 ethel reth[526219]: 2024-04-26T19:27:40.837033Z INFO Received headers total=10000 from_block=1400305 to_block=1390306
Apr 26 12:27:43 ethel reth[526219]: 2024-04-26T19:27:43.196793Z INFO Received headers total=10000 from_block=1390305 to_block=1380306Attestations started about 7hrs later:
Apr 26 19:20:29 ethel lighthouse[526220]: Apr 27 02:20:29.161 ERRO Error updating deposit contract cache error: Failed to get remote head and new block ranges: EndpointError(FarBehind), retry_millis: 60000, service: deposit_contract_rpc
Apr 26 19:21:29 ethel lighthouse[526220]: Apr 27 02:21:29.161 ERRO Error updating deposit contract cache error: Failed to get remote head and new block ranges: EndpointError(FarBehind), retry_millis: 60000, service: deposit_contract_rpc
Apr 26 19:22:29 ethel lighthouse[526220]: Apr 27 02:22:29.169 ERRO Error updating deposit contract cache error: Failed to get remote head and new block ranges: EndpointError(FarBehind), retry_millis: 60000, service: deposit_contract_rpc
Apr 26 19:23:29 ethel lighthouse[526220]: Apr 27 02:23:29.161 ERRO Error updating deposit contract cache error: Failed to get remote head and new block ranges: EndpointError(FarBehind), retry_millis: 60000, service: deposit_contract_rpc
Apr 26 19:23:57 ethel lighthouse[526220]: Apr 27 02:23:57.470 INFO Previous epoch attestation(s) missing validators: ["1624364", "1624363"], epoch: 47608, service: val_mon, service: beacon
Apr 26 19:30:21 ethel lighthouse[526220]: Apr 27 02:30:21.462 INFO Previous epoch attestation(s) missing validators: ["1624364", "1624363"], epoch: 47609, service: val_mon, service: beacon
Apr 26 19:36:45 ethel lighthouse[526220]: Apr 27 02:36:45.469 INFO Previous epoch attestation(s) success validators: ["1624364", "1624363"], epoch: 47610, service: val_mon, service: beacon
Apr 26 19:43:09 ethel lighthouse[526220]: Apr 27 02:43:09.516 INFO Previous epoch attestation(s) success validators: ["1624364", "1624363"], epoch: 47611, service: val_mon, service: beaconbeta.6 failed with "mismatched block state root".
Here is the directory with db and logs...: https://drive.google.com/file/d/1HGYmHoI2ImPKIsJQuZoFAwTSfVzOILtM/view?usp=drive_link
Here is the sha256sum of the above file: https://drive.google.com/file/d/1yDpqeBgtseSsaBoN-m4q03fLiL041Rxd/view?usp=drive_link
Here is reth.log: https://drive.google.com/file/d/1lIl7g_9RAwezi_Vi2FPUe_LRcIiQafOp/view?usp=drive_link
And it's sha256sum: https://drive.google.com/file/d/1QP9riJj3MlpNmVn0ZEGOSxY_CVGCGnXG/view?usp=drive_link
Here is the log lines around the first error:
2024-05-02T09:41:01.558729Z DEBUG blockchain_tree: Appending block to canonical chain head=0xd80097d3e5b3ef413c0ce3bd8dcd24941c849c3397ffc5c61739baf4c7293c50 parent=(1462114, 0x71cd9cd46ea0ecc762e6ae227c533d6e2ce1c3c47a1246f729d9e352adcca472)
2024-05-02T09:41:01.643935Z DEBUG evm: Execution time evm_transact=81.072169ms apply_state=509.229µs apply_post_state=5.15µs merge_transitions=548.025µs receipt_root=2.363484ms
2024-05-02T09:41:01.645314Z DEBUG trie::parallel_state_root: pre-calculating storage roots len=394
2024-05-02T09:41:02.064694Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0xd80097d3e5b3ef413c0ce3bd8dcd24941c849c3397ffc5c61739baf4c7293c50, number=1462115, parent_hash=0x71cd9cd46ea0ecc762e6ae227c533d6e2ce1c3c47a1246f729d9e352adcca472): mismatched block state root: got 0x9dc21474467a4fa1cc82968e91f9ec5b0a69f0921e36f59a71d506fae9aa2a0f, expected 0xb1fc80619f2159d3e11361ac3c6083c12b1628f0906810853eb565496ff8689d
2024-05-02T09:41:02.065046Z WARN consensus::engine: Invalid block error on new payload invalid_hash=0xd80097d3e5b3ef413c0ce3bd8dcd24941c849c3397ffc5c61739baf4c7293c50 invalid_number=1462115 error=mismatched block state root: got 0x9dc21474467a4fa1cc82968e91f9ec5b0a69f0921e36f59a71d506fae9aa2a0f, expected 0xb1fc80619f2159d3e11361ac3c6083c12b1628f0906810853eb565496ff8689d
2024-05-02T09:41:02.067004Z WARN consensus::engine: Bad block with hash hash=0xd80097d3e5b3ef413c0ce3bd8dcd24941c849c3397ffc5c61739baf4c7293c50 header=Header { parent_hash: 0x71cd9cd46ea0ecc762e6ae227c533d6e2ce1c3c47a1246f729d9e352adcca472, ommers_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, beneficiary: 0x148914866080716b10d686f5570631fbb2207002, state_root: 0xb1fc80619f2159d3e11361ac3c6083c12b1628f0906810853eb565496ff8689d, transactions_root: 0xf7c7fc5e532b4a0f3f7a0c24c22482c3dca46684f30c7f4e4a39caf9b27ca8d7, receipts_root: 0xfefcdeaa2d7ec432bd6f00a29f6128ec0bee3f6685cfd47037b70de85dddab8e, withdrawals_root: Some(0x2ee06f790cde99c3ca70a7d70b1f02c209bea9cc1aadc18ff3d0e9704316eaff), logs_bloom: 0x44cc39b308080b4110833df1f9d580896f1d0941946cb0d01d34f7d0d4f646715580898628374868472627fda9d02d2f522c2b15ba380e8d85bc162793b1c3ef1034020591886358560fc81918a9728f010fcc63743aaa5b6c143d898988d14584063d5026461104a9f26d1614115855293d1b02641fe263273d69fc14638cd03a46dbda098dfc0e2b1df47d3f7c0434183cb68a1702301a0146dde37fa6266ad745fc41327659c06a4f3475a5234c294be2770aa516fc6d33b8580e21889e1d01df862feb0cc9085d28b15693c47da5883d9416f17600b5892a3f26573c75ea145b8ad3caa055d951fab119f90a2a454e5697f8e81917c5c9134af65f0f3223, difficulty: 0x0_U256, number: 1462115, gas_limit: 30000000, gas_used: 28957346, timestamp: 1714642860, mix_hash: 0x5c25f38d1a7310dfbfcfc491ec9803d2765b4af57adce1e09d382c506c736c76, nonce: 0, base_fee_per_gas: Some(3718827006), blob_gas_used: Some(655360), excess_blob_gas: Some(80216064), parent_beacon_block_root: Some(0xc0bf037f523033779dda6e075cdb1597cd03971402234667ecddb2fd05fdcafb), extra_data: 0x546974616e2028746974616e6275696c6465722e78797a29 }
2024-05-02T09:41:02.067382Z DEBUG consensus::engine::hooks: Next hook is not ready hook="Prune"
2024-05-02T09:41:10.150915Z DEBUG jsonrpsee-server: Accepting new connection 1/500
2024-05-02T09:41:19.391768Z DEBUG jsonrpsee-server: Accepting new connection 1/500
2024-05-02T09:41:19.394391Z DEBUG blockchain_tree: Appending block to canonical chain head=0xd80097d3e5b3ef413c0ce3bd8dcd24941c849c3397ffc5c61739baf4c7293c50 parent=(1462114, 0x71cd9cd46ea0ecc762e6ae227c533d6e2ce1c3c47a1246f729d9e352adcca472)
2024-05-02T09:41:19.418196Z DEBUG evm: Execution time evm_transact=20.236627ms apply_state=456.03µs apply_post_state=4.423µs merge_transitions=748.571µs receipt_root=2.180102ms
2024-05-02T09:41:19.419683Z DEBUG trie::parallel_state_root: pre-calculating storage roots len=394
2024-05-02T09:41:19.498095Z WARN consensus::engine: Error while processing payload error=Failed to insert block (hash=0xd80097d3e5b3ef413c0ce3bd8dcd24941c849c3397ffc5c61739baf4c7293c50, number=1462115, parent_hash=0x71cd9cd46ea0ecc762e6ae227c533d6e2ce1c3c47a1246f729d9e352adcca472): mismatched block state root: got 0x9dc21474467a4fa1cc82968e91f9ec5b0a69f0921e36f59a71d506fae9aa2a0f, expected 0xb1fc80619f2159d3e11361ac3c6083c12b1628f0906810853eb565496ff8689d
2024-05-02T09:41:19.498155Z WARN consensus::engine: Invalid block error on new payload invalid_hash=0xd80097d3e5b3ef413c0ce3bd8dcd24941c849c3397ffc5c61739baf4c7293c50 invalid_number=1462115 error=mismatched block state root: got 0x9dc21474467a4fa1cc82968e91f9ec5b0a69f0921e36f59a71d506fae9aa2a0f, expected 0xb1fc80619f2159d3e11361ac3c6083c12b1628f0906810853eb565496ff8689d
2024-05-02T09:41:19.498414Z DEBUG consensus::engine::hooks: Next hook is not ready hook="StaticFile"Here is the vitals of the node:
kendall@ethel 24-05-03T04:30:40.076Z:~
$ print-info.sh
~/bin/reth --version:
reth Version: 0.2.0-beta.6-dev
Commit SHA: ac29b4b73
Build Timestamp: 2024-04-24T00:06:44.055414554Z
Build Features: jemalloc
Build Profile: release
~/bin/lighthouse --version:
Lighthouse v5.1.3-3058b96
BLS library: blst-modern
SHA256 hardware acceleration: false
Allocator: jemalloc
Profile: maxperf
Specs: mainnet (true), minimal (false), gnosis (true)
inxi:
CPU: quad core Intel Core i5-8259U (-MT MCP-)
speed/min/max: 1249/400/3800 MHz Kernel: 6.5.0-27-generic x86_64
Up: 15d 10h 16m Mem: 1214.6/31953.5 MiB (3.8%) Storage: 2.73 TiB (21.1% used)
Procs: 255 Shell: Bash inxi: 3.3.13
lsb_release -a:
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 22.04.4 LTS
Release: 22.04
Codename: jammy
df -h:
Filesystem Size Used Avail Use% Mounted on
tmpfs 3.2G 2.0M 3.2G 1% /run
/dev/nvme0n1p2 916G 124G 745G 15% /
tmpfs 16G 0 16G 0% /dev/shm
tmpfs 5.0M 4.0K 5.0M 1% /run/lock
efivarfs 192K 59K 129K 32% /sys/firmware/efi/efivars
/dev/nvme0n1p1 511M 6.1M 505M 2% /boot/efi
/dev/sda1 1.8T 466G 1.3T 27% /home/kendall/eth2-data
tmpfs 3.2G 108K 3.2G 1% /run/user/125
tmpfs 3.2G 96K 3.2G 1% /run/user/1000
kendall@ethel 24-05-03T04:53:26.135Z:~
$ cat /etc/systemd/system/reth.service
# The ethereum service (part of systemd)
# file: /etc/systemd/system/eth1.service
[Unit]
Description = reth eth2 service
Requires = network-online.target
After = network-online.target
[Service]
User = kendall
ExecStartPre = /bin/sleep 2
ExecStart = \
/home/kendall/bin/reth node \
--full \
--chain holesky \
--instance 1 \
--max-outbound-peers 16 \
--max-inbound-peers 16 \
--http \
--http.addr 0.0.0.0 \
--ws \
--http.api admin,eth,web3,net \
--datadir /home/kendall/eth2-data/reth/holesky \
--authrpc.addr 127.0.0.1 \
--authrpc.port 8551 \
--authrpc.jwtsecret /home/kendall/eth2-data/secrets/jwtsecret \
--log.file.format terminal \
--log.file.filter debug \
--log.file.directory /home/kendall/eth2-data/reth \
--log.file.max-size 200 \
--log.file.max-files 5 \
--log.journald \
--log.journald.filter error \
--color auto \
--metrics 0.0.0.0:9001 \
Restart = no
RestartSec = 3
TimeoutSec = 300
[Install]
WantedBy = multi-user.target
kendall@ethel 24-05-03T04:54:26.103Z:~I came up with some additional debug!, dbg-v0.2.0-beta.6 (71f3c6b). What I'm hoping is that when the state root error occurs we'll be able find the SealedHeader for both the block we failed on as well as the expected block and maybe that will provide useful information.
Of course, if there is a solution or additional debug! I'll stop this and test whatever the experts want.
winksaville
commented
2 months ago @Rjected, has asked me to remove the panic!, before I do I'd like to see if there are any other debug! log statements people would like to be added?
Also, when I restarted the first time with my initial changes the first wink output was state_root::calculate just before the first run of the MerkleExecute stage finished:
2024-05-04T18:29:46.996165Z INFO reth::cli: Starting reth version="0.2.0-beta.6-dev (6adb54c90)"
...
2024-05-04T18:45:27.973719Z DEBUG reth_trie::trie: wink: trie::state_root::calculate: 0xc3812b2303d2b564f03b17284d9fb284309585cf65f6cbb228d9932c9a8c5a7c
2024-05-04T18:45:27.990954Z INFO reth_node_events::node: Finished stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1462136 target=1462136 stage_progress=100.00% stage_eta=unknownI decided to search the logs and I found that state root 0xc3812b23..8c5a7c corresponds to the expected state root in the last mismatched block state root when v0.2.0-beta.6 (ac29b4b73) failed:
2024-04-26T19:25:41.588216Z INFO reth::cli: Starting reth version="0.2.0-beta.6-dev (ac29b4b73)"
...
2024-05-02T10:00:54.178146Z ERROR sync::pipeline: Stage encountered a validation error: mismatched block state root: got 0xb51453298d8df1e83d55f8f658f4a925f005dc0a5c5edd6ae5714cd05169b1a8, expected 0xc3812b2303d2b564f03b17284d9fb284309585cf65f6cbb228d9932c9a8c5a7c stage=MerkleExecute bad_block=1462136I thought that was interesting, so would anyone like to add more debug! log statements before I rebuild and restart my node?
Latest logs: reth-dbg-v0.2.0-beta.6-ac29b4b73-6adb54c90-71f3c6b9c-logs.tar.gz and .sha256sum
winksaville
commented
2 months ago As @Rjected asked I've removed the panic! but left the 3 debug! statements. I stopped EL and CL and dropped the Merkle stage recompiled resulting in reth version="0.2.0-beta.6-dev (4f6be12e5)".
I then restarted EL and CL and reth when though the stages once and shortly after that the bn was reporting successful attestations.
Now we just need to wait a week or so and see what happens, LoL.
Here are reth logs showing startup through the first set of stages:
May 08 12:01:14 ethel reth[647583]: 2024-05-08T19:01:14.289539Z INFO Pruner finished tip_block_number=1504649 elapsed=310.521878ms stats={AccountHistory: (Finished, 621)}
May 08 12:01:16 ethel systemd[1]: Stopping reth eth2 service...
May 08 12:01:16 ethel reth[647583]: 2024-05-08T19:01:16.341372Z INFO Wrote network peers to file peers_file="/home/kendall/eth2-data/reth/holesky/known-peers.json"
May 08 12:01:16 ethel systemd[1]: reth.service: Deactivated successfully.
May 08 12:01:16 ethel systemd[1]: Stopped reth eth2 service.
May 08 12:01:16 ethel systemd[1]: reth.service: Consumed 6h 16min 28.560s CPU time.
May 08 12:40:22 ethel systemd[1]: Starting reth eth2 service...
May 08 12:40:24 ethel systemd[1]: Started reth eth2 service.
May 08 12:40:24 ethel reth[700461]: 2024-05-08T19:40:24.516383Z INFO Starting reth version="0.2.0-beta.6-dev (4f6be12e5)"
...
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.818053Z INFO Preparing stage pipeline_stages=1/12 stage=Headers checkpoint=1504649 target=None
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.818068Z INFO Target block already reached checkpoint=1504649 target=Hash(0x03bd2f085839b479bf2e64775e6cb9400d085c9b06085f14aa3c8f973b36dbea)
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.818107Z INFO Executing stage pipeline_stages=1/12 stage=Headers checkpoint=1504649 target=None
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.818204Z INFO Finished stage pipeline_stages=1/12 stage=Headers checkpoint=1504649 target=None
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.831464Z INFO Preparing stage pipeline_stages=2/12 stage=Bodies checkpoint=1504649 target=1504649
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.831486Z INFO Executing stage pipeline_stages=2/12 stage=Bodies checkpoint=1504649 target=1504649
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.831497Z INFO Finished stage pipeline_stages=2/12 stage=Bodies checkpoint=1504649 target=1504649
...
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.888691Z INFO Preparing stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1504649 target=1504649
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.888741Z INFO Executing stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1504649 target=1504649
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.888762Z INFO Finished stage pipeline_stages=7/12 stage=StorageHashing checkpoint=1504649 target=1504649
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.898846Z INFO Preparing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=0 target=1504649
May 08 12:41:10 ethel reth[700461]: 2024-05-08T19:41:10.898865Z INFO Executing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=0 target=1504649
May 08 12:41:11 ethel reth[700461]: 2024-05-08T19:41:11.835594Z INFO Committed stage progress pipeline_stages=8/12 stage=MerkleExecute checkpoint=0 target=1504649 stage_progress=0.12%
May 08 12:41:11 ethel reth[700461]: 2024-05-08T19:41:11.866590Z INFO Preparing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=0 target=1504649
May 08 12:41:11 ethel reth[700461]: 2024-05-08T19:41:11.866614Z INFO Executing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=0 target=1504649
May 08 12:41:12 ethel reth[700461]: 2024-05-08T19:41:12.649713Z INFO Committed stage progress pipeline_stages=8/12 stage=MerkleExecute checkpoint=0 target=1504649 stage_progress=0.22% stage_eta=13m 56s
...
May 08 12:54:25 ethel reth[700461]: 2024-05-08T19:54:25.212144Z INFO Preparing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1504649 target=1504833
May 08 12:54:25 ethel reth[700461]: 2024-05-08T19:54:25.212214Z INFO Executing stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1504649 target=1504833
May 08 12:54:39 ethel reth[700461]: 2024-05-08T19:54:39.114246Z INFO Status connected_peers=6 freelist=203451 stage=MerkleExecute checkpoint=1504649 target=1504833
May 08 12:55:02 ethel reth[700461]: 2024-05-08T19:55:02.709632Z INFO Finished stage pipeline_stages=8/12 stage=MerkleExecute checkpoint=1504833 target=1504833 stage_progress=100.00%
May 08 12:55:04 ethel reth[700461]: 2024-05-08T19:55:04.113732Z INFO Status connected_peers=8 freelist=203451 latest_block=1504649
May 08 12:55:04 ethel reth[700461]: 2024-05-08T19:55:04.818513Z INFO Updating transaction lookup tx_range=1504649..=1504833
May 08 12:55:04 ethel reth[700461]: 2024-05-08T19:55:04.818515Z INFO Preparing stage pipeline_stages=9/12 stage=TransactionLookup checkpoint=1504649 target=1504833
...
May 08 12:55:19 ethel reth[700461]: 2024-05-08T19:55:19.032953Z INFO Writing indices progress=98.89%
May 08 12:55:19 ethel reth[700461]: 2024-05-08T19:55:19.083176Z INFO Writing indices progress=99.89%
May 08 12:55:19 ethel reth[700461]: 2024-05-08T19:55:19.088559Z INFO Finished stage pipeline_stages=11/12 stage=IndexAccountHistory checkpoint=1504833 target=1504833
May 08 12:55:19 ethel reth[700461]: 2024-05-08T19:55:19.706231Z INFO Preparing stage pipeline_stages=12/12 stage=Finish checkpoint=1504649 target=1504833
May 08 12:55:19 ethel reth[700461]: 2024-05-08T19:55:19.706336Z INFO Executing stage pipeline_stages=12/12 stage=Finish checkpoint=1504649 target=1504833
May 08 12:55:19 ethel reth[700461]: 2024-05-08T19:55:19.706441Z INFO Finished stage pipeline_stages=12/12 stage=Finish checkpoint=1504833 target=1504833And here are some bn logs from it starting to the EL is online and shortly after we see a successful attestation of both vc's:
May 08 12:01:23 ethel systemd[1]: beacon-chain.service: Deactivated successfully.
May 08 12:01:23 ethel systemd[1]: Stopped eth2 beacon chain service.
May 08 12:01:23 ethel systemd[1]: beacon-chain.service: Consumed 6d 2h 24min 39.531s CPU time.
May 08 12:40:22 ethel systemd[1]: Starting eth2 beacon chain service...
May 08 12:40:24 ethel systemd[1]: Started eth2 beacon chain service.
May 08 12:40:24 ethel lighthouse[700462]: May 08 19:40:24.533 INFO Logging to file path: "/home/kendall/eth2-data/lighthouse/holesky/beacon/logs/beacon.log"
May 08 12:40:24 ethel lighthouse[700462]: May 08 19:40:24.542 INFO Lighthouse started version: Lighthouse/v5.1.3-3058b96
May 08 12:40:24 ethel lighthouse[700462]: May 08 19:40:24.542 INFO Configured for network name: holesky
May 08 12:40:24 ethel lighthouse[700462]: May 08 19:40:24.542 INFO Data directory initialised datadir: /home/kendall/eth2-data/lighthouse/holesky
...
May 08 12:55:17 ethel lighthouse[700462]: May 08 19:55:17.507 WARN Execution endpoint is not synced last_seen_block_unix_timestamp: 1695902100, endpoint: http://127.0.0.1:8551/, auth=true, service: deposit_contract_rpc
May 08 12:55:17 ethel lighthouse[700462]: May 08 19:55:17.508 ERRO Error updating deposit contract cache error: Failed to get remote head and new block ranges: EndpointError(FarBehind), retry_millis: 60000, service: deposit_contract_rpc
May 08 12:55:18 ethel lighthouse[700462]: May 08 19:55:18.001 WARN Head is optimistic execution_block_hash: 0xeb1649632e1446cd18f083242a845c9ad54cab7c0b90a60c8cbe16b19cc56464, info: chain not fully verified, block and attestation production disabled until execution engine syncs, service: slot_notifier
May 08 12:55:18 ethel lighthouse[700462]: May 08 19:55:18.001 INFO Synced slot: 1607976, block: 0xeaf4…4acb, epoch: 50249, finalized_epoch: 50247, finalized_root: 0x4187…5532, exec_hash: 0xeb16…6464 (unverified), peers: 100, service: slot_notifier
May 08 12:55:25 ethel lighthouse[700462]: May 08 19:55:25.309 INFO New block received root: 0xf0d9b65c5d4add6d18bcfd1393f1c3f52d09dbcee8eb835ccffea20855634565, slot: 1607977
May 08 12:55:25 ethel lighthouse[700462]: May 08 19:55:25.669 INFO Execution engine online service: exec
May 08 12:55:25 ethel lighthouse[700462]: May 08 19:55:25.669 INFO Issuing forkchoiceUpdated forkchoice_state: ForkchoiceState { head_block_hash: 0xeb1649632e1446cd18f083242a845c9ad54cab7c0b90a60c8cbe16b19cc56464, safe_block_hash: 0x2d469d9db7c75199c468457da36e77f1c2c88b503902ca355fc8fc7f57a96cbd, finalized_block_hash: 0x3953c2106e5af4ca1a4af9c3ea0fc7fd61c6050432e5de35f0ba83d0203bd8e6 }, service: exec
...
May 08 13:12:45 ethel lighthouse[700462]: May 08 20:12:45.473 INFO Previous epoch attestation(s) success validators: ["1624363", "1624364"], epoch: 50250, service: val_mon, service: beacon
github-actions[bot]
commented
1 month ago This issue is stale because it has been open for 21 days with no activity.
Describe the bug
Reth was only reporting it was connected to peers and lighthouse becaon said and validators weren't happy, so I decided to reboot the computer and it went into a restart loop.
Steps to reproduce
I don't know how to reproduce the problem, but here is what I observed.
This morning I looked at the reth log output from journalctl on my Arch Linux machine and it wasn't not doing much
And the lighthouse beacon and validator nodes weren't happy, so I restarted them leaving reth running. In retrospect I probably should have left beacon and validator alone and restarted reth.
But anyway, here is beacon restarting:
And here is the validator:
That didn't help so after waiting a short while, I decided reboot the computer.
And reth found a problem
Apr 02 10:49:48 ethel reth[1523]: shutting down due to errorand restartedApr 02 10:49:51 ethel systemd[1]: reth.service: Scheduled restart job, restart counter is at 1:And kept restarting:
Node logs
Platform(s)
Linux (x86)
What version/commit are you on?
What database version are you on?
What type of node are you running?
Archive (default)
What prune config do you use, if any?
There is no
[prune]section in reth.toml:But my reth.service ExecStart is
--full:If you've built Reth from source, provide the full command you used
cargo install --locked --path bin/reth --bin reth
Code of Conduct