Geth always ~100 blocks behind - knownStates always 0

[newearthmartin]

System information

Geth version: 1.10.8-stable
OS & Version: Ubuntu 21.04
Hardware: 8 Gb ram - 2TB WD blue M2 SATA SSD

Actual behaviour

Geth is always ~100 blocks behind, no matter when I check. It never starts downloading states.

> eth.syncing
{
  currentBlock: 13188285,
  highestBlock: 13188389,
  knownStates: 0,
  pulledStates: 0,
  startingBlock: 13186299
}

In forums, people always blame the SSD. I included the hardware info so that we don't lose time with that question.
It is much more likely to be a bug than the SSD.

[misbach]

Since a recent geth upgrade, I'm running into similar problem.

[newearthmartin]

Only a few hours later from posting this, something has changed, after days and days of waiting. Ironic. Now I'm getting this:

> eth.syncing
false

and the output has changed too:

Sep 09 01:15:06 golden geth.sh[1565]: INFO [09-09|01:15:06.386] Imported new chain segment               blocks=1       txs=267        mgas=26.896 elapsed=1.373s      mgasps=19.579 number=13,189,339 hash=a533e0..4674d4 dirty=131.40MiB
Sep 09 01:15:08 golden geth.sh[1565]: INFO [09-09|01:15:08.701] Downloader queue stats                   receiptTasks=0 blockTasks=0  itemSize=84.84KiB throttle=3090
Sep 09 01:15:10 golden geth.sh[1565]: INFO [09-09|01:15:10.466] Aborting state snapshot generation       root=42f81a..eac5f2 at=17ace8..81b1c3 accounts=13,436,230 slots=70,163,540 storage=5.76GiB elapsed=10m53.235s  eta=13h35m18.115s
Sep 09 01:15:10 golden geth.sh[1565]: INFO [09-09|01:15:10.469] Resuming state snapshot generation       root=3052b3..b48510 at=17ace8..81b1c3 accounts=13,436,230 slots=70,163,540 storage=5.76GiB elapsed=10m53.237s  eta=13h35m18.265s
Sep 09 01:15:10 golden geth.sh[1565]: INFO [09-09|01:15:10.472] Imported new chain segment               blocks=1       txs=87         mgas=6.183  elapsed=321.398ms   mgasps=19.238 number=13,189,340 hash=da5a05..675354 dirty=132.20MiB
Sep 09 01:15:11 golden geth.sh[1565]: INFO [09-09|01:15:11.709] Indexing transactions                    blocks=151,985 txs=29,169,492 tail=11,711,193 total=1,023,908 elapsed=10m41.902s
Sep 09 01:15:12 golden geth.sh[1565]: ERROR[09-09|01:15:12.802] Snapshot extension registration failed   peer=2a0e045e err="peer connected on snap without compatible eth support"
Sep 09 01:15:18 golden geth.sh[1565]: INFO [09-09|01:15:18.069] Deep froze chain segment                 blocks=4       elapsed=422.447ms   number=13,099,340 hash=1a1bc5..e00ff0
Sep 09 01:15:18 golden geth.sh[1565]: INFO [09-09|01:15:18.469] Generating state snapshot                root=3052b3..b48510 at=17ba43..9bb901 accounts=13,466,063 slots=70,192,635 storage=5.76GiB elapsed=11m1.237s   eta=13h31m27.657s
Sep 09 01:15:19 golden geth.sh[1565]: INFO [09-09|01:15:19.736] Indexing transactions                    blocks=153,233 txs=29,408,803 tail=11,709,945 total=1,023,908 elapsed=10m49.929s
Sep 09 01:15:26 golden geth.sh[1565]: INFO [09-09|01:15:26.474] Generating state snapshot                root=3052b3..b48510 at=17c32b..c97eda accounts=13,486,282 slots=70,241,891 storage=5.77GiB elapsed=11m9.243s   eta=13h32m12.244s
Sep 09 01:15:28 golden geth.sh[1565]: INFO [09-09|01:15:28.397] Indexing transactions                    blocks=154,816 txs=29,682,750 tail=11,708,362 total=1,023,908 elapsed=10m58.590s
Sep 09 01:15:29 golden geth.sh[1565]: INFO [09-09|01:15:29.605] Aborting state snapshot generation       root=3052b3..b48510 at=17ca9b..eef05d accounts=13,503,051 slots=70,271,649 storage=5.77GiB elapsed=11m12.373s  eta=13h28m32.054s
Sep 09 01:15:29 golden geth.sh[1565]: INFO [09-09|01:15:29.609] Imported new chain segment               blocks=1       txs=203        mgas=26.182 elapsed=482.533ms   mgasps=54.259 number=13,189,341 hash=39bc0b..5152bf dirty=134.58MiB
Sep 09 01:15:29 golden geth.sh[1565]: INFO [09-09|01:15:29.609] Resuming state snapshot generation       root=610d6f..b8f5ab at=17ca9b..eef05d accounts=13,503,051 slots=70,271,649 storage=5.77GiB elapsed=11m12.378s  eta=13h28m32.415s

and some ETA has appeared (eta=13h28m32.415s), which is nice.

The question is: Would this have had changed if I hadn't created this issue? 😎
And more serious: Why can't Geth show any sense of progress or ETA before this step?

[karalabe]

When you opened the issue, Geth was still finishing up sync. When you snap sync, first we download most of the state data via snapshots, but need to apply certain changes on top that the network did in between. Since we don't know how many changes the network did, we can't show an ETA for this step. The longer downloading the snapshots takes, the longer it will take to fill in the stuff the network did concurrently to you syncing.

In your second log, you're already synced, it's just fixing stuff up for the acceleration structure, which is done in a background, you can use your node (although it does take it's disk toll).

The eth.syncing is a bit broken in snap sync, it does not fill in the necessary infos. We need to fix that.

[newearthmartin]

Is there a way to provide more info in the sync stage? even a reassurance that something is happening, that some progress is being made? No need for an ETA, really, but an absolute number that is growing would be enough. Any indication that Geth is not just stuck but doing something.

This is a big problem for new users.

All new users see is the difference between currentBlock and highestBlock, and it always appears to be 100 blocks away. I got the idea that curentBlock needs to catch up to highestBlock to start downloading states. That, apparently, is wrong. Also, it doesn't help that the community is too fast to point to your hardware and say that your hardware is not enough.

It made me quite anxious, enough that I installed OpenEthereum and fully synced it. But I understand that OE is on its way out so I was back in square one. It was going back to Geth or try Erigon. I decided to give Geth another chance.

[ligi]

I initiated some discussion some time ago here: https://ethereum-magicians.org/t/improve-syncing-rpc-call/6994

[ubearline]

I have the same problem. So what can I do now? This state lasted for several days. It seems that it will never start working

[newearthmartin]

I have the same problem. So what can I do now? This state lasted for several days. It seems that it will never start working

Just wait, it doesn't seem that it is progressing but it is

[newearthmartin]

I have the same problem. So what can I do now? This state lasted for several days. It seems that it will never start working

This is a big problem for geth. New users can't trust that geth will finish synching. I hope the developers take notice.

[icodeface]

same issue

[karalabe]

The stats are not updated in snap sync, those will be fixed in #23576.