erigon
erigon copied to clipboard
Post-merge erigon appears to stay stuck behind chain tip sometimes
v2022.09.03 (but I've seen this behavior in previous versions too)
When running erigon post-merge, I've seen sometimes getting stuck far behind the chain tip. I don't know what triggers this behavior, but it eventually recovers by itself.
You can see a proof of that happening in the following screenshot from otterscan home page, where now we display the chain tip (from erigon) alongside the finalized slot (from beacon chain REST API, in this case I'm using prysm):

The finalized slot is correct (~2 epochs, so 19 min behind is ok), but erigon is 44 min behind.
What I noticed is that on these cases, erigon seems to enter some different staged sync cycle where it goes only from stages 1-7, see compose logs (erigon+prysm):
mainnet-erigon-1 | [INFO] [09-22|14:08:08.385] [p2p] GoodPeers eth66=33
mainnet-erigon-1 | [INFO] [09-22|14:08:10.021] Timings (slower than 50ms) Bodies=220ms Senders=85ms Execution=2.294s HashState=263ms IntermediateHashes=1.908s
mainnet-erigon-1 | [INFO] [09-22|14:08:10.021] Tables PlainState=912.0KB AccountChangeSet=500.0KB StorageChangeSet=916.0KB BlockTransaction=2.6MB TransactionLog=2.1MB FreeList=0B
mainnet-prysm-1 | time="2022-09-22 14:08:10" level=warning msg="Execution client is not syncing" prefix=powchain
mainnet-erigon-1 | [INFO] [09-22|14:08:10.595] [4/7 Senders] Started from=15589264 to=15589293
mainnet-erigon-1 | [INFO] [09-22|14:08:10.677] [5/7 Execution] Blocks execution from=15589264 to=15589293
mainnet-prysm-1 | time="2022-09-22 14:08:11" level=info msg="Called new payload with optimistic block" payloadBlockHash=0x12ee1e51f52b prefix=blockchain slot=4752639
mainnet-prysm-1 | time="2022-09-22 14:08:11" level=info msg="Called fork choice updated with optimistic block" finalizedPayloadBlockHash=0x21d640cf4169 headPayloadBlockHash=0x12ee1e51f52b headSlot=4752639 prefix=blockchain
mainnet-prysm-1 | time="2022-09-22 14:08:11" level=info msg="Synced new block" block=0x457b33c6... epoch=148519 finalizedEpoch=148517 finalizedRoot=0x4ece553a... prefix=blockchain slot=4752639
mainnet-prysm-1 | time="2022-09-22 14:08:11" level=info msg="Finished applying state transition" attestations=77 payloadHash=0x12ee1e51f52b prefix=blockchain slot=4752639 syncBitsCount=0 txCount=112
mainnet-prysm-1 | time="2022-09-22 14:08:12" level=info msg="Peer summary" activePeers=41 inbound=0 outbound=41 prefix=p2p
mainnet-erigon-1 | [INFO] [09-22|14:08:14.039] [5/7 Execution] Completed on block=15589293
mainnet-erigon-1 | [INFO] [09-22|14:08:14.039] [6/7 HashState] Promoting plain state from=15589264 to=15589293
mainnet-erigon-1 | [INFO] [09-22|14:08:14.039] [6/7 HashState] Incremental promotion from=15589264 to=15589293 codes=true csbucket=AccountChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:14.196] [6/7 HashState] Incremental promotion from=15589264 to=15589293 codes=false csbucket=AccountChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:14.251] [6/7 HashState] Incremental promotion from=15589264 to=15589293 codes=false csbucket=StorageChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:14.380] [7/7 IntermediateHashes] Generating intermediate hashes from=15589264 to=15589293
mainnet-erigon-1 | [INFO] [09-22|14:08:18.002] [txpool] stat block=15589264 pending=7815 baseFee=30000 queued=27716 alloc=6.0GB sys=8.5GB
mainnet-erigon-1 | [INFO] [09-22|14:08:18.306] Timings (slower than 50ms) Bodies=498ms Senders=82ms Execution=3.362s HashState=340ms IntermediateHashes=3.926s
mainnet-erigon-1 | [INFO] [09-22|14:08:18.306] Tables PlainState=956.0KB AccountChangeSet=524.0KB StorageChangeSet=972.0KB BlockTransaction=2.8MB TransactionLog=2.2MB FreeList=0B
mainnet-erigon-1 | [INFO] [09-22|14:08:18.882] [4/7 Senders] Started from=15589264 to=15589294
mainnet-erigon-1 | [INFO] [09-22|14:08:18.967] [5/7 Execution] Blocks execution from=15589264 to=15589294
mainnet-erigon-1 | [INFO] [09-22|14:08:22.315] [5/7 Execution] Completed on block=15589294
mainnet-erigon-1 | [INFO] [09-22|14:08:22.315] [6/7 HashState] Promoting plain state from=15589264 to=15589294
mainnet-erigon-1 | [INFO] [09-22|14:08:22.315] [6/7 HashState] Incremental promotion from=15589264 to=15589294 codes=true csbucket=AccountChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:22.450] [6/7 HashState] Incremental promotion from=15589264 to=15589294 codes=false csbucket=AccountChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:22.503] [6/7 HashState] Incremental promotion from=15589264 to=15589294 codes=false csbucket=StorageChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:22.639] [7/7 IntermediateHashes] Generating intermediate hashes from=15589264 to=15589294
mainnet-prysm-1 | time="2022-09-22 14:08:24" level=warning msg="Execution client is not syncing" prefix=powchain
mainnet-prysm-1 | time="2022-09-22 14:08:25" level=info msg="Called new payload with optimistic block" payloadBlockHash=0x783943f658a0 prefix=blockchain slot=4752640
mainnet-prysm-1 | time="2022-09-22 14:08:25" level=info msg="Called fork choice updated with optimistic block" finalizedPayloadBlockHash=0x0f8eb42845b8 headPayloadBlockHash=0x783943f658a0 headSlot=4752640 prefix=blockchain
mainnet-erigon-1 | [INFO] [09-22|14:08:25.801] Timings (slower than 50ms) Bodies=510ms Senders=84ms Execution=3.347s HashState=323ms IntermediateHashes=3.162s
mainnet-erigon-1 | [INFO] [09-22|14:08:25.801] Tables PlainState=988.0KB AccountChangeSet=548.0KB StorageChangeSet=1020.0KB BlockTransaction=2.9MB TransactionLog=2.3MB FreeList=0B
mainnet-prysm-1 | time="2022-09-22 14:08:26" level=info msg="Synced new block" block=0xd7bb4bce... epoch=148520 finalizedEpoch=148518 finalizedRoot=0xc2e272fd... prefix=blockchain slot=4752640
mainnet-prysm-1 | time="2022-09-22 14:08:26" level=info msg="Finished applying state transition" attestations=128 payloadHash=0x783943f658a0 prefix=blockchain slot=4752640 syncBitsCount=505 txCount=188
mainnet-erigon-1 | [INFO] [09-22|14:08:27.157] [4/7 Senders] Started from=15589264 to=15589295
mainnet-erigon-1 | [INFO] [09-22|14:08:27.245] [5/7 Execution] Blocks execution from=15589264 to=15589295
mainnet-erigon-1 | [INFO] [09-22|14:08:30.617] [5/7 Execution] Completed on block=15589295
mainnet-erigon-1 | [INFO] [09-22|14:08:30.617] [6/7 HashState] Promoting plain state from=15589264 to=15589295
mainnet-erigon-1 | [INFO] [09-22|14:08:30.617] [6/7 HashState] Incremental promotion from=15589264 to=15589295 codes=true csbucket=AccountChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:30.749] [6/7 HashState] Incremental promotion from=15589264 to=15589295 codes=false csbucket=AccountChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:30.813] [6/7 HashState] Incremental promotion from=15589264 to=15589295 codes=false csbucket=StorageChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:30.951] [7/7 IntermediateHashes] Generating intermediate hashes from=15589264 to=15589295
mainnet-erigon-1 | [INFO] [09-22|14:08:34.576] Timings (slower than 50ms) Bodies=1.26s Senders=87ms Execution=3.372s HashState=333ms IntermediateHashes=3.624s
mainnet-erigon-1 | [INFO] [09-22|14:08:34.576] Tables PlainState=1016.0KB AccountChangeSet=568.0KB StorageChangeSet=1.0MB BlockTransaction=3.1MB TransactionLog=2.4MB FreeList=0B
mainnet-erigon-1 | [INFO] [09-22|14:08:35.545] [4/7 Senders] Started from=15589264 to=15589296
mainnet-erigon-1 | [INFO] [09-22|14:08:35.671] [5/7 Execution] Blocks execution from=15589264 to=15589296
mainnet-prysm-1 | time="2022-09-22 14:08:36" level=info msg="Called new payload with optimistic block" payloadBlockHash=0x85ff763ada23 prefix=blockchain slot=4752641
mainnet-prysm-1 | time="2022-09-22 14:08:36" level=info msg="Called fork choice updated with optimistic block" finalizedPayloadBlockHash=0x0f8eb42845b8 headPayloadBlockHash=0x85ff763ada23 headSlot=4752641 prefix=blockchain
mainnet-prysm-1 | time="2022-09-22 14:08:36" level=info msg="Synced new block" block=0x8ca35479... epoch=148520 finalizedEpoch=148518 finalizedRoot=0xc2e272fd... prefix=blockchain slot=4752641
mainnet-prysm-1 | time="2022-09-22 14:08:36" level=info msg="Finished applying state transition" attestations=128 payloadHash=0x85ff763ada23 prefix=blockchain slot=4752641 syncBitsCount=486 txCount=56
mainnet-prysm-1 | time="2022-09-22 14:08:38" level=warning msg="Execution client is not syncing" prefix=powchain
mainnet-erigon-1 | [INFO] [09-22|14:08:39.321] [5/7 Execution] Completed on block=15589296
mainnet-erigon-1 | [INFO] [09-22|14:08:39.321] [6/7 HashState] Promoting plain state from=15589264 to=15589296
mainnet-erigon-1 | [INFO] [09-22|14:08:39.321] [6/7 HashState] Incremental promotion from=15589264 to=15589296 codes=true csbucket=AccountChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:08:39.474] [6/7 HashState] Incremental promotion from=15589264 to=15589296 codes=false csbucket=AccountChangeSet
it keeps cycling between these stages, so I guess that's why it is far behind the chain tip (it didn't complete all stages up to 16).
Later, it eventually triggered what appears to be the "normal" cycle (1-16):
mainnet-erigon-1 | [INFO] [09-22|14:58:45.670] [6/7 HashState] Incremental promotion from=15589502 to=15589534 codes=false csbucket=StorageChangeSet
mainnet-erigon-1 | [INFO] [09-22|14:58:45.800] [7/7 IntermediateHashes] Generating intermediate hashes from=15589502 to=15589534
mainnet-prysm-1 | time="2022-09-22 14:58:46" level=warning msg="Execution client is not syncing" prefix=powchain
mainnet-prysm-1 | time="2022-09-22 14:58:49" level=info msg="Called new payload with optimistic block" payloadBlockHash=0x2b447fc839ad prefix=blockchain slot=4752892
mainnet-prysm-1 | time="2022-09-22 14:58:49" level=info msg="Called fork choice updated with optimistic block" finalizedPayloadBlockHash=0x140526799bc6 headPayloadBlockHash=0x2b447fc839ad headSlot=4752892 prefix=blockchain
mainnet-prysm-1 | time="2022-09-22 14:58:49" level=info msg="Synced new block" block=0x3da5351a... epoch=148527 finalizedEpoch=148525 finalizedRoot=0x79b1d222... prefix=blockchain slot=4752892
mainnet-prysm-1 | time="2022-09-22 14:58:49" level=info msg="Finished applying state transition" attestations=128 payloadHash=0x2b447fc839ad prefix=blockchain slot=4752892 syncBitsCount=504 txCount=141
mainnet-erigon-1 | [INFO] [09-22|14:58:50.684] Timings (slower than 50ms) Bodies=1.974s Senders=97ms Execution=4.313s HashState=302ms IntermediateHashes=4.883s
mainnet-erigon-1 | [INFO] [09-22|14:58:50.684] Tables PlainState=968.0KB AccountChangeSet=552.0KB StorageChangeSet=920.0KB BlockTransaction=3.0MB TransactionLog=2.3MB FreeList=0B
mainnet-erigon-1 | [INFO] [09-22|14:58:50.902] PoS headers verified and saved requestId=143 fork head=0x8be1fa84d4df6adf42e62fbd0fb408e5668d26b0c438400497a65a7bb021b04a
mainnet-erigon-1 | [INFO] [09-22|14:58:50.902] [2/16 Headers] DONE in=4m26.323511504s
mainnet-erigon-1 | [INFO] [09-22|14:58:50.903] Timings (slower than 50ms) Headers=4m26.323s
mainnet-erigon-1 | [INFO] [09-22|14:58:50.903] Tables PlainState=74.4GB AccountChangeSet=163.9GB StorageChangeSet=242.3GB BlockTransaction=16.3GB TransactionLog=451.1GB FreeList=89.9MB ReclaimableSpace=89.9GB
mainnet-erigon-1 | [INFO] [09-22|14:58:51.163] Commit cycle in=259.403286ms
mainnet-erigon-1 | [INFO] [09-22|14:58:51.165] RPC Daemon notified of new headers from=15589502 to=15589604 header sending=968.439µs log sending=426ns
it stopped at stage 2, and then resumed (apparently) only after an unwind.
mainnet-erigon-1 | [INFO] [09-22|14:59:12.874] [2/16 Headers] Waiting for Consensus Layer...
mainnet-erigon-1 | [INFO] [09-22|14:59:12.919] [2/16 Headers] Fork choice re-org headerNumber=15589629 forkingPoint=15589502
mainnet-erigon-1 | [INFO] [09-22|14:59:12.919] UnwindTo block=15589502 bad_block_hash=0x0000000000000000000000000000000000000000000000000000000000000000
mainnet-erigon-1 | [INFO] [09-22|14:59:12.919] [2/16 Headers] Unsettled forkchoice after unwind height=15589629 forkchoice="&{HeadBlockHash:0xbcdb37aab9625356409b5a91a2fda99ee20c8da3c82a1b84509958148b74030d SafeBlockHash:0x0ef151599c038d600fa500a3eba652347f56fff01317c22f0befe3d67d87099f FinalizedBlockHash:0x140526799bc6f101236e3fd4ee15ce0ed31c8b04458925e34f3bff2a543ffee5}"
mainnet-prysm-1 | time="2022-09-22 14:59:12" level=info msg="Called fork choice updated with optimistic block" finalizedPayloadBlockHash=0x140526799bc6 headPayloadBlockHash=0xbcdb37aab962 headSlot=4752894 prefix=blockchain
mainnet-erigon-1 | [INFO] [09-22|14:59:12.922] [5/16 Bodies] Processing bodies... from=15589502 to=15589629
mainnet-prysm-1 | time="2022-09-22 14:59:12" level=info msg="Synced new block" block=0xca094975... epoch=148527 finalizedEpoch=148525 finalizedRoot=0x79b1d222... prefix=blockchain slot=4752894
mainnet-prysm-1 | time="2022-09-22 14:59:12" level=info msg="Finished applying state transition" attestations=66 payloadHash=0xbcdb37aab962 prefix=blockchain slot=4752894 syncBitsCount=507 txCount=210
mainnet-prysm-1 | time="2022-09-22 14:59:14" level=warning msg="Execution client is not syncing" prefix=powchain
mainnet-erigon-1 | [INFO] [09-22|14:59:15.762] [txpool] stat block=15589534 pending=8033 baseFee=30000 queued=29998 alloc=4.1GB sys=8.5GB
mainnet-prysm-1 | time="2022-09-22 14:59:23" level=info msg="Called new payload with optimistic block" payloadBlockHash=0x4991617ad2a2 prefix=blockchain slot=4752895
I'm facing the same exact issue D+1 from the merge.
I'm facing the similar issue too. Sometimes post-merge erigon EL stucked for some time. In my case I suppose that it could be related to lighthouse(CL). Here is issue that I've opened: https://github.com/sigp/lighthouse/issues/3615
Same here. CL is lighthouse and I'm running on c2655ad6ef2c063678dfc00c2dc4989b1b04ef24
Startup args:
--snap.stop --authrpc.jwtsecret /etc/ethereum/jwt.hex --authrpc.port 8553 --datadir /erigon --http=false --maxpeers 20 --ethash.dagdir /erigon/erigon-ethash --port 30305 --trustedpeers=enode://xxx
I'm running rpcdaemon as a separate process (but same happens with the embed rpc)
Logs:
[INFO] [09-27|22:43:14.341] [2/16 Headers] Waiting for Consensus Layer...
[INFO] [09-27|22:43:25.631] [5/7 Execution] Completed on block=15626255
[INFO] [09-27|22:43:26.164] Timings (slower than 50ms) Execution=820ms HashState=70ms IntermediateHashes=462ms
[INFO] [09-27|22:43:26.164] Tables PlainState=544.0KB AccountChangeSet=280.0KB StorageChangeSet=504.0KB BlockTransaction=1.5MB TransactionLog=1.2MB FreeList=0B
[INFO] [09-27|22:43:26.178] Timings (slower than 50ms) Headers=11.837s
[INFO] [09-27|22:43:26.178] Tables PlainState=74.7GB AccountChangeSet=164.5GB StorageChangeSet=243.4GB BlockTransaction=163.6GB TransactionLog=454.1GB FreeList=10.0MB ReclaimableSpace=10.0GB
[INFO] [09-27|22:43:26.180] Commit cycle in=1.543738ms
[INFO] [09-27|22:43:26.180] RPC Daemon notified of new headers from=15626240 to=15626255 header sending=13.526µs log sending=180ns
[INFO] [09-27|22:43:26.180] [2/16 Headers] Waiting for Consensus Layer...
[WARN] [09-27|22:43:26.323] Served conn=127.0.0.1:39918 method=engine_exchangeTransitionConfigurationV1 reqid=1 t=62.318µs err="the execution layer doesn't have a terminal total difficulty. expected: 0xc70d808a128d7380000"
[INFO] [09-27|22:43:36.457] [5/7 Execution] Completed on block=15626256
[INFO] [09-27|22:43:36.886] Timings (slower than 50ms) Execution=682ms HashState=66ms IntermediateHashes=363ms
[INFO] [09-27|22:43:36.886] Tables PlainState=548.0KB AccountChangeSet=284.0KB StorageChangeSet=508.0KB BlockTransaction=1.5MB TransactionLog=1.2MB FreeList=0B
[INFO] [09-27|22:43:36.901] Timings (slower than 50ms) Headers=10.72s
[INFO] [09-27|22:43:36.901] Tables PlainState=74.7GB AccountChangeSet=164.5GB StorageChangeSet=243.4GB BlockTransaction=163.6GB TransactionLog=454.1GB FreeList=10.0MB ReclaimableSpace=10.0GB
[INFO] [09-27|22:43:36.902] Commit cycle in=1.164692ms
[INFO] [09-27|22:43:36.902] RPC Daemon notified of new headers from=15626240 to=15626256 header sending=19.357µs log sending=270ns
[INFO] [09-27|22:43:36.902] [2/16 Headers] Waiting for Consensus Layer...
[INFO] [09-27|22:43:45.261] [txpool] stat block=15626256 pending=10000 baseFee=0 queued=27170 alloc=5.8GB sys=8.2GB
[INFO] [09-27|22:43:48.406] [4/7 Senders] Started from=15626240 to=15626257
[INFO] [09-27|22:43:48.455] [5/7 Execution] Blocks execution from=15626240 to=15626257
[INFO] [09-27|22:43:49.223] [5/7 Execution] Completed on block=15626257
[INFO] [09-27|22:43:49.223] [6/7 HashState] Promoting plain state from=15626240 to=15626257
[INFO] [09-27|22:43:49.223] [6/7 HashState] Incremental promotion from=15626240 to=15626257 codes=true csbucket=AccountChangeSet
[INFO] [09-27|22:43:49.242] [6/7 HashState] Incremental promotion from=15626240 to=15626257 codes=false csbucket=AccountChangeSet
[INFO] [09-27|22:43:49.261] [6/7 HashState] Incremental promotion from=15626240 to=15626257 codes=false csbucket=StorageChangeSet
[INFO] [09-27|22:43:49.297] [7/7 IntermediateHashes] Generating intermediate hashes from=15626240 to=15626257
[INFO] [09-27|22:43:49.721] Timings (slower than 50ms) Execution=768ms HashState=74ms IntermediateHashes=424ms
[INFO] [09-27|22:43:49.721] Tables PlainState=564.0KB AccountChangeSet=300.0KB StorageChangeSet=528.0KB BlockTransaction=1.6MB TransactionLog=1.3MB FreeList=0B
[INFO] [09-27|22:43:49.737] Timings (slower than 50ms) Headers=12.834s
[INFO] [09-27|22:43:49.737] Tables PlainState=74.7GB AccountChangeSet=164.5GB StorageChangeSet=243.4GB BlockTransaction=163.6GB TransactionLog=454.1GB FreeList=10.0MB ReclaimableSpace=10.0GB
[INFO] [09-27|22:43:49.738] Commit cycle in=1.51812ms
[INFO] [09-27|22:43:49.738] RPC Daemon notified of new headers from=15626240 to=15626257 header sending=14.206µs log sending=170ns
[INFO] [09-27|22:43:49.738] [2/16 Headers] Waiting for Consensus Layer...
[INFO] [09-27|22:44:01.045] [4/7 Senders] Started from=15626240 to=15626258
[INFO] [09-27|22:44:01.096] [5/7 Execution] Blocks execution from=15626240 to=15626258
[INFO] [09-27|22:44:02.030] [5/7 Execution] Completed on block=15626258
[INFO] [09-27|22:44:02.030] [6/7 HashState] Promoting plain state from=15626240 to=15626258
[INFO] [09-27|22:44:02.030] [6/7 HashState] Incremental promotion from=15626240 to=15626258 codes=true csbucket=AccountChangeSet
[INFO] [09-27|22:44:02.059] [6/7 HashState] Incremental promotion from=15626240 to=15626258 codes=false csbucket=AccountChangeSet
[INFO] [09-27|22:44:02.077] [6/7 HashState] Incremental promotion from=15626240 to=15626258 codes=false csbucket=StorageChangeSet
[INFO] [09-27|22:44:02.128] [7/7 IntermediateHashes] Generating intermediate hashes from=15626240 to=15626258
[INFO] [09-27|22:44:02.642] Timings (slower than 50ms) Senders=51ms Execution=933ms HashState=97ms IntermediateHashes=514ms
[INFO] [09-27|22:44:02.642] Tables PlainState=612.0KB AccountChangeSet=320.0KB StorageChangeSet=564.0KB BlockTransaction=1.7MB TransactionLog=1.4MB FreeList=0B
[INFO] [09-27|22:44:02.658] Timings (slower than 50ms) Headers=12.919s
[INFO] [09-27|22:44:02.658] Tables PlainState=74.7GB AccountChangeSet=164.5GB StorageChangeSet=243.4GB BlockTransaction=163.6GB TransactionLog=454.1GB FreeList=10.0MB ReclaimableSpace=10.0GB
[INFO] [09-27|22:44:02.659] Commit cycle in=1.863273ms
[INFO] [09-27|22:44:02.660] RPC Daemon notified of new headers from=15626240 to=15626258 header sending=16.171µs log sending=160ns
[INFO] [09-27|22:44:02.660] [2/16 Headers] Waiting for Consensus Layer...
[INFO] [09-27|22:44:12.850] [4/7 Senders] Started from=15626240 to=15626259
[INFO] [09-27|22:44:12.903] [5/7 Execution] Blocks execution from=15626240 to=15626259
[INFO] [09-27|22:44:13.864] [5/7 Execution] Completed on block=15626259
[INFO] [09-27|22:44:13.864] [6/7 HashState] Promoting plain state from=15626240 to=15626259
[INFO] [09-27|22:44:13.864] [6/7 HashState] Incremental promotion from=15626240 to=15626259 codes=true csbucket=AccountChangeSet
[INFO] [09-27|22:44:13.892] [6/7 HashState] Incremental promotion from=15626240 to=15626259 codes=false csbucket=AccountChangeSet
[INFO] [09-27|22:44:13.911] [6/7 HashState] Incremental promotion from=15626240 to=15626259 codes=false csbucket=StorageChangeSet
[INFO] [09-27|22:44:13.951] [7/7 IntermediateHashes] Generating intermediate hashes from=15626240 to=15626259
[INFO] [09-27|22:44:14.456] Timings (slower than 50ms) Senders=53ms Execution=961ms HashState=86ms IntermediateHashes=504ms
[INFO] [09-27|22:44:14.456] Tables PlainState=648.0KB AccountChangeSet=340.0KB StorageChangeSet=608.0KB BlockTransaction=1.8MB TransactionLog=1.5MB FreeList=0B
[INFO] [09-27|22:44:14.471] Timings (slower than 50ms) Headers=11.81s
[INFO] [09-27|22:44:14.471] Tables PlainState=74.7GB AccountChangeSet=164.5GB StorageChangeSet=243.4GB BlockTransaction=163.6GB TransactionLog=454.1GB FreeList=10.0MB ReclaimableSpace=10.0GB
[INFO] [09-27|22:44:14.473] Commit cycle in=1.733077ms
[INFO] [09-27|22:44:14.473] RPC Daemon notified of new headers from=15626240 to=15626259 header sending=15.91µs log sending=200ns
[INFO] [09-27|22:44:14.473] [2/16 Headers] Waiting for Consensus Layer...
[INFO] [09-27|22:44:24.756] [4/7 Senders] Started from=15626240 to=15626260
[INFO] [09-27|22:44:24.795] [5/7 Execution] Blocks execution from=15626240 to=15626260
[INFO] [09-27|22:44:25.819] [5/7 Execution] Completed on block=15626260
[INFO] [09-27|22:44:25.819] [6/7 HashState] Promoting plain state from=15626240 to=15626260
[INFO] [09-27|22:44:25.819] [6/7 HashState] Incremental promotion from=15626240 to=15626260 codes=true csbucket=AccountChangeSet
[INFO] [09-27|22:44:25.848] [6/7 HashState] Incremental promotion from=15626240 to=15626260 codes=false csbucket=AccountChangeSet
[INFO] [09-27|22:44:25.872] [6/7 HashState] Incremental promotion from=15626240 to=15626260 codes=false csbucket=StorageChangeSet
[INFO] [09-27|22:44:25.918] [7/7 IntermediateHashes] Generating intermediate hashes from=15626240 to=15626260
Probably related: It looks like RPC daemon "forgets" to notify about the new headers https://github.com/ledgerwatch/erigon/issues/5481#issuecomment-1262686681
Any updates here? @geomad, @Texnomic , @wmitsuda have you found the solution ?
I noticed (unless that's random and just luck) that with --snap.stop erigon is mostly in sync and sometimes 1 block behind the chain. Without it my RPC was falling behind up to 30 blocks (usually 6-10). Hope this helps debugging. Btw my machine is not weak, its 16 core 64GB ram gen4 ssd.
Any updates here? @geomad, @Texnomic , @wmitsuda have you found the solution ?
@AndriyAntonenko The situation is slightly better with 2022.10.02 release. It needs hours
of zero
RPC load to be In-Sync with CL Client. The preformance is still far from Erigon pre-merge.
This issue is stale because it has been open for 40 days with no activity. Remove stale label or comment, or this will be closed in 7 days.
This issue was closed because it has been stalled for 7 days with no activity.