v1.13.0 rewinds to block 0 #28120
Description
System information
Geth version: v1.13.0
CL client & version: lighthouse v4.4.1
OS & Version: Linux
I restarted geth while syncing from scratch with --state.sceme=path and this lead (I think) the chain to start rewinding to block zero. chaindata size started to decrease. after 2 hours and another restart I decided to removedb (without removing ancients) and the node resumed syncing again.
Logs just before the restart:
INFO [09-14|09:46:16.398] IPC endpoint closed url=/chain/chain.ipc
WARN [09-14|09:46:16.399] Rewinding blockchain to block target=7,944,977
INFO [09-14|09:46:24.487] Looking for peers peercount=0 tried=168 static=1
INFO [09-14|09:46:34.522] Looking for peers peercount=0 tried=116 static=1
INFO [09-14|09:46:41.793] Loaded most recent local header number=7,944,977 hash=6ba207..e2dc1e td=10,579,629,261,200,387,371,986 age=4y3mo3w
INFO [09-14|09:46:41.793] Loaded most recent local block number=0
hash=d4e567..cb8fa3 td=17,179,869,184 age=54y5mo3w
INFO [09-14|09:46:41.793] Loaded most recent local snap block number=7,906,288 hash=623ffe..808d51 td=10,500,012,474,221,072,800,842 age=4y4mo16h
INFO [09-14|09:46:41.793] Loaded last snap-sync pivot marker number=18,132,746
WARN [09-14|09:46:41.793] Rolled back chain segment header=7947026->7944977 snap=7906288->7906288 block=0->0 reason="syncing canceled (requested)"
INFO [09-14|09:46:41.812] Syncing: chain download in progress synced=43.61% chain=82.92GiB headers=7,944,[email protected] bodies=7,908,[email protected] receipts=7,908,[email protected] eta=28h9m18.490s
INFO [09-14|09:46:41.812] Syncing: state download in progress synced=54.81% state=152.61GiB accounts=126,154,[email protected] slots=600,831,[email protected] codes=616,[email protected] eta=7h45m21.870s
ERROR[09-14|09:46:41.949] Beacon backfilling failed err="content processing canceled (requested)"
INFO [09-14|09:46:41.957] Ethereum protocol stopped
INFO [09-14|09:46:41.957] Transaction pool stopped
ERROR[09-14|09:46:41.961] Failed to journal state snapshot err="snapshot [0xd7f8974fb5ac78d9ac099b9ad5018bedc2ce0a72dad1827a1709da30580f0544] missing"
INFO [09-14|09:46:41.961] Persisting dirty state to disk root=d7f897..0f0544 layers=0
INFO [09-14|09:46:41.963] Persisted dirty state to disk size=69.00B elapsed=2.252ms
INFO [09-14|09:46:41.965] Blockchain stopped
geth.service: Deactivated successfully.
Stopped geth.service - Ethereum geth client daemon by The Ethereum Foundation.
Logs right after the restart:
INFO [09-14|09:46:53.751]
INFO [09-14|09:46:53.752] Loaded most recent local header number=7,944,977 hash=6ba207..e2dc1e td=10,579,629,261,200,387,371,986 age=4y3mo3w
INFO [09-14|09:46:53.752] Loaded most recent local block number=0
hash=d4e567..cb8fa3 td=17,179,869,184 age=54y5mo3w
INFO [09-14|09:46:53.752] Loaded most recent local snap block number=7,908,044 hash=e8f41d..7dd8dd td=10,503,796,279,546,327,487,969 age=4y4mo9h
INFO [09-14|09:46:53.752] Loaded last snap-sync pivot marker number=18,132,746
ERROR[09-14|09:46:53.752] Unexpected trie node in disk owner=000000..000000 path=[] expect=d7f897..0f0544 got=5d7a4d..b04697
WARN [09-14|09:46:53.800] Head state missing, repairing number=0
hash=d4e567..cb8fa3
ERROR[09-14|09:46:53.800] Unexpected trie node in disk owner=000000..000000 path=[] expect=d7f897..0f0544 got=5d7a4d..b04697
ERROR[09-14|09:46:53.800] Unexpected trie node in disk owner=000000..000000 path=[] expect=d7f897..0f0544 got=5d7a4d..b04697
INFO [09-14|09:46:54.058] Opened ancient database database=/chain/geth/geth/chaindata/ancient/state readonly=false
INFO [09-14|09:46:54.058] Rebuilt trie database root=56e81f..63b421
INFO [09-14|09:46:54.627] Loaded most recent local header number=7,944,977 hash=6ba207..e2dc1e td=10,579,629,261,200,387,371,986 age=4y3mo3w
INFO [09-14|09:46:54.627] Loaded most recent local block number=0
hash=d4e567..cb8fa3 td=17,179,869,184 age=54y5mo3w
INFO [09-14|09:46:54.627] Loaded last snap-sync pivot marker number=18,132,746
ERROR[09-14|09:46:54.627] Truncating ancient chain from=7,944,977 to=0
WARN [09-14|09:46:54.628] Rewinding blockchain to block target=0
Logs after 2 hours where I attempted another restart (at this point chaindata was almost half the size, ancients decreased in size too)
INFO [09-14|10:36:32.740] Loaded most recent local header number=7,664,518 hash=dd5b9a..9c5985 td=10,011,359,787,843,088,592,518 age=4y5mo1w
INFO [09-14|10:36:32.740] Loaded most recent local block number=0
hash=d4e567..cb8fa3 td=17,179,869,184 age=54y5mo3w
INFO [09-14|10:36:32.740] Loaded last snap-sync pivot marker number=18,132,746
ERROR[09-14|10:36:32.740] Truncating ancient chain from=7,664,518 to=0
WARN [09-14|10:36:32.740] Rewinding blockchain to block target=0
WARN [09-14|10:36:32.751] Truncating freezer table database=/chain/geth/geth/chaindata/ancient/chain table=diffs items=7,664,520 limit=7,664,518