eth_syncing returns False when syncing to recover head state

[wjmelements]

System information

Geth version: v1.10.23
OS & Version: Linux

Expected behaviour

eth.syncing is True when node is syncing

Actual behaviour

eth.syncing is false

Steps to reproduce the behaviour

doesn't always happen but here's what happened
sigkill geth and restart it
geth is now resyncing, logs look like:

INFO [09-21|21:09:46.928] Imported new potential chain segment     blocks=1 txs=23   mgas=2.109  elapsed=98.149ms    mgasps=21.491  number=15,583,629 hash=25797f..03a707 age=2h21m11s  dirty=4.96GiB
WARN [09-21|21:09:48.746] Ignoring payload with missing parent     number=15,584,328 hash=83b38f..b3a8a9 parent=2930e0..a00ffe
INFO [09-21|21:09:49.244] Imported new potential chain segment     blocks=1 txs=234  mgas=29.945 elapsed=2.314s      mgasps=12.939  number=15,583,630 hash=75e4d6..7a12b2 age=2h21m2s   dirty=4.96GiB

however, eth.syncing is False during this.

It may have been in some unusual state because the import eventually stopped importing "new potential chain segment", with:

INFO [09-21|21:10:07.679] Imported new potential chain segment     blocks=1 txs=183  mgas=29.987 elapsed=184.355ms   mgasps=162.661 number=15,583,699 hash=d457d9..f625e7 age=2h7m20s   dirty=4.97GiB
INFO [09-21|21:10:07.680] Recovered head state                     number=15,583,699 hash=d457d9..f625e7
WARN [09-21|21:10:11.907] Ignoring payload with missing parent     number=15,584,330 hash=d5adbb..c7c34d parent=af5a43..af1f57
WARN [09-21|21:10:25.010] Ignoring payload with missing parent     number=15,584,331 hash=26deac..00340a parent=d5adbb..c7c34d
WARN [09-21|21:10:35.865] Ignoring payload with missing parent     number=15,584,332 hash=fd3524..159ad6 parent=26deac..00340a
WARN [09-21|21:10:49.082] Ignoring payload with missing parent     number=15,584,333 hash=9dfe3c..8097ab parent=fd3524..159ad6
INFO [09-21|21:10:57.273] Extend chain                             add=28041 number=15,583,699 hash=d457d9..f625e7

[Sreeram1993]

Same here also, the geth sync is too slow. I have attached a node which had blocks 3 hours back and the sync alongside with CL is too slow...

INFO [09-22|14:11:39.074] Imported new potential chain segment blocks=1 txs=395 mgas=29.999 elapsed=279.611ms mgasps=107.288 number=15,588,331 hash=8c32b1..78282b age=3h34m4s dirty=0.00B
WARN [09-22|14:12:04.541] Ignoring already known beacon payload number=15,588,331 hash=8c32b1..78282b age=3h34m29s

Any help will be great or we wait for this to catchup in few days time ? Because it will never catchup if this keeps on increasing.

[holiman]

however, eth.syncing is False during this.

This is as expected, and arguably correct. Geth doesn't "see" into the future, we're simply handed blocks to import. We're not actively doing a sync (e.g. snap-sync), but just importing blocks, one by one.

[karalabe]

@Sreeram1993 Geth seems to import blocks fairly reasonably fast, 280ms. There's nothing seemingly wrong there, perhaps the machine being slightly under-powered.

[Sreeram1993]

Thanks a lot @karalabe for the update. And yes an update is I got my archival nodes synced last day.

[wjmelements]

however, eth.syncing is False during this.

This is as expected, and arguably correct. Geth doesn't "see" into the future, we're simply handed blocks to import. We're not actively doing a sync (e.g. snap-sync), but just importing blocks, one by one.

Ok. My goal is to be able to detect this situation then, and if you don't want to call it syncing, I request an alternative API to detect when the node is behind and catching up.

[karalabe]

I've proposed this a few weeks ago to expose some more metadata from the consensus client towards the execution client to be able to detect and expose this status nugget. It will probably take a bit to get it in, but I definitely agree that we should be able to expose this information.

[wjmelements]

If a v2 ForkchoiceState added a block number, that would be sufficient for an execution layer to identify whether it was behind.

[sambacha]

If a v2 ForkchoiceState added a block number, that would be sufficient for an execution layer to identify whether it was behind.

💯

[yashbhavsar007]

Guys,
We are using prysm beacon + geth on the same server.
We have observed some things on geth we are not sure if we are doing something wrong here or what?
We are using docker to run geth and we are havin following commands with that
--datadir=/root --http --http.port=8545 --http.addr=0.0.0.0 --http.vhosts=* --http.api=eth,net,engine,admin --maxpeers 100 --cache 3072 --authrpc.addr=0.0.0.0 --authrpc.vhosts=* --authrpc.jwtsecret=/jwt/jwt.hex

Here we have observed one thing which is that when we transfer geth's data to another server and start syncing from there it takes a lot of time to sync because it has very slow syncing.
Here I would like to share some geth logs.

INFO [11-30|06:24:50.241] Forkchoice requested sync to new head    number=16,076,017 hash=27fb63..5ac62d
INFO [11-30|06:25:05.368] Imported new chain segment               blocks=1  txs=179  mgas=14.637  elapsed=41.823s mgasps=0.350 number=16,075,716 hash=7365f5..e4ce06 age=17h43m6s  dirty=37.86MiB
INFO [11-30|06:25:34.012] Forkchoice requested sync to new head    number=16,076,081 hash=2c09b9..257637
INFO [11-30|06:25:35.444] Imported new chain segment               blocks=1  txs=152  mgas=26.383  elapsed=30.075s mgasps=0.877 number=16,075,717 hash=9059f0..e49bac age=17h43m24s dirty=39.78MiB
INFO [11-30|06:25:35.444] Downloader queue stats                   receiptTasks=0 blockTasks=0   itemSize=64.00KiB throttle=4097
INFO [11-30|06:25:35.807] Unindexed transactions                   blocks=23 txs=4917 tail=13,725,718 elapsed=363.285ms
WARN [11-30|06:25:36.351] Snapshot extension registration failed   peer=d348bda2 err="peer connected on snap without compatible eth support"
INFO [11-30|06:26:08.531] Imported new chain segment               blocks=1  txs=141  mgas=10.711  elapsed=33.085s   mgasps=0.324 number=16,075,718 hash=fdf854..25e51a age=17h43m45s dirty=41.24MiB
INFO [11-30|06:26:37.727] Forkchoice requested sync to new head    number=16,076,145 hash=a76e4e..cedaac
INFO [11-30|06:26:43.906] Imported new chain segment               blocks=1  txs=148  mgas=16.371  elapsed=35.374s   mgasps=0.463 number=16,075,719 hash=2b0e0b..565775 age=17h44m8s  dirty=42.65MiB
INFO [11-30|06:27:21.732] Imported new chain segment               blocks=1  txs=136  mgas=13.131  elapsed=37.826s   mgasps=0.347 number=16,075,720 hash=09e793..f58f96 age=17h44m34s dirty=44.31MiB
INFO [11-30|06:27:21.851] Forkchoice requested sync to new head    number=16,076,209 hash=ba33d9..7dbfa6
INFO [11-30|06:27:52.032] Imported new chain segment               blocks=1  txs=149  mgas=11.501  elapsed=30.299s   mgasps=0.380 number=16,075,721 hash=e5d184..a40fa7 age=17h44m53s dirty=45.83MiB
I```

You can see that instead of going down age is increasing. We are using m5.xlarge instance with gp3 16k IOPS. I'm happy to replicate this scenario in any one of your's aws by giving ami access. 

I tested the fio It says that the disk is giving its 100% by delivering 16k IOPS.