CRIT Failed to truncate extra state histories err=EOF

[SimonSMH1015]

System information

Geth version: geth 1.13.0
CL client & version: e.g. lighthouse@v4.1.0
OS & Version: Linux

Expected behaviour

After looking the new feature provided by version 1.13.0, I updated my node. I leaved only the ancient blocks and restarted my geth with --state.scheme=path. It tookl me around 6 hour to resynced blocks and generated snapshot.

To test the Semi-instant shutdowns, I forced shutdown my server without closing geth. Then I got the Error after I lauched the geth :-)

INFO [09-13|17:38:43.874] Starting Geth on Ethereum mainnet...
INFO [09-13|17:38:43.874] Bumping default cache on mainnet         provided=1024 updated=4096
INFO [09-13|17:38:43.876] Maximum peer count                       ETH=50 LES=0 total=50
INFO [09-13|17:38:43.877] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
INFO [09-13|17:38:44.034] Using pebble as the backing database
INFO [09-13|17:38:44.034] Allocated cache and file handles         database=/mnt/eth/geth/geth/chaindata cache=2.00GiB handles=32767
INFO [09-13|17:38:44.705] Opened ancient database                  database=/mnt/eth/geth/geth/chaindata/ancient/chain readonly=true
INFO [09-13|17:38:44.705] State scheme set by user                 scheme=path
INFO [09-13|17:38:44.710] Set global gas cap                       cap=50,000,000
INFO [09-13|17:38:44.716] Initializing the KZG library             backend=gokzg
INFO [09-13|17:38:44.759] Allocated trie memory caches             clean=614.00MiB dirty=1024.00MiB
INFO [09-13|17:38:44.838] Using pebble as the backing database
INFO [09-13|17:38:44.838] Allocated cache and file handles         database=/mnt/eth/geth/geth/chaindata cache=2.00GiB handles=32767
INFO [09-13|17:38:45.737] Opened ancient database                  database=/mnt/eth/geth/geth/chaindata/ancient/chain readonly=false
INFO [09-13|17:38:45.739] Initialising Ethereum protocol           network=1 dbversion=8
WARN [09-13|17:38:45.739] Sanitizing invalid node buffer size      provided=1024.00MiB updated=256.00MiB
INFO [09-13|17:38:45.739] Failed to load journal, discard it       err="journal not found"
INFO [09-13|17:38:45.741] Opened ancient database                  database=/mnt/eth/geth/geth/chaindata/ancient/state readonly=false
CRIT [09-13|17:38:46.774] Failed to truncate extra state histories err=EOF

Now I have to synced form 0 as leave the ancient block data still leading to this problem.

[karalabe]

The error seems to be with the ancient/state thing, which is only used by pathdb. If you resync, you could also delete that and leave ancient/chain. That will save a lot. Will look into what's happening here. My guess is that it's some very stupid simple small check.

[rjl493456442]

Do you still have the corrupted database which can reproduce this issue? Or do you keep the ancient folder by any chance?

[rjl493456442]

My hunch is the state ancientstore is somehow corrupted by losing some data chunk, but it's really hard to say without enough debug information. I will try to expose more error messages and hopefully it can be reproduced.

[SimonSMH1015]

Do you still have the corrupted database which can reproduce this issue? Or do you keep the ancient folder by any chance?

Sorry, I did not keep that. My node is now resyncing. But Im happy to do it again and tried to reproduce after synced.

[rjl493456442]

#28115

Would be nice to use this patch to reproduce, with a bit debug information, thank you!

[rjl493456442]

Please keep a bit logs before shutdown as well, easier to know what's the previous status.

[SimonSMH1015]

geth.log

I ve reproduced this ,and will kept the broken db as you may need more infos @rjl493456442

[rjl493456442]

Can you please ls -l the state ancient folder?

e.g. :~/xxx/geth/chaindata/ancient/state$ ls -l

[rjl493456442]

The thing I have discovered via the log is:

a) The index file is zero size after restart, which truncates the head data file respectively

WARN [09-14|21:09:33.203] Truncating dangling head database=/mnt/eth/geth/geth/chaindata/ancient/state table=history.meta indexed=0 stored=413,253

b) The EOF error shouldn't occur, even with a corrupted ancient database. The only exception is the index refers to some non-existent data which results in the EOF read.

[ryny24]

Yesterday I did a resync with "--state.scheme=path" and now my GETH won't start, with this error. What do I do??

[rjl493456442]

@ryny24 can you share a bit more logs? You also reboot the machine without stopping geth?

[ryny24]

I did not reboot unless there was a power issue I'm not aware of, this machine is off-site, I only stopped GETH after the constant restart phone alerts woke up my wife lol. Here is the last of the log before it tries again.

INFO [09-15|03:14:49.764] Set global gas cap                       cap=50,000,000
INFO [09-15|03:14:49.765] Initializing the KZG library             backend=gokzg
INFO [09-15|03:14:49.919] Allocated trie memory caches             clean=614.00MiB dirty=1024.00MiB
INFO [09-15|03:14:50.055] Using pebble as the backing database
INFO [09-15|03:14:50.055] Allocated cache and file handles         database=/home/ryan/.ethereum/geth/chaindata cache=2.00GiB handles=26
2,144
INFO [09-15|03:14:52.116] Opened ancient database                  database=/home/ryan/.ethereum/geth/chaindata/ancient/chain readonly=f
alse
INFO [09-15|03:14:52.120] Initialising Ethereum protocol           network=1 dbversion=8
WARN [09-15|03:14:52.120] Sanitizing invalid node buffer size      provided=1024.00MiB updated=256.00MiB
INFO [09-15|03:14:52.121] Failed to load journal, discard it       err="journal not found"
INFO [09-15|03:14:52.122] Opened ancient database                  database=/home/ryan/.ethereum/geth/chaindata/ancient/state readonly=f
alse
CRIT [09-15|03:14:52.200] Failed to truncate extra state histories err=EOF

[ryny24]

Here is my state folder. I hope this is enough for now, I'm going back to bed.

total 180
-rw-r--r-- 1 ryan ryan     0 Sep 15 03:10 account.data.0000.cdat
-rw-r--r-- 1 ryan ryan 25872 Sep 15 03:07 account.data.cidx
-rw-r--r-- 1 ryan ryan     3 Sep 14 12:26 account.data.meta
-rw-r--r-- 1 ryan ryan     0 Sep 15 03:10 account.index.0000.cdat
-rw-r--r-- 1 ryan ryan 25872 Sep 15 03:07 account.index.cidx
-rw-r--r-- 1 ryan ryan     3 Sep 14 12:26 account.index.meta
-rw------- 1 ryan ryan     0 Sep 14 12:26 FLOCK
-rw-r--r-- 1 ryan ryan     0 Sep 15 03:10 history.meta.0000.rdat
-rw-r--r-- 1 ryan ryan     3 Sep 14 12:26 history.meta.meta
-rw-r--r-- 1 ryan ryan 25872 Sep 15 03:07 history.meta.ridx
-rw-r--r-- 1 ryan ryan     0 Sep 15 03:10 storage.data.0000.cdat
-rw-r--r-- 1 ryan ryan 25872 Sep 15 03:07 storage.data.cidx
-rw-r--r-- 1 ryan ryan     3 Sep 14 12:26 storage.data.meta
-rw-r--r-- 1 ryan ryan     0 Sep 15 03:10 storage.index.0000.cdat
-rw-r--r-- 1 ryan ryan 25872 Sep 15 03:07 storage.index.cidx
-rw-r--r-- 1 ryan ryan     3 Sep 14 12:26 storage.index.meta

[ryny24]

Oh yes, it looks there was a power issue that caused GETH to shutdown unclean. Can I just delete the ancient only and just resync that?