Mordor Fails to Sync Around Block 497800

[nottug]

On an initial sync for Mordor, it fails with issues similar (but not exactly the same) as #439 - the behavior seems most similar to #439 (comment). It was pretty easy to reproduce for me (just never restart the node) and pretty easy to solve (just restart the node). Just adding this for tracking purposes. The block it fails on is never the same, but its always around 497700-497800

System information

Geth version: v1.12.18
OS & Version: Docker version 20.10.6, build 370c289
Command: geth --mordor --port=30302 --syncmode=snap --http

Expected behaviour

• Snap sync on Mordor can sync the full chain without restarting

Actual behaviour

• Snap sync on Mordor can't sync the full chain without restarting.

Steps to reproduce the behaviour

• Sync Mordor from scratch with snap sync, without restarting it ever
• Wait until around 497800 and issues should arise
• To fix, just restart the node

Backtrace

INFO [07-28|19:02:25.306] Imported new block headers               count=192  elapsed=9.905ms     number=4,978,110 hash=1222d5..f3fc27 age=9mo5d20h
INFO [07-28|19:02:25.319] Imported new block receipts              count=28   elapsed=11.047ms    number=4,977,946 hash=328f96..13e1e4 age=9mo5d21h   size=9.31KiB
INFO [07-28|19:02:25.373] Imported new block receipts              count=164  elapsed=30.838ms    number=4,978,110 hash=1222d5..f3fc27 age=9mo5d20h   size=54.66KiB
INFO [07-28|19:02:25.679] Imported new block headers               count=1536 elapsed=69.824ms    number=4,979,646 hash=86d7fc..420986 age=9mo5d15h
WARN [07-28|19:02:25.708] Invalid header encountered               number=4,980,026 hash=541494..f512bc parent=3a0c4e..739f55 err="invalid mix digest"
WARN [07-28|19:02:25.708] Rewinding blockchain                     target=4,977,597
INFO [07-28|19:02:25.720] Imported new block receipts              count=346  elapsed=33.029ms    number=4,978,456 hash=1e671a..b00613 age=9mo5d19h   size=114.78KiB
WARN [07-28|19:02:25.736] Truncating freezer table                 database=/root/.ethereum/mordor/geth/chaindata/ancient table=headers items=4,979,647 limit=4,979,058
WARN [07-28|19:02:25.737] Truncating freezer table                 database=/root/.ethereum/mordor/geth/chaindata/ancient table=hashes  items=4,979,647 limit=4,979,058
WARN [07-28|19:02:25.737] Truncating freezer table                 database=/root/.ethereum/mordor/geth/chaindata/ancient table=bodies  items=4,979,647 limit=4,979,058
WARN [07-28|19:02:25.737] Truncating freezer table                 database=/root/.ethereum/mordor/geth/chaindata/ancient table=receipts items=4,979,647 limit=4,979,058
WARN [07-28|19:02:25.737] Truncating freezer table                 database=/root/.ethereum/mordor/geth/chaindata/ancient table=diffs    items=4,979,647 limit=4,979,058
INFO [07-28|19:02:25.965] Loaded most recent local header          number=4,977,597 hash=b99335..455612 td=30,036,356,302,196 age=9mo5d22h
INFO [07-28|19:02:25.965] Loaded most recent local full block      number=0         hash=a68ebd..59a3f1 td=131,072            age=2y10mo1w
INFO [07-28|19:02:25.965] Loaded most recent local fast block      number=4,977,597 hash=b99335..455612 td=30,036,356,302,196 age=9mo5d22h
INFO [07-28|19:02:25.965] Loaded last fast-sync pivot marker       number=6,849,858
WARN [07-28|19:02:25.965] Rolled back chain segment                header=4979646->4977597 snap=4978456->4977597 block=0->0 reason="invalid mix digest"
WARN [07-28|19:02:25.965] Synchronisation failed, dropping peer    peer=c127c43f93d3e177ec18af1ded1e3bf147dec266bb1fead9a1e45309005f3260 err="retrieved hash chain is invalid: invalid mix digest"
INFO [07-28|19:02:28.233] Looking for peers                        peercount=2 tried=1 static=0
INFO [07-28|19:02:40.139] State heal in progress                   accounts=5@298.00B         slots=0@0.00B           codes=0@0.00B         nodes=33@12.63KiB pending=1
INFO [07-28|19:02:40.273] State heal in progress                   accounts=7@396.00B         slots=0@0.00B           codes=0@0.00B         nodes=45@16.92KiB pending=0
INFO [07-28|19:02:40.541] Imported new block headers               count=192  elapsed=13.580ms    number=4,977,789 hash=22e762..a84c46 age=9mo5d21h
INFO [07-28|19:02:40.573] Imported new block receipts              count=192  elapsed=29.474ms    number=4,977,789 hash=22e762..a84c46 age=9mo5d21h   size=63.67KiB
INFO [07-28|19:02:40.678] Imported new block headers               count=192  elapsed=12.708ms    number=4,977,981 hash=3245b0..fb566b age=9mo5d21h
INFO [07-28|19:02:40.693] Imported new block receipts              count=157  elapsed=13.725ms    number=4,977,946 hash=328f96..13e1e4 age=9mo5d21h   size=52.12KiB
INFO [07-28|19:02:40.723] Imported new block receipts              count=35   elapsed=22.979ms    number=4,977,981 hash=3245b0..fb566b age=9mo5d21h   size=11.88KiB
INFO [07-28|19:02:40.918] Imported new block headers               count=1536 elapsed=73.155ms    number=4,979,517 hash=d61cfe..f2dad7 age=9mo5d15h
WARN [07-28|19:02:40.959] Invalid header encountered               number=4,980,010 hash=0da9e1..ecc0f6 parent=482896..1b9d22 err="invalid mix digest"
WARN [07-28|19:02:40.959] Rewinding blockchain                     target=4,977,468
INFO [07-28|19:02:41.153] Loaded most recent local header          number=4,977,468 hash=74329d..442e5c td=30,036,192,354,746 age=9mo5d22h
INFO [07-28|19:02:41.153] Loaded most recent local full block      number=0         hash=a68ebd..59a3f1 td=131,072            age=2y10mo1w
INFO [07-28|19:02:41.153] Loaded most recent local fast block      number=4,977,468 hash=74329d..442e5c td=30,036,192,354,746 age=9mo5d22h
INFO [07-28|19:02:41.153] Loaded last fast-sync pivot marker       number=6,849,861
WARN [07-28|19:02:41.153] Rolled back chain segment                header=4979517->4977468 snap=4977981->4977468 block=0->0 reason="invalid mix digest"
WARN [07-28|19:02:41.154] Synchronisation failed, dropping peer    peer=c127c43f93d3e177ec18af1ded1e3bf147dec266bb1fead9a1e45309005f3260 err="retrieved hash chain is invalid: side blocks can't be accepted as ancient chain data"

[meowsbits]

Thanks for the report. I've seen this is issue before, too. #439

I just reproduced it yesterday as well, and will take a look at it this week.

[saturn4er]

Looks like --ethash.dagsinmem=0 --ethash.dagsinmem=1 fixed sync for me

[meowsbits]

Thanks for the tip. Is that a typo in the flags (I'm seeing double... :)?

[saturn4er]

Ha, I missed that they are the same :) but this is what I added, and after restart sync contined