err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2" #387

pc-quiknode · 2024-05-09T09:20:53Z

System information

Erigon version: erigon version 1.2.7-dev

OS & Version: Linux

Commit hash: 1c9e207

Issue

Our nodes are stuck in a loop of [5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2

[2/15 Headers] Waiting for headers...    from=40177466
[2/15 Headers] Processed                 highest=40177533 age=53s headers=67 in=0.128 blk/sec=523
[5/15 Bodies] Processing bodies...       from=40177466 to=40177533
Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2"
[2/15 Headers] Waiting for headers...    from=40177466
[2/15 Headers] Processed                 highest=40177554 age=2s headers=88 in=0.118 blk/sec=745
[5/15 Bodies] Processing bodies...       from=40177466 to=40177554
Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2"
[2/15 Headers] Waiting for headers...    from=40177466
[2/15 Headers] Processed                 highest=40177557 age=1s headers=91 in=0.158 blk/sec=577
[5/15 Bodies] Processing bodies...       from=40177466 to=40177557
Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2"
[2/15 Headers] Waiting for headers...    from=40177466
[2/15 Headers] Processed                 highest=40177560 age=3s headers=94 in=0.125 blk/sec=750
[5/15 Bodies] Processing bodies...       from=40177466 to=40177560
Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2"
[2/15 Headers] Waiting for headers...    from=40177466
[2/15 Headers] Processed                 highest=40177564 age=2s headers=98 in=0.130 blk/sec=753
[5/15 Bodies] Processing bodies...       from=40177466 to=40177564

The text was updated successfully, but these errors were encountered:

harshsingh-cs · 2024-05-09T09:23:08Z

Facing the same issue

blxdyx · 2024-05-09T09:25:51Z

Try restart?

harshsingh-cs · 2024-05-09T09:27:01Z

@blxdyx Tried did not help
Actually the [EROR] [05-09|09:12:01.705] Staged Sync err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:4" appeared after restart
Before it was

 err="failed MdbxKV cursor.Seek(): mdbx_cursor_get: MDBX_BAD_VALSIZE: Invalid size or alignment of key or data for target database, either invalid subDB name, bucket: PoolTransaction,  key: 292f5c308341e0d92e6327f0daf26bfb02e242d0d7a1f418cec61ac34e23be7e"
[WARN] [05-09|08:53:29.175] [rpc] served                             conn=10.100.26.88:33974 method=eth_feeHistory reqid=6369023567291614 t=302.945µs err="request beyond head block: requested 40177058, head 40177056"
[WARN] [05-09|08:53:29.282] [rpc] served                             conn=10.100.26.88:33974 method=eth_feeHistory reqid=4716567559346192 t=376.484µs err="request beyond head block: requested 40177057, head 40177056"
[INFO] [05-09|08:53:29.408] [2/15 Headers] Waiting for headers...    from=40177056
[WARN] [05-09|08:53:29.412] [rpc] served                             conn=10.100.26.88:33974 method=eth_feeHistory reqid=7345505564336888 t=307.732µs err="request beyond head block: requested 40177058, head 40177056"
[WARN] [05-09|08:53:29.429] [rpc] served                             conn=10.100.26.88:33974 method=eth_feeHistory reqid=3608448839414913 t=407.434µs err="request beyond head block: requested 40177058, head 40177056"
[WARN] [05-09|08:53:29.504] [downloader] Rejected header marked as bad hash=0xd9a63d09204e68780f80a852cd49a44a00019cd607d370264373464920ede0ef height=40177057
[WARN] [05-09|08:53:29.505] [downloader] Rejected header marked as bad

blxdyx · 2024-05-09T09:52:06Z

Reproduced, checking

blxdyx · 2024-05-09T11:11:25Z

temporary fix:
integration state_stages --unwind=20 --chain=bsc --datadir=/path
integration stage_headers --unwind=20 --chain=bsc --datadir=/path
then restart

use v1.2.6

Zorato · 2024-05-09T11:44:29Z

Unwinding resolved the issue. Using v1.2.7 on BSC testnet.

harshsingh-cs · 2024-05-09T12:01:01Z

It did not help :(

INFO] [05-09|11:53:19.108] [txpool] stat                            pending=0 baseFee=0 queued=2690 alloc=158.6MB sys=564.5MB
[WARN] [05-09|11:53:59.919] Caller gas above allowance, capping      requested=69998932 cap=50000000
[INFO] [05-09|11:54:03.179] [13/15 LogIndex] processing              from=40177037 to=40180460
[INFO] [05-09|11:54:34.041] [13/15 LogIndex] ETL [2/2] Loading       into=LogTopicIndex current_prefix=000000000000000000000000f8cee87a2bb8f3dd618f7ef5725c7e1934d58e35ffffffff
[WARN] [05-09|11:54:37.479] Caller gas above allowance, capping      requested=69998932 cap=50000000
[INFO] [05-09|11:55:27.147] [14/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current_prefix=7f2e7beb
[INFO] [05-09|11:55:57.152] [14/15 TxLookup] ETL [2/2] Loading       into=BlockTransactionLookup current_prefix=fbae26c5
[INFO] [05-09|11:55:58.082] [14/15 TxLookup] DONE                    in=1m2.176015683s
[INFO] [05-09|11:55:58.950] RPC Daemon notified of new headers       from=40179436 to=40180460 amount=1024 hash=0xf702deb0c8c7d3f58a84826d52ad48d2c4656d63e797203e8c7f6595f09b6dfc header sending=1.478421ms log sending=500.908732ms
[INFO] [05-09|11:55:58.950] Timings (slower than 50ms)               Headers=7.128s BlockHashes=2.524s Bodies=3m20.286s Senders=803ms Execution=1m50.81s HashState=51.507s IntermediateHashes=1m58.093s CallTraces=40.845s AccountHistoryIndex=30.321s StorageHistoryIndex=21.733s LogIndex=52.727s TxLookup=1m2.176s
[INFO] [05-09|11:55:58.950] Tables                                   PlainState=41.6GB AccountChangeSet=28.7GB StorageChangeSet=92.3GB BlockTransaction=216.0GB TransactionLog=196.2GB FreeList=112.0KB ReclaimableSpace=112.0MB
[INFO] [05-09|11:55:59.655] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:56:00.454] [2/15 Headers] Processed                 highest=40180691 age=1s headers=231 in=0.800 blk/sec=288
[INFO] [05-09|11:56:00.605] [5/15 Bodies] Processing bodies...       from=40180460 to=40180691
[EROR] [05-09|11:56:06.741] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:56:07.966] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:56:08.468] [2/15 Headers] Processed                 highest=40180694 age=0 headers=234 in=0.502 blk/sec=466
[INFO] [05-09|11:56:08.472] [5/15 Bodies] Processing bodies...       from=40180460 to=40180694
[INFO] [05-09|11:56:12.045] [p2p] GoodPeers                          eth68=4
[INFO] [05-09|11:56:12.494] [mem] memory stats                       Rss=8.1MB Size=0B Pss=8.1MB SharedClean=4B SharedDirty=0B PrivateClean=7.7MB PrivateDirty=394.7KB Referenced=8.1MB Anonymous=395.2KB Swap=0B alloc=139.5MB sys=564.5MB
[EROR] [05-09|11:56:14.381] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:56:15.566] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:56:17.312] [2/15 Headers] Processed                 highest=40180697 age=0 headers=237 in=1.746 blk/sec=135
[INFO] [05-09|11:56:17.316] [5/15 Bodies] Processing bodies...       from=40180460 to=40180697
[INFO] [05-09|11:56:19.107] [txpool] stat                            pending=0 baseFee=0 queued=3349 alloc=185.8MB sys=564.5MB
[WARN] [05-09|11:56:23.179] Caller gas above allowance, capping      requested=70000000 cap=50000000
[EROR] [05-09|11:56:25.249] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:56:26.451] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:56:28.072] [2/15 Headers] Processed                 highest=40180700 age=2s headers=240 in=1.622 blk/sec=147
[INFO] [05-09|11:56:28.077] [5/15 Bodies] Processing bodies...       from=40180460 to=40180700
[EROR] [05-09|11:56:33.457] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:56:34.680] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:56:35.269] [2/15 Headers] Processed                 highest=40180703 age=0 headers=243 in=0.589 blk/sec=412
[INFO] [05-09|11:56:35.274] [5/15 Bodies] Processing bodies...       from=40180460 to=40180703
[EROR] [05-09|11:56:41.248] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:56:42.552] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:56:44.173] [2/15 Headers] Processed                 highest=40180706 age=0 headers=246 in=1.621 blk/sec=151
[INFO] [05-09|11:56:44.177] [5/15 Bodies] Processing bodies...       from=40180460 to=40180706
[EROR] [05-09|11:56:49.474] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:56:50.962] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:56:52.760] [2/15 Headers] Processed                 highest=40180708 age=2s headers=248 in=1.799 blk/sec=137
[INFO] [05-09|11:56:52.765] [5/15 Bodies] Processing bodies...       from=40180460 to=40180708
[EROR] [05-09|11:56:58.676] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:56:59.830] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:57:01.605] [2/15 Headers] Processed                 highest=40180711 age=2s headers=251 in=1.775 blk/sec=141
[INFO] [05-09|11:57:01.610] [5/15 Bodies] Processing bodies...       from=40180460 to=40180711
[EROR] [05-09|11:57:09.944] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:57:11.351] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:57:12.489] [2/15 Headers] Processed                 highest=40180715 age=1s headers=255 in=1.138 blk/sec=224
[INFO] [05-09|11:57:12.495] [5/15 Bodies] Processing bodies...       from=40180460 to=40180715
[EROR] [05-09|11:57:20.961] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:57:22.143] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:57:23.297] [2/15 Headers] Processed                 highest=40180719 age=0 headers=259 in=1.154 blk/sec=224
[INFO] [05-09|11:57:23.302] [5/15 Bodies] Processing bodies...       from=40180460 to=40180719
[EROR] [05-09|11:57:32.005] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:57:33.203] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:57:34.946] [2/15 Headers] Processed                 highest=40180722 age=2s headers=262 in=1.742 blk/sec=150
[INFO] [05-09|11:57:34.954] [5/15 Bodies] Processing bodies...       from=40180460 to=40180722
[EROR] [05-09|11:57:42.512] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:57:43.649] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:57:44.420] [2/15 Headers] Processed                 highest=40180726 age=0 headers=266 in=0.771 blk/sec=344
[INFO] [05-09|11:57:44.426] [5/15 Bodies] Processing bodies...       from=40180460 to=40180726
[EROR] [05-09|11:57:50.994] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"
[INFO] [05-09|11:57:52.226] [2/15 Headers] Waiting for headers...    from=40180460
[INFO] [05-09|11:57:53.416] [2/15 Headers] Processed                 highest=40180729 age=0 headers=269 in=1.190 blk/sec=226
[INFO] [05-09|11:57:53.422] [5/15 Bodies] Processing bodies...       from=40180460 to=40180729
[EROR] [05-09|11:58:02.822] Staged Sync                              err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:3"

blxdyx · 2024-05-09T12:03:17Z

Try again?

harshsingh-cs · 2024-05-09T14:21:33Z

Worked, thanks @blxdyx

harshsingh-cs · 2024-05-10T08:54:04Z

It has happened again

pc-quiknode · 2024-05-10T09:01:23Z

unwind doesn't seem to work this time

blxdyx · 2024-05-10T09:02:41Z

unwind and use v.1.2.6 can work
v1.2.7 have some bugs

harshsingh-cs · 2024-05-10T11:46:02Z

It is happening on 1.2.6 as well

[WARN] [05-10|11:19:49.465] [fetch] onNewBlock                       err="failed MdbxKV cursor.Seek(): mdbx_cursor_get: MDBX_BAD_VALSIZE: Invalid size or alignment of key or data for target database, either invalid subDB name, bucket: PoolTransaction,  key: 363187a30387868f8a45452ed9c10ec294b1f8f3e8c2572040e6d08a20e0e6bc"
[EROR] [05-10|11:19:49.586] RPC method eth_getTransactionCount crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 eth_accounts.go:70 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:204 asm_amd64.s:1650]
[WARN] [05-10|11:19:49.586] [rpc] served                             conn=10.100.10.65:60288 method=eth_getTransactionCount reqid=1149839364325318 t=480.81µs err="method handler crashed"
[INFO] [05-10|11:19:49.593] [2/15 Headers] Waiting for headers...    from=40208752
[WARN] [05-10|11:19:49.626] [downloader] Rejected header marked as bad hash=0x99c053e882fc3cdc60ec554cb1ba633cced2f8f0e01165646da4f90999e7b0ad height=40208753
[WARN] [05-10|11:19:49.726] [downloader] Rejected header marked as bad hash=0x99c053e882fc3cdc60ec554cb1ba633cced2f8f0e01165646da4f90999e7b0ad height=40208753
[WARN] [05-10|11:19:49.734] [downloader] Rejected header marked as bad hash=0x99c053e882fc3cdc60ec554cb1ba633cced2f8f0e01165646da4f90999e7b0ad height=40208753
[WARN] [05-10|11:19:49.982] [rpc] served                             conn=10.100.10.65:60288 method=eth_sendRawTransaction reqid=1149839364325319 t=774.935µs err="ALREADY_EXISTS: already known"
[WARN] [05-10|11:19:50.268] [downloader] Rejected header marked as bad hash=0x99c053e882fc3cdc60ec554cb1ba633cced2f8f0e01165646da4f90999e7b0ad height=40208753
[WARN] [05-10|11:19:50.356] [downloader] Rejected header marked as bad hash=0x99c053e882fc3cdc60ec554cb1ba633cced2f8f0e01165646da4f90999e7b0ad height=40208753
[WARN] [05-10|11:19:50.374] [downloader] Rejected header marked as bad hash=0x99c053e882fc3cdc60ec554cb1ba633cced2f8f0e01165646da4f90999e7b0ad height=40208753
[WARN] [05-10|11:19:50.384] [downloader] Rejected header marked as bad hash=0x99c053e882fc3cdc60ec554cb1ba633cced2f8f0e01165646da4f90999e7b0ad height=40208753

harshsingh-cs · 2024-05-10T11:59:00Z

@pc-quiknode did you manage to get it syncing again?

pc-quiknode · 2024-05-10T12:00:01Z

@pc-quiknode did you manage to get it syncing again?

Downgrading to 1.2.6 works for me

harshsingh-cs · 2024-05-10T12:04:36Z

Yes it did work for me but just now started see the errors again

harshsingh-cs · 2024-05-10T12:05:09Z

@blxdyx will there be an official release which fixes this issue ?

sokiaoba · 2024-05-10T12:18:17Z

Constantly having the same issue with 1.2.6

avinashbo · 2024-05-10T13:28:44Z

Rewind + 1.2.6 only helps for a while before the nodes stop syncing again

insider89 · 2024-05-10T14:16:35Z

Have the same issue. Unwind didn't fix the issue.

blxdyx · 2024-05-11T06:17:58Z

Will release a bug fix version later

sokiaoba · 2024-05-13T02:47:00Z

Thank you, when the new release will be created? We need a docker image for it. @blxdyx

avinashbo · 2024-05-13T13:43:36Z

Any update on the bug fix ?

blxdyx · 2024-05-14T03:15:20Z

The latest release v1.2.8 have fixed it.

blxdyx mentioned this issue May 11, 2024

Fix sidecar boardcast issue #388

Merged

pc-quiknode closed this as completed May 17, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2" #387

err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2" #387

pc-quiknode commented May 9, 2024

harshsingh-cs commented May 9, 2024

blxdyx commented May 9, 2024

harshsingh-cs commented May 9, 2024

blxdyx commented May 9, 2024

blxdyx commented May 9, 2024 •

edited

Loading

Zorato commented May 9, 2024

harshsingh-cs commented May 9, 2024

blxdyx commented May 9, 2024

harshsingh-cs commented May 9, 2024

harshsingh-cs commented May 10, 2024

pc-quiknode commented May 10, 2024

blxdyx commented May 10, 2024 •

edited

Loading

harshsingh-cs commented May 10, 2024 •

edited

Loading

harshsingh-cs commented May 10, 2024

pc-quiknode commented May 10, 2024

harshsingh-cs commented May 10, 2024

harshsingh-cs commented May 10, 2024

sokiaoba commented May 10, 2024

avinashbo commented May 10, 2024

insider89 commented May 10, 2024

blxdyx commented May 11, 2024

sokiaoba commented May 13, 2024 •

edited

Loading

avinashbo commented May 13, 2024

blxdyx commented May 14, 2024

err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2" #387

err="[5/15 Bodies] blob info mismatch: sidecars 0, versionedHashes:2" #387

Comments

pc-quiknode commented May 9, 2024

System information

Issue

harshsingh-cs commented May 9, 2024

blxdyx commented May 9, 2024

harshsingh-cs commented May 9, 2024

blxdyx commented May 9, 2024

blxdyx commented May 9, 2024 • edited Loading

Zorato commented May 9, 2024

harshsingh-cs commented May 9, 2024

blxdyx commented May 9, 2024

harshsingh-cs commented May 9, 2024

harshsingh-cs commented May 10, 2024

pc-quiknode commented May 10, 2024

blxdyx commented May 10, 2024 • edited Loading

harshsingh-cs commented May 10, 2024 • edited Loading

harshsingh-cs commented May 10, 2024

pc-quiknode commented May 10, 2024

harshsingh-cs commented May 10, 2024

harshsingh-cs commented May 10, 2024

sokiaoba commented May 10, 2024

avinashbo commented May 10, 2024

insider89 commented May 10, 2024

blxdyx commented May 11, 2024

sokiaoba commented May 13, 2024 • edited Loading

avinashbo commented May 13, 2024

blxdyx commented May 14, 2024

blxdyx commented May 9, 2024 •

edited

Loading

blxdyx commented May 10, 2024 •

edited

Loading

harshsingh-cs commented May 10, 2024 •

edited

Loading

sokiaoba commented May 13, 2024 •

edited

Loading