erigon icon indicating copy to clipboard operation
erigon copied to clipboard

"received incorrect merkle index" logs on prysm + erigon

Open wmitsuda opened this issue 3 years ago • 3 comments

v2022.09.03 - mainnet + prysm 3.1.1

I don't know exactly what triggers it, I've seen it in the past, I think it healed by itself by restarting, opening this issue so it could be investigated further:

sample erigon logs:

INFO[09-25|22:53:24.991] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:53:25.056] [2/16 Headers] Fork choice re-org        headerNumber=15614389 forkingPoint=15614386
INFO[09-25|22:53:25.056] UnwindTo                                 block=15614386 bad_block_hash=0x0000000000000000000000000000000000000000000000000000000000000000
INFO[09-25|22:53:25.056] [2/16 Headers] Unsettled forkchoice after unwind height=15614389 forkchoice="&{HeadBlockHash:0x52f555eca2257ccee76db6b64e8f092f6b907423d0fbc6e6bc50d3053d35ae1e SafeBlockHash:0x19647b793fe0ed5957c14fe606f86de257c7492491e72bc70415e0a60e81321f FinalizedBlockHash:0xa03a81f6d9ba41dddcbd48578862269511c888c2e4345cc9acf2a1dec999af1a}"
INFO[09-25|22:53:25.359] [7/16 Execution] Completed on            block=15614389
INFO[09-25|22:53:26.555] Timings (slower than 50ms)               Headers=64ms Bodies=183ms Execution=109ms HashState=65ms IntermediateHashes=131ms CallTraces=236ms AccountHistoryIndex=161ms StorageHistoryIndex=295ms LogIndex=184ms TxLookup=120ms
INFO[09-25|22:53:26.555] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.6MB ReclaimableSpace=85.6GB
INFO[09-25|22:53:30.160] Commit cycle                             in=3.60486181s
INFO[09-25|22:53:30.160] RPC Daemon notified of new headers       from=15614386 to=15614389 header sending=13.238µs log sending=157ns
INFO[09-25|22:53:30.160] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:53:33.577] [txpool] stat                            block=15614389 pending=4554 baseFee=30000 queued=29999 alloc=4.6GB sys=10.2GB
INFO[09-25|22:53:36.708] [5/7 Execution] Completed on             block=15614390
INFO[09-25|22:53:37.163] Timings (slower than 50ms)               Execution=152ms IntermediateHashes=438ms
INFO[09-25|22:53:37.164] Tables                                   PlainState=48.0KB AccountChangeSet=24.0KB StorageChangeSet=28.0KB BlockTransaction=176.0KB TransactionLog=68.0KB FreeList=0B
INFO[09-25|22:53:37.165] Timings (slower than 50ms)               Headers=7.004s
INFO[09-25|22:53:37.165] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:53:37.167] Commit cycle                             in=2.079157ms
INFO[09-25|22:53:37.167] RPC Daemon notified of new headers       from=15614389 to=15614390 header sending=5.845µs log sending=220ns
INFO[09-25|22:53:37.167] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:53:37.237] Flushing in-memory state
INFO[09-25|22:53:38.518] Timings (slower than 50ms)               Headers=949ms CallTraces=100ms AccountHistoryIndex=78ms StorageHistoryIndex=85ms LogIndex=74ms TxLookup=63ms
INFO[09-25|22:53:38.519] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:53:40.213] Commit cycle                             in=1.694676714s
INFO[09-25|22:53:40.213] RPC Daemon notified of new headers       from=15614389 to=15614390 header sending=8.467µs log sending=170ns
INFO[09-25|22:53:40.213] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:53:48.300] [5/7 Execution] Completed on             block=15614391
INFO[09-25|22:53:48.329] Timings (slower than 50ms)               Headers=8.114s
INFO[09-25|22:53:48.329] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:53:48.331] Commit cycle                             in=2.103947ms
INFO[09-25|22:53:48.331] RPC Daemon notified of new headers       from=15614390 to=15614391 header sending=7.678µs log sending=140ns
INFO[09-25|22:53:48.331] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:53:48.376] Flushing in-memory state
INFO[09-25|22:53:48.450] Timings (slower than 50ms)               Headers=91ms
INFO[09-25|22:53:48.450] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:53:48.611] Commit cycle                             in=161.161772ms
INFO[09-25|22:53:48.611] RPC Daemon notified of new headers       from=15614390 to=15614391 header sending=12.383µs log sending=185ns
INFO[09-25|22:53:48.611] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:00.805] [5/7 Execution] Completed on             block=15614392
INFO[09-25|22:54:01.491] Timings (slower than 50ms)               Execution=313ms IntermediateHashes=658ms
INFO[09-25|22:54:01.491] Tables                                   PlainState=80.0KB AccountChangeSet=28.0KB StorageChangeSet=52.0KB BlockTransaction=128.0KB TransactionLog=136.0KB FreeList=0B
INFO[09-25|22:54:01.492] Timings (slower than 50ms)               Headers=12.88s
INFO[09-25|22:54:01.492] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:01.496] Commit cycle                             in=3.637767ms
INFO[09-25|22:54:01.496] RPC Daemon notified of new headers       from=15614391 to=15614392 header sending=14.754µs log sending=139ns
INFO[09-25|22:54:01.496] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:01.550] Flushing in-memory state
INFO[09-25|22:54:02.323] Timings (slower than 50ms)               Headers=182ms CallTraces=149ms AccountHistoryIndex=107ms StorageHistoryIndex=165ms LogIndex=126ms TxLookup=93ms
INFO[09-25|22:54:02.323] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:04.816] Commit cycle                             in=2.493248937s
INFO[09-25|22:54:04.816] RPC Daemon notified of new headers       from=15614391 to=15614392 header sending=15.327µs log sending=207ns
INFO[09-25|22:54:04.816] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:12.392] [5/7 Execution] Completed on             block=15614393
INFO[09-25|22:54:12.706] Timings (slower than 50ms)               Execution=137ms IntermediateHashes=303ms
INFO[09-25|22:54:12.707] Tables                                   PlainState=44.0KB AccountChangeSet=20.0KB StorageChangeSet=28.0KB BlockTransaction=84.0KB TransactionLog=84.0KB FreeList=0B
INFO[09-25|22:54:12.708] Timings (slower than 50ms)               Headers=7.89s
INFO[09-25|22:54:12.708] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:12.711] Commit cycle                             in=2.929208ms
INFO[09-25|22:54:12.711] RPC Daemon notified of new headers       from=15614392 to=15614393 header sending=5.831µs log sending=144ns
INFO[09-25|22:54:12.711] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:12.749] Flushing in-memory state
INFO[09-25|22:54:13.277] Timings (slower than 50ms)               Headers=250ms CallTraces=82ms AccountHistoryIndex=60ms StorageHistoryIndex=64ms LogIndex=63ms
INFO[09-25|22:54:13.277] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:14.790] Commit cycle                             in=1.512757742s
INFO[09-25|22:54:14.790] RPC Daemon notified of new headers       from=15614392 to=15614393 header sending=24.211µs log sending=161ns
INFO[09-25|22:54:14.790] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:23.776] [5/7 Execution] Completed on             block=15614394
INFO[09-25|22:54:23.931] Timings (slower than 50ms)               Execution=66ms IntermediateHashes=150ms
INFO[09-25|22:54:23.931] Tables                                   PlainState=24.0KB AccountChangeSet=16.0KB StorageChangeSet=20.0KB BlockTransaction=28.0KB TransactionLog=40.0KB FreeList=0B
INFO[09-25|22:54:23.932] Timings (slower than 50ms)               Headers=9.141s
INFO[09-25|22:54:23.932] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:23.936] Commit cycle                             in=3.679805ms
INFO[09-25|22:54:23.936] RPC Daemon notified of new headers       from=15614393 to=15614394 header sending=7.122µs log sending=137ns
INFO[09-25|22:54:23.936] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:23.978] Flushing in-memory state
INFO[09-25|22:54:24.180] Timings (slower than 50ms)               Headers=91ms
INFO[09-25|22:54:24.180] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:25.601] Commit cycle                             in=1.421092784s
INFO[09-25|22:54:25.601] RPC Daemon notified of new headers       from=15614393 to=15614394 header sending=9.379µs log sending=163ns
INFO[09-25|22:54:25.601] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:30.815] [p2p] GoodPeers                          eth66=29
INFO[09-25|22:54:33.613] [txpool] stat                            block=15614394 pending=4618 baseFee=30000 queued=29998 alloc=3.7GB sys=10.2GB
INFO[09-25|22:54:36.267] [5/7 Execution] Completed on             block=15614395
INFO[09-25|22:54:36.693] Timings (slower than 50ms)               Execution=179ms IntermediateHashes=411ms
INFO[09-25|22:54:36.694] Tables                                   PlainState=48.0KB AccountChangeSet=20.0KB StorageChangeSet=32.0KB BlockTransaction=80.0KB TransactionLog=72.0KB FreeList=0B
INFO[09-25|22:54:36.695] Timings (slower than 50ms)               Headers=11.092s
INFO[09-25|22:54:36.695] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:36.701] Commit cycle                             in=6.06574ms
INFO[09-25|22:54:36.701] RPC Daemon notified of new headers       from=15614394 to=15614395 header sending=64.148µs log sending=185ns
INFO[09-25|22:54:36.701] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:36.824] Flushing in-memory state
INFO[09-25|22:54:37.505] Timings (slower than 50ms)               Headers=275ms CallTraces=114ms AccountHistoryIndex=71ms StorageHistoryIndex=127ms LogIndex=149ms TxLookup=64ms
INFO[09-25|22:54:37.505] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:40.201] Commit cycle                             in=2.696235234s
INFO[09-25|22:54:40.202] RPC Daemon notified of new headers       from=15614394 to=15614395 header sending=9.688µs log sending=156ns
INFO[09-25|22:54:40.202] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:47.969] [5/7 Execution] Completed on             block=15614396
INFO[09-25|22:54:48.331] Timings (slower than 50ms)               Execution=125ms IntermediateHashes=347ms
INFO[09-25|22:54:48.331] Tables                                   PlainState=32.0KB AccountChangeSet=20.0KB StorageChangeSet=24.0KB BlockTransaction=48.0KB TransactionLog=44.0KB FreeList=0B
INFO[09-25|22:54:48.333] Timings (slower than 50ms)               Headers=8.13s
INFO[09-25|22:54:48.333] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:48.336] Commit cycle                             in=3.664727ms
INFO[09-25|22:54:48.336] RPC Daemon notified of new headers       from=15614395 to=15614396 header sending=5.59µs log sending=146ns
INFO[09-25|22:54:48.337] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:54:48.383] Flushing in-memory state
INFO[09-25|22:54:48.768] Timings (slower than 50ms)               Headers=133ms CallTraces=65ms AccountHistoryIndex=56ms StorageHistoryIndex=72ms LogIndex=56ms
INFO[09-25|22:54:48.768] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:54:50.662] Commit cycle                             in=1.893732764s
INFO[09-25|22:54:50.662] RPC Daemon notified of new headers       from=15614395 to=15614396 header sending=17.861µs log sending=361ns
INFO[09-25|22:54:50.662] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:55:01.427] [5/7 Execution] Completed on             block=15614397
INFO[09-25|22:55:02.131] Timings (slower than 50ms)               Execution=306ms IntermediateHashes=674ms
INFO[09-25|22:55:02.131] Tables                                   PlainState=76.0KB AccountChangeSet=28.0KB StorageChangeSet=52.0KB BlockTransaction=152.0KB TransactionLog=112.0KB FreeList=0B
INFO[09-25|22:55:02.133] Timings (slower than 50ms)               Headers=11.47s
INFO[09-25|22:55:02.133] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:55:02.138] Commit cycle                             in=4.394453ms
INFO[09-25|22:55:02.138] RPC Daemon notified of new headers       from=15614396 to=15614397 header sending=5.664µs log sending=145ns
INFO[09-25|22:55:02.138] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:55:02.179] Flushing in-memory state
INFO[09-25|22:55:03.192] Timings (slower than 50ms)               Headers=407ms CallTraces=144ms AccountHistoryIndex=97ms StorageHistoryIndex=188ms LogIndex=131ms TxLookup=83ms
INFO[09-25|22:55:03.192] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:55:16.999] Commit cycle                             in=13.80586527s
INFO[09-25|22:55:16.999] RPC Daemon notified of new headers       from=15614396 to=15614397 header sending=8.978µs log sending=158ns
INFO[09-25|22:55:16.999] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:55:24.861] [2/16 Headers] New payload: need to download parent height=15614399 hash=0xf2b1ed511e00138697fcac6c3930671462469a1e757485ef6ba161b8fd17da3c parentHash=0x982834adfba8458f510f33a97265e3508083129787c88ac4f8c5d25ff9eb0d96
INFO[09-25|22:55:24.861] [2/16 Headers] Downloading PoS headers... height=15614398 hash=0x982834adfba8458f510f33a97265e3508083129787c88ac4f8c5d25ff9eb0d96 requestId=1732
INFO[09-25|22:55:24.965] Timings (slower than 50ms)               Headers=7.964s
INFO[09-25|22:55:24.965] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:55:24.965] Commit cycle                             in=9.787µs
INFO[09-25|22:55:24.965] RPC Daemon notified of new headers       from=15614397 to=15614398 header sending=12.318µs log sending=296ns
INFO[09-25|22:55:28.462] [5/7 Execution] Completed on             block=15614398
INFO[09-25|22:55:28.562] Timings (slower than 50ms)               Bodies=603ms Execution=54ms IntermediateHashes=96ms
INFO[09-25|22:55:28.562] Tables                                   PlainState=16.0KB AccountChangeSet=8.0KB StorageChangeSet=12.0KB BlockTransaction=20.0KB TransactionLog=40.0KB FreeList=0B
INFO[09-25|22:55:28.593] PoS headers verified and saved           requestId=1732 fork head=0x322216cb28a929d85dc29984c68e22a9789b05ad761b5fa7649d8382ef5cec39
INFO[09-25|22:55:28.594] Timings (slower than 50ms)               Headers=3.627s
INFO[09-25|22:55:28.594] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:55:28.600] Commit cycle                             in=6.149634ms
INFO[09-25|22:55:28.600] RPC Daemon notified of new headers       from=15614397 to=15614398 header sending=8.33µs log sending=224ns
INFO[09-25|22:55:28.600] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:55:29.071] [5/7 Execution] Completed on             block=15614399
INFO[09-25|22:55:29.883] Timings (slower than 50ms)               Execution=448ms IntermediateHashes=768ms
INFO[09-25|22:55:29.883] Tables                                   PlainState=96.0KB AccountChangeSet=32.0KB StorageChangeSet=64.0KB BlockTransaction=168.0KB TransactionLog=180.0KB FreeList=0B
INFO[09-25|22:55:29.904] Timings (slower than 50ms)               Headers=1.303s
INFO[09-25|22:55:29.904] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:55:29.909] Commit cycle                             in=4.060576ms
INFO[09-25|22:55:29.909] RPC Daemon notified of new headers       from=15614397 to=15614399 header sending=8.567µs log sending=238ns
INFO[09-25|22:55:29.909] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:55:35.627] [5/7 Execution] Completed on             block=15614400
INFO[09-25|22:55:35.767] Timings (slower than 50ms)               Execution=113ms IntermediateHashes=127ms
INFO[09-25|22:55:35.767] Tables                                   PlainState=100.0KB AccountChangeSet=32.0KB StorageChangeSet=72.0KB BlockTransaction=180.0KB TransactionLog=188.0KB FreeList=0B
INFO[09-25|22:55:35.794] Timings (slower than 50ms)               Headers=5.884s
INFO[09-25|22:55:35.794] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:55:35.800] Commit cycle                             in=5.742731ms
INFO[09-25|22:55:35.800] RPC Daemon notified of new headers       from=15614397 to=15614400 header sending=7.105µs log sending=160ns
INFO[09-25|22:55:35.800] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:55:35.878] [2/16 Headers] Fork choice re-org        headerNumber=15614400 forkingPoint=15614397
INFO[09-25|22:55:35.878] UnwindTo                                 block=15614397 bad_block_hash=0x0000000000000000000000000000000000000000000000000000000000000000
INFO[09-25|22:55:35.878] [2/16 Headers] Unsettled forkchoice after unwind height=15614400 forkchoice="&{HeadBlockHash:0xc83d735c32762115e3a9ce33ae8df8153d7a93eabb23e2d6684147fa690e05ea SafeBlockHash:0x19647b793fe0ed5957c14fe606f86de257c7492491e72bc70415e0a60e81321f FinalizedBlockHash:0xa03a81f6d9ba41dddcbd48578862269511c888c2e4345cc9acf2a1dec999af1a}"
INFO[09-25|22:55:36.006] [7/16 Execution] Completed on            block=15614400
INFO[09-25|22:55:36.982] [txpool] stat                            block=15614399 pending=4535 baseFee=30000 queued=29978 alloc=4.1GB sys=10.2GB
INFO[09-25|22:55:37.098] Timings (slower than 50ms)               Headers=78ms Execution=108ms HashState=59ms IntermediateHashes=118ms CallTraces=210ms AccountHistoryIndex=124ms StorageHistoryIndex=282ms LogIndex=196ms TxLookup=99ms
INFO[09-25|22:55:37.098] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:55:44.292] Commit cycle                             in=7.193915489s
INFO[09-25|22:55:44.292] RPC Daemon notified of new headers       from=15614397 to=15614400 header sending=8.376µs log sending=215ns
INFO[09-25|22:55:44.293] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:55:48.557] [5/7 Execution] Completed on             block=15614401
INFO[09-25|22:55:48.969] Timings (slower than 50ms)               Execution=144ms IntermediateHashes=396ms
INFO[09-25|22:55:48.969] Tables                                   PlainState=48.0KB AccountChangeSet=24.0KB StorageChangeSet=32.0KB BlockTransaction=100.0KB TransactionLog=76.0KB FreeList=0B
INFO[09-25|22:55:48.970] Timings (slower than 50ms)               Headers=4.677s
INFO[09-25|22:55:48.970] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:55:48.976] Commit cycle                             in=5.410193ms
INFO[09-25|22:55:48.976] RPC Daemon notified of new headers       from=15614400 to=15614401 header sending=6.239µs log sending=152ns
INFO[09-25|22:55:48.976] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:55:49.021] Flushing in-memory state
INFO[09-25|22:55:49.513] Timings (slower than 50ms)               Headers=127ms CallTraces=106ms AccountHistoryIndex=82ms StorageHistoryIndex=79ms LogIndex=79ms TxLookup=61ms
INFO[09-25|22:55:49.513] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:55:53.121] Commit cycle                             in=3.60802793s
INFO[09-25|22:55:53.121] RPC Daemon notified of new headers       from=15614400 to=15614401 header sending=8.395µs log sending=156ns
INFO[09-25|22:55:53.121] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:00.761] [5/7 Execution] Completed on             block=15614402
INFO[09-25|22:56:01.200] Timings (slower than 50ms)               Execution=231ms IntermediateHashes=417ms
INFO[09-25|22:56:01.200] Tables                                   PlainState=68.0KB AccountChangeSet=24.0KB StorageChangeSet=48.0KB BlockTransaction=120.0KB TransactionLog=96.0KB FreeList=0B
INFO[09-25|22:56:01.201] Timings (slower than 50ms)               Headers=8.079s
INFO[09-25|22:56:01.201] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:56:01.207] Commit cycle                             in=5.662644ms
INFO[09-25|22:56:01.207] RPC Daemon notified of new headers       from=15614401 to=15614402 header sending=5.914µs log sending=143ns
INFO[09-25|22:56:01.207] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:01.268] Flushing in-memory state
INFO[09-25|22:56:01.807] Timings (slower than 50ms)               Headers=160ms CallTraces=118ms AccountHistoryIndex=69ms StorageHistoryIndex=103ms LogIndex=80ms TxLookup=67ms
INFO[09-25|22:56:01.807] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:56:06.039] Commit cycle                             in=4.232271541s
INFO[09-25|22:56:06.039] RPC Daemon notified of new headers       from=15614401 to=15614402 header sending=8.85µs log sending=208ns
INFO[09-25|22:56:06.041] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:11.668] [5/7 Execution] Completed on             block=15614403
INFO[09-25|22:56:11.701] Timings (slower than 50ms)               Headers=5.659s
INFO[09-25|22:56:11.701] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:56:11.705] Commit cycle                             in=4.208727ms
INFO[09-25|22:56:11.705] RPC Daemon notified of new headers       from=15614402 to=15614403 header sending=5.272µs log sending=189ns
INFO[09-25|22:56:11.705] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:11.780] Flushing in-memory state
INFO[09-25|22:56:11.843] Timings (slower than 50ms)               Headers=108ms
INFO[09-25|22:56:11.843] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:56:12.143] Commit cycle                             in=300.130173ms
INFO[09-25|22:56:12.143] RPC Daemon notified of new headers       from=15614402 to=15614403 header sending=8.787µs log sending=159ns
INFO[09-25|22:56:12.143] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:24.689] [5/7 Execution] Completed on             block=15614404
INFO[09-25|22:56:25.369] Timings (slower than 50ms)               Execution=282ms IntermediateHashes=648ms
INFO[09-25|22:56:25.369] Tables                                   PlainState=72.0KB AccountChangeSet=28.0KB StorageChangeSet=48.0KB BlockTransaction=128.0KB TransactionLog=116.0KB FreeList=0B
INFO[09-25|22:56:25.370] Timings (slower than 50ms)               Headers=13.225s
INFO[09-25|22:56:25.370] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:56:25.376] Commit cycle                             in=5.942369ms
INFO[09-25|22:56:25.376] RPC Daemon notified of new headers       from=15614403 to=15614404 header sending=26.579µs log sending=143ns
INFO[09-25|22:56:25.376] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:25.412] Flushing in-memory state
INFO[09-25|22:56:26.182] Timings (slower than 50ms)               Headers=212ms CallTraces=143ms AccountHistoryIndex=100ms StorageHistoryIndex=167ms LogIndex=104ms TxLookup=77ms
INFO[09-25|22:56:26.182] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.7MB ReclaimableSpace=85.7GB
INFO[09-25|22:56:30.817] [p2p] GoodPeers                          eth66=32
INFO[09-25|22:56:32.754] Commit cycle                             in=6.572231123s
INFO[09-25|22:56:32.754] RPC Daemon notified of new headers       from=15614403 to=15614404 header sending=32.194µs log sending=170ns
INFO[09-25|22:56:32.755] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:33.589] [txpool] stat                            block=15614404 pending=4534 baseFee=30000 queued=30000 alloc=3.7GB sys=10.2GB
INFO[09-25|22:56:36.913] [5/7 Execution] Completed on             block=15614405
INFO[09-25|22:56:37.274] Timings (slower than 50ms)               Execution=188ms IntermediateHashes=335ms
INFO[09-25|22:56:37.274] Tables                                   PlainState=40.0KB AccountChangeSet=20.0KB StorageChangeSet=28.0KB BlockTransaction=108.0KB TransactionLog=76.0KB FreeList=0B
INFO[09-25|22:56:37.275] Timings (slower than 50ms)               Headers=4.52s
INFO[09-25|22:56:37.275] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:56:37.279] Commit cycle                             in=3.72534ms
INFO[09-25|22:56:37.279] RPC Daemon notified of new headers       from=15614404 to=15614405 header sending=21.356µs log sending=146ns
INFO[09-25|22:56:37.279] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:37.329] Flushing in-memory state
INFO[09-25|22:56:38.865] Timings (slower than 50ms)               Headers=1.288s CallTraces=69ms AccountHistoryIndex=50ms StorageHistoryIndex=84ms LogIndex=58ms
INFO[09-25|22:56:38.865] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:56:42.812] Commit cycle                             in=3.947183419s
INFO[09-25|22:56:42.812] RPC Daemon notified of new headers       from=15614404 to=15614405 header sending=8.108µs log sending=156ns
INFO[09-25|22:56:42.812] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:49.082] [5/7 Execution] Completed on             block=15614406
INFO[09-25|22:56:49.511] Timings (slower than 50ms)               Execution=190ms IntermediateHashes=412ms
INFO[09-25|22:56:49.511] Tables                                   PlainState=48.0KB AccountChangeSet=20.0KB StorageChangeSet=32.0KB BlockTransaction=72.0KB TransactionLog=72.0KB FreeList=0B
INFO[09-25|22:56:49.512] Timings (slower than 50ms)               Headers=6.699s
INFO[09-25|22:56:49.512] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:56:49.516] Commit cycle                             in=3.961281ms
INFO[09-25|22:56:49.516] RPC Daemon notified of new headers       from=15614405 to=15614406 header sending=5.745µs log sending=162ns
INFO[09-25|22:56:49.516] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:49.561] Flushing in-memory state
INFO[09-25|22:56:50.009] Timings (slower than 50ms)               Headers=128ms CallTraces=94ms AccountHistoryIndex=59ms StorageHistoryIndex=97ms LogIndex=62ms TxLookup=50ms
INFO[09-25|22:56:50.009] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:56:56.629] Commit cycle                             in=6.619646923s
INFO[09-25|22:56:56.629] RPC Daemon notified of new headers       from=15614405 to=15614406 header sending=12.919µs log sending=185ns
INFO[09-25|22:56:56.629] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:59.666] [5/7 Execution] Completed on             block=15614407
INFO[09-25|22:56:59.715] Timings (slower than 50ms)               Headers=3.085s
INFO[09-25|22:56:59.715] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:56:59.719] Commit cycle                             in=3.720801ms
INFO[09-25|22:56:59.719] RPC Daemon notified of new headers       from=15614406 to=15614407 header sending=18.908µs log sending=382ns
INFO[09-25|22:56:59.719] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:56:59.800] Flushing in-memory state
INFO[09-25|22:56:59.876] Timings (slower than 50ms)               Headers=114ms
INFO[09-25|22:56:59.876] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:57:00.180] Commit cycle                             in=303.638361ms
INFO[09-25|22:57:00.180] RPC Daemon notified of new headers       from=15614406 to=15614407 header sending=8.708µs log sending=170ns
INFO[09-25|22:57:00.180] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:57:12.696] [5/7 Execution] Completed on             block=15614408
INFO[09-25|22:57:13.171] Timings (slower than 50ms)               Execution=267ms IntermediateHashes=457ms
INFO[09-25|22:57:13.171] Tables                                   PlainState=48.0KB AccountChangeSet=24.0KB StorageChangeSet=32.0KB BlockTransaction=124.0KB TransactionLog=80.0KB FreeList=0B
INFO[09-25|22:57:13.173] Timings (slower than 50ms)               Headers=12.992s
INFO[09-25|22:57:13.173] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:57:13.179] Commit cycle                             in=6.631609ms
INFO[09-25|22:57:13.179] RPC Daemon notified of new headers       from=15614407 to=15614408 header sending=14.306µs log sending=148ns
INFO[09-25|22:57:13.179] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:57:13.245] Flushing in-memory state
INFO[09-25|22:57:13.843] Timings (slower than 50ms)               Headers=244ms CallTraces=107ms AccountHistoryIndex=70ms StorageHistoryIndex=104ms LogIndex=55ms TxLookup=80ms
INFO[09-25|22:57:13.843] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:57:20.662] Commit cycle                             in=6.818766578s
INFO[09-25|22:57:20.662] RPC Daemon notified of new headers       from=15614407 to=15614408 header sending=15.652µs log sending=194ns
INFO[09-25|22:57:20.662] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:57:25.086] [5/7 Execution] Completed on             block=15614409
INFO[09-25|22:57:26.389] Timings (slower than 50ms)               Execution=324ms IntermediateHashes=1.266s
INFO[09-25|22:57:26.389] Tables                                   PlainState=88.0KB AccountChangeSet=44.0KB StorageChangeSet=52.0KB BlockTransaction=168.0KB TransactionLog=188.0KB FreeList=0B
INFO[09-25|22:57:26.391] Timings (slower than 50ms)               Headers=5.728s
INFO[09-25|22:57:26.391] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:57:26.397] Commit cycle                             in=5.429285ms
INFO[09-25|22:57:26.397] RPC Daemon notified of new headers       from=15614408 to=15614409 header sending=6.385µs log sending=222ns
INFO[09-25|22:57:26.397] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:57:26.456] Flushing in-memory state
INFO[09-25|22:57:28.109] Timings (slower than 50ms)               Headers=419ms CallTraces=354ms AccountHistoryIndex=309ms StorageHistoryIndex=152ms LogIndex=253ms TxLookup=222ms
INFO[09-25|22:57:28.109] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:57:33.577] [txpool] stat                            block=15614409 pending=4616 baseFee=30000 queued=29997 alloc=4.1GB sys=10.2GB
INFO[09-25|22:57:35.813] Commit cycle                             in=7.703306161s
INFO[09-25|22:57:35.813] RPC Daemon notified of new headers       from=15614408 to=15614409 header sending=32.072µs log sending=154ns
INFO[09-25|22:57:35.813] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:57:36.557] [5/7 Execution] Completed on             block=15614410
INFO[09-25|22:57:36.885] Timings (slower than 50ms)               Execution=61ms IntermediateHashes=321ms
INFO[09-25|22:57:36.886] Tables                                   PlainState=28.0KB AccountChangeSet=20.0KB StorageChangeSet=20.0KB BlockTransaction=56.0KB TransactionLog=36.0KB FreeList=0B
INFO[09-25|22:57:36.887] Timings (slower than 50ms)               Headers=1.072s
INFO[09-25|22:57:36.887] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:57:36.890] Commit cycle                             in=3.247779ms
INFO[09-25|22:57:36.890] RPC Daemon notified of new headers       from=15614409 to=15614410 header sending=5.893µs log sending=146ns
INFO[09-25|22:57:36.890] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:57:36.926] Flushing in-memory state
INFO[09-25|22:57:37.245] Timings (slower than 50ms)               Headers=97ms CallTraces=81ms AccountHistoryIndex=69ms TxLookup=51ms
INFO[09-25|22:57:37.245] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:57:38.930] Commit cycle                             in=1.684798988s
INFO[09-25|22:57:38.930] RPC Daemon notified of new headers       from=15614409 to=15614410 header sending=8.58µs log sending=147ns
INFO[09-25|22:57:38.930] [2/16 Headers] Waiting for Consensus Layer...
INFO[09-25|22:57:49.592] [5/7 Execution] Completed on             block=15614411
INFO[09-25|22:57:50.251] Timings (slower than 50ms)               Execution=310ms IntermediateHashes=631ms
INFO[09-25|22:57:50.252] Tables                                   PlainState=64.0KB AccountChangeSet=28.0KB StorageChangeSet=44.0KB BlockTransaction=196.0KB TransactionLog=112.0KB FreeList=0B
INFO[09-25|22:57:50.253] Timings (slower than 50ms)               Headers=11.32s
INFO[09-25|22:57:50.253] Tables                                   PlainState=74.7GB AccountChangeSet=164.3GB StorageChangeSet=243.0GB BlockTransaction=18.4GB TransactionLog=453.1GB FreeList=85.8MB ReclaimableSpace=85.8GB
INFO[09-25|22:57:50.260] Commit cycle                             in=6.660964ms
INFO[09-25|22:57:50.260] RPC Daemon notified of new headers       from=15614410 to=15614411 header sending=7.015µs log sending=149ns

sample prysm logs (same time range):

[2022-09-26 01:53:48]  INFO blockchain: Synced new block block=0xfc1a34c4... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777767
[2022-09-26 01:53:48]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0x19524ed7855c slot=4777767 syncBitsCount=503 txCount=13
[2022-09-26 01:54:00]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4452
[2022-09-26 01:54:00] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:54:04]  INFO blockchain: Synced new block block=0x5ac182a3... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777768
[2022-09-26 01:54:04]  INFO blockchain: Finished applying state transition attestations=66 payloadHash=0x5c2dc4268ac1 slot=4777768 syncBitsCount=509 txCount=263
[2022-09-26 01:54:11]  INFO p2p: Peer summary activePeers=46 inbound=0 outbound=46
[2022-09-26 01:54:14]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4453
[2022-09-26 01:54:14] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:54:14]  INFO blockchain: Synced new block block=0xea9fce8a... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777769
[2022-09-26 01:54:14]  INFO blockchain: Finished applying state transition attestations=70 payloadHash=0x5a07d3039a69 slot=4777769 syncBitsCount=500 txCount=133
[2022-09-26 01:54:25]  INFO blockchain: Synced new block block=0xa6e2638f... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777770
[2022-09-26 01:54:25]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0xd15c98e69b1a slot=4777770 syncBitsCount=501 txCount=51
[2022-09-26 01:54:28]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4455
[2022-09-26 01:54:28] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:54:40]  INFO blockchain: Synced new block block=0xd73e90b9... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777771
[2022-09-26 01:54:40]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0x780bf0491edd slot=4777771 syncBitsCount=507 txCount=136
[2022-09-26 01:54:42]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4456
[2022-09-26 01:54:42] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:54:50]  INFO blockchain: Synced new block block=0x64b409c1... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777772
[2022-09-26 01:54:50]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0xfc31d8f727d2 slot=4777772 syncBitsCount=507 txCount=128
[2022-09-26 01:54:56]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4457
[2022-09-26 01:54:56] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:55:08] ERROR blockchain: received an undefined ee error error=timeout from http.Client
[2022-09-26 01:55:08]  INFO blockchain: Synced new block block=0x2a10277a... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777773
[2022-09-26 01:55:08]  INFO blockchain: Finished applying state transition attestations=71 payloadHash=0x322216cb28a9 slot=4777773 syncBitsCount=508 txCount=242
[2022-09-26 01:55:10]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4457
[2022-09-26 01:55:10] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:55:11]  INFO p2p: Peer summary activePeers=45 inbound=0 outbound=45
[2022-09-26 01:55:12]  INFO blockchain: Called new payload with optimistic block payloadBlockHash=0x982834adfba8 slot=4777774
[2022-09-26 01:55:17]  INFO blockchain: Called fork choice updated with optimistic block finalizedPayloadBlockHash=0xa03a81f6d9ba headPayloadBlockHash=0x982834adfba8 headSlot=4777774
[2022-09-26 01:55:17]  INFO blockchain: Synced new block block=0xb2bbd83d... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777774
[2022-09-26 01:55:17]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0x982834adfba8 slot=4777774 syncBitsCount=499 txCount=55
[2022-09-26 01:55:24]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4458
[2022-09-26 01:55:24] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:55:24]  INFO blockchain: Called new payload with optimistic block payloadBlockHash=0xf2b1ed511e00 slot=4777775
[2022-09-26 01:55:25]  INFO blockchain: Called fork choice updated with optimistic block finalizedPayloadBlockHash=0xa03a81f6d9ba headPayloadBlockHash=0xf2b1ed511e00 headSlot=4777775
[2022-09-26 01:55:25]  INFO blockchain: Synced new block block=0xe8e05232... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777775
[2022-09-26 01:55:25]  INFO blockchain: Finished applying state transition attestations=120 payloadHash=0xf2b1ed511e00 slot=4777775 syncBitsCount=508 txCount=221
[2022-09-26 01:55:38]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4458
[2022-09-26 01:55:38] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:55:41] ERROR blockchain: received an undefined ee error error=timeout from http.Client
[2022-09-26 01:55:41]  INFO blockchain: Synced new block block=0x8984c219... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777776
[2022-09-26 01:55:41]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0xc83d735c3276 slot=4777776 syncBitsCount=495 txCount=18
[2022-09-26 01:55:52]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4461
[2022-09-26 01:55:52] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:55:53]  INFO blockchain: Synced new block block=0xbcacf733... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777777
[2022-09-26 01:55:53]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0xc88dc195578f slot=4777777 syncBitsCount=506 txCount=182
[2022-09-26 01:56:06]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4462
[2022-09-26 01:56:06] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:56:06]  INFO blockchain: Synced new block block=0x792c24e2... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777778
[2022-09-26 01:56:06]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0xa35d34af766e slot=4777778 syncBitsCount=506 txCount=197
[2022-09-26 01:56:11]  INFO p2p: Peer summary activePeers=46 inbound=0 outbound=46
[2022-09-26 01:56:12]  INFO blockchain: Synced new block block=0x242324c2... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777779
[2022-09-26 01:56:12]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0x38cf8701c7ed slot=4777779 syncBitsCount=505 txCount=14
[2022-09-26 01:56:20]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4464
[2022-09-26 01:56:20] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:56:31] ERROR blockchain: received an undefined ee error error=timeout from http.Client
[2022-09-26 01:56:31]  INFO blockchain: Synced new block block=0xa6d52a81... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777780
[2022-09-26 01:56:31]  INFO blockchain: Finished applying state transition attestations=78 payloadHash=0x04e1d43cc8d3 slot=4777780 syncBitsCount=509 txCount=230
[2022-09-26 01:56:34]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4465
[2022-09-26 01:56:34] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:56:42]  INFO blockchain: Synced new block block=0x4af3cfed... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777781
[2022-09-26 01:56:42]  INFO blockchain: Finished applying state transition attestations=70 payloadHash=0x7fdc07d4e49f slot=4777781 syncBitsCount=504 txCount=99
[2022-09-26 01:56:48]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4466
[2022-09-26 01:56:48] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:56:55] ERROR blockchain: received an undefined ee error error=timeout from http.Client
[2022-09-26 01:56:55]  INFO blockchain: Synced new block block=0xa4c8d747... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777782
[2022-09-26 01:56:55]  INFO blockchain: Finished applying state transition attestations=128 payloadHash=0xd1cf900f6110 slot=4777782 syncBitsCount=505 txCount=155
[2022-09-26 01:57:00]  INFO blockchain: Synced new block block=0xd63d6eb8... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777783
[2022-09-26 01:57:00]  INFO blockchain: Finished applying state transition attestations=119 payloadHash=0x6de7609057d7 slot=4777783 syncBitsCount=504 txCount=15
[2022-09-26 01:57:02]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4468
[2022-09-26 01:57:02] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:57:10]  INFO p2p: Peer summary activePeers=43 inbound=0 outbound=43
[2022-09-26 01:57:15]  INFO powchain: Falling back to historical headers and logs sync. Current difference is 4468
[2022-09-26 01:57:16] ERROR powchain: Could not process deposit log: received incorrect merkle index: wanted 443538 but got 443938
[2022-09-26 01:57:19] ERROR blockchain: received an undefined ee error error=timeout from http.Client
[2022-09-26 01:57:19]  INFO blockchain: Synced new block block=0xa8874dc2... epoch=149305 finalizedEpoch=149303 finalizedRoot=0x7e100101... slot=4777784
[2022-09-26 01:57:19]  INFO blockchain: Finished applying state transition attestations=64 payloadHash=0x7fbb03102f41 slot=4777784 syncBitsCount=500 txCount=230

wmitsuda avatar Sep 26 '22 02:09 wmitsuda

I'll stop both processes and restart, let me know if you need more info so I can pay attention the next time it happens.

wmitsuda avatar Sep 26 '22 02:09 wmitsuda

and yes, there are timeouts on prysm logs, I remember someone was reporting timeouts on erigon discord and I mentioned I've seen that too, not sure if they are related, but that's what I've seen so far.

wmitsuda avatar Sep 26 '22 02:09 wmitsuda

adding that this is happening to me as well, pretty regularly, so it's not uncommon, at the very least

it seems to happen when erigon is attempting to catch up / sync, so perhaps it is just a race/timeout based on when prysm/erigon can and can't handle certain actions?

elee1766 avatar Oct 14 '22 08:10 elee1766

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.

github-actions[bot] avatar Nov 24 '22 02:11 github-actions[bot]

This issue was closed because it has been stalled for 7 days with no activity.

github-actions[bot] avatar Dec 01 '22 03:12 github-actions[bot]