Sync from scratch is broken for Gnosis mainnet

[somnathb1]

System information

Erigon version: ./erigon --version
2.48

OS & Version: Windows/Linux/OSX
OSX

Commit hash:

Erigon Command (with flags/config):

Consensus Layer: Lighthouse

Concensus Layer Command (with flags/config):

Chain/Network: Gnosis

Expected behaviour

Gnosis syncs from scratch (new datadir) to the tip with no issues

Actual behaviour

It took 24 hours (intermittent). And it seems to be all over the place.

A gist of errors (latest first)

#1
In loop:
EROR[07-12|21:02:17.016] Staged Sync err="[5/15 Bodies] WriteRawBodyIfNotExists: WriteRawTransactions: txId=176685251, baseTxId=176685251, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"

Basically it's stuck on a loop Processing bodies... from=26499999 to=28914146 this set of number varies a little bit, but the above was the same on various restarts.

#2
[9/15 IntermediateHashes] Wrong trie root of block 139129
That happens for blocks 278258, 556517, 1113034

Steps to reproduce the behaviour

Backtrace

➜  erigonElData ./erigon --datadir="/Volumes/big1/gnosis/erigonElData" --chain=gnosis --authrpc.jwtsecret="/Volumes/big1/gnosis/jwt.hex" --verbosity=3 --snapshots --torrent.download.rate=20mb --http.api=eth,erigon,web3,net,debug,trace,txpool,parity,admin
INFO[07-12|21:30:43.378] logging to file system                   log dir=/Volumes/big1/gnosis/erigonElData/logs file prefix=erigon log level=info json=false
INFO[07-12|21:30:43.378] Build info                               git_branch= git_tag= git_commit=
INFO[07-12|21:30:43.378] Starting Erigon on                       devnet=gnosis
INFO[07-12|21:30:43.379] Maximum peer count                       ETH=100 total=100
INFO[07-12|21:30:43.379] starting HTTP APIs                       APIs=eth,erigon,web3,net,debug,trace,txpool,parity,admin
INFO[07-12|21:30:43.380] torrent verbosity                        level=WRN
INFO[07-12|21:30:45.484] Set global gas cap                       cap=50000000
INFO[07-12|21:30:45.485] [Downloader] Runnning with               ipv6-enabled=true ipv4-enabled=true download.rate=20mb upload.rate=4mb
INFO[07-12|21:30:45.486] Opening Database                         label=chaindata path=/Volumes/big1/gnosis/erigonElData/chaindata
INFO[07-12|21:30:45.752] Initialised chain configuration          config="{ChainID: 100, Homestead: 0, DAO: <nil>, Tangerine Whistle: 0, Spurious Dragon: 0, Byzantium: 0, Constantinople: 1604400, Petersburg: 2508800, Istanbul: 7298030, Muir Glacier: <nil>, Berlin: 16101500, London: 19040000, Arrow Glacier: <nil>, Gray Glacier: <nil>, Terminal Total Difficulty: 8626000000000000000000058750000000000000000000, Merge Netsplit: <nil>, Shanghai: 1690889660, Cancun: <nil>, Prague: <nil>, Engine: aura}" genesis=0x4f1dd23188aab3a76b463e4af801b52b1248ef073c648cbdc4c9333d3da79756
INFO[07-12|21:30:45.844] Initialising Ethereum protocol           network=100
INFO[07-12|21:30:46.041] Starting private RPC server              on=127.0.0.1:9090
INFO[07-12|21:30:46.041] new subscription to logs established 
INFO[07-12|21:30:46.041] rpc filters: subscribing to Erigon events 
INFO[07-12|21:30:46.041] new subscription to newHeaders established 
INFO[07-12|21:30:46.041] New txs subscriber joined 
INFO[07-12|21:30:46.042] Reading JWT secret                       path=/Volumes/big1/gnosis/jwt.hex
INFO[07-12|21:30:46.042] HTTP endpoint opened for Engine API      url=127.0.0.1:8551 ws=true ws.compression=true
INFO[07-12|21:30:46.044] HTTP endpoint opened                     url=127.0.0.1:8545 ws=false ws.compression=true grpc=false
INFO[07-12|21:30:46.051] [txpool] Started 
INFO[07-12|21:30:46.054] Started P2P networking                   version=68 self=enode://3aa21cbba3a632167bdcafd2964ce2e759a27a4c2e9bf5ce5e2a5e444d727b96b72265f23f885aa96a6ed7581649a7a22d0763c561e36c291a7f126541fd3190@127.0.0.1:0 name=erigon/v2.48.0/darwin-arm64/go1.20.5
INFO[07-12|21:30:46.056] [1/15 Snapshots] Fetching torrent files metadata 
INFO[07-12|21:30:46.077] Started P2P networking                   version=67 self=enode://3aa21cbba3a632167bdcafd2964ce2e759a27a4c2e9bf5ce5e2a5e444d727b96b72265f23f885aa96a6ed7581649a7a22d0763c561e36c291a7f126541fd3190@127.0.0.1:0 name=erigon/v2.48.0/darwin-arm64/go1.20.5
INFO[07-12|21:30:46.216] [snapshots] Blocks Stat                  blocks=26500k indices=26500k alloc=336.7MB sys=569.4MB
INFO[07-12|21:30:46.216] [5/15 Bodies] Processing bodies...       from=27723531 to=28914146
INFO[07-12|21:31:06.221] [5/15 Bodies] Writing block bodies       block_num=28083448 remaining=830698 alloc=1.4GB sys=2.1GB
INFO[07-12|21:31:26.216] [5/15 Bodies] No block bodies to write in this log period block number=28153793
INFO[07-12|21:31:46.042] [txpool] stat                            pending=0 baseFee=0 queued=0 alloc=1.1GB sys=2.1GB
INFO[07-12|21:31:46.215] [5/15 Bodies] No block bodies to write in this log period block number=28153793
INFO[07-12|21:32:06.215] [5/15 Bodies] No block bodies to write in this log period block number=28153793
INFO[07-12|21:32:26.215] [5/15 Bodies] No block bodies to write in this log period block number=28153793
EROR[07-12|21:32:33.981] Staged Sync                              err="[5/15 Bodies] WriteRawBodyIfNotExists: WriteRawTransactions: txId=176685251, baseTxId=176685251, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"
INFO[07-12|21:32:34.681] [5/15 Bodies] Processing bodies...       from=27723531 to=28914146
INFO[07-12|21:32:45.843] [p2p] GoodPeers                          eth68=1
INFO[07-12|21:32:46.040] [txpool] stat                            pending=0 baseFee=0 queued=0 alloc=1.5GB sys=2.2GB
INFO[07-12|21:32:54.681] [5/15 Bodies] Downloading block bodies   block_num=28153793 delivery/sec=226.5KB wasted/sec=315.4KB remaining=760352 delivered=384 cache=2.8MB alloc=1.3GB sys=2.2GB
EROR[07-12|21:32:57.889] Staged Sync                              err="[5/15 Bodies] WriteRawBodyIfNotExists: WriteRawTransactions: txId=176685251, baseTxId=176685251, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"
INFO[07-12|21:32:58.590] [5/15 Bodies] Processing bodies...       from=27723531 to=28914146
EROR[07-12|21:33:15.649] Staged Sync                              err="[5/15 Bodies] WriteRawBodyIfNotExists: WriteRawTransactions: txId=176685251, baseTxId=176685251, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"
INFO[07-12|21:33:16.360] [5/15 Bodies] Processing bodies...       from=27723531 to=28914146
EROR[07-12|21:33:35.332] Staged Sync                              err="[5/15 Bodies] WriteRawBodyIfNotExists: WriteRawTransactions: txId=176685251, baseTxId=176685251, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"
INFO[07-12|21:33:36.043] [5/15 Bodies] Processing bodies...       from=27723531 to=28914146
INFO[07-12|21:33:46.040] [txpool] stat                            pending=0 baseFee=0 queued=0 alloc=1.3GB sys=2.3GB
INFO[07-12|21:33:56.044] [5/15 Bodies] Downloading block bodies   block_num=28153793 delivery/sec=297.6KB wasted/sec=236.4KB remaining=760352 delivered=512 cache=11.4MB alloc=1.2GB sys=2.3GB
EROR[07-12|21:34:03.320] Staged Sync                              err="[5/15 Bodies] WriteRawBodyIfNotExists: WriteRawTransactions: txId=176685251, baseTxId=176685251, bucket: BlockTransaction, mdbx_cursor_put: MDBX_EKEYMISMATCH: The given key value is mismatched to the current cursor position"
INFO[07-12|21:34:04.044] [5/15 Bodies] Processing bodies...       from=27723531 to=28914146
INFO[07-12|21:34:24.046] [5/15 Bodies] Downloading block bodies   block_num=28153793 delivery/sec=661.7KB wasted/sec=278.0KB remaining=760352 delivered=1024 cache=20.5MB alloc=1.5GB sys=2.3GB
EROR[07-12|21:34:24.697] Staged Sync  

[AskAlexSharov]

in this case, please do: integration stage_headers —reset

[yperbasis]

Another telltale of the issue:

[WARN] [07-09|20:45:40.984] [7/15 Execution] Execution failed block=1113035 hash=0x86b657aa3a3a5e2fc26acb9847bf97a0f0ac4311713befa49a2d01388b176a41 err="mismatched receipt headers for block 1113035 (0xe522f5f273ce4349be61d91e4fbd9d87b5dad96dc47afe3bce660b832a944d7a != 0xdf3aced259ebd6c88f7dac86667744d94fdaa7d986acaccac99e3c8401c0b98b)"
Jul 09 20:45:40 rpc01-var-m gnosis-mainnet.sh[588155]: [INFO] [07-09|20:45:40.985] UnwindTo block=1113034 bad_block_hash=0x86b657aa3a3a5e2fc26acb9847bf97a0f0ac4311713befa49a2d01388b176a41