Describe the bug Reth was only reporting it was connected to peers

Here is an link to the logs: <a href="https://drive.google.com/file/d/1uEwgV3V6dqqnUT7

tysm for all the logs <a class="user-mention notranslate" data-hovercard-type="user" d

tysm for all the logs <a class="user-mention notranslate" data-hovercard-

Seeing the weirdness <a href="https://github.com/paradigmxyz/reth/issues/7430#issuecom

This keeps happening on beta.5 <div class="snippet-clipboard-content notranslate p

<a class="user-mention notranslate" data-hovercard-type="user" data-hovercard-url="/us

It does look like that, cc <a class="user-mention notranslate" data-hovercard-type="us

Reth on holesky looks to have a corrupted DB and entered restart loop after rebooting,about paradigmxyz/reth

Comments (31)

Rjected commented on June 12, 2024 2

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 :)

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?

from reth.

winksaville commented on June 12, 2024 1

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: beacon

Thanks!

from reth.

winksaville commented on June 12, 2024

Here is an link to the logs: https://drive.google.com/file/d/1uEwgV3V6dqqnUT7dxu9lfHT88773Uhe3/view?usp=sharing

from reth.

mattsse commented on June 12, 2024

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

from reth.

winksaville commented on June 12, 2024

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/reth

But 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 0x4ed32b88c105a497378e0773cf741fcac17ab4474b074f515e0ad7f99dbb4af8

What 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?

from reth.

winksaville commented on June 12, 2024

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…c1114bf1

Until 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…f99dbb4af8

The 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 opened

Also, 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: sync

So 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!

from reth.

pistomat commented on June 12, 2024

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: maxperf

Dropping 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.

from reth.

winksaville commented on June 12, 2024

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.

from reth.

winksaville commented on June 12, 2024

@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?

from reth.

DaniPopes commented on June 12, 2024

It does look like that, cc @mattsse

from reth.

winksaville commented on June 12, 2024

Note: After a little less that and hour my node was successfully attesting after I reth stage drop merkle and restarting the node.

from reth.

winksaville commented on June 12, 2024

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 :)

from reth.

pistomat commented on June 12, 2024

This happened to me again today, dropping the stage again helped.

Do you want me to post any more info?

from reth.

Rjected commented on June 12, 2024

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?

from reth.

winksaville commented on June 12, 2024

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 <#7430 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAH2CHBGKCTNVUSRH2XP4OTY5DTVRAVCNFSM6AAAAABFUBABCSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDANJTGU3TAOJYGM> . You are receiving this because you were mentioned.Message ID: ***@***.***>

from reth.

winksaville commented on June 12, 2024

@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)"

from reth.

winksaville commented on June 12, 2024

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                   @0

That 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                        @0

It 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                        @0

And 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.

from reth.

winksaville commented on June 12, 2024

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.

from reth.

winksaville commented on June 12, 2024

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/reth

And 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"

from reth.

winksaville commented on June 12, 2024

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

from reth.

gakonst commented on June 12, 2024

Fixed in #7753.

from reth.

winksaville commented on June 12, 2024

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=1414478

The 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

from reth.

rkrasiuk commented on June 12, 2024

@winksaville doesn't seem like links are working

from reth.

winksaville commented on June 12, 2024

@winksaville doesn't seem like links are working

Fixed now

from reth.

winksaville commented on June 12, 2024

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=1380306

from reth.

winksaville commented on June 12, 2024

Attestations 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: beacon

from reth.

winksaville commented on June 12, 2024

beta.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:~

from reth.

winksaville commented on June 12, 2024

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.

from reth.

winksaville commented on June 12, 2024

@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=unknown

I 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=1462136

I 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

from reth.

winksaville commented on June 12, 2024

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=1504833

And 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

from reth.

github-actions commented on June 12, 2024

This issue is stale because it has been open for 21 days with no activity.

from reth.

Reth on holesky looks to have a corrupted DB and entered restart loop after rebooting about reth HOT 31 OPEN

Comments (31)

Related Issues (20)

Recommend Projects

React

Vue.js

Typescript

TensorFlow

Django

Laravel

D3

Recommend Topics

javascript

web

server

Machine learning

Visualization

Game

Recommend Org

Facebook

Microsoft

Google

Alibaba

D3

Tencent