WARN tx iteration error error="unexpected EOF" ... constantly

[razimih]

System information

Geth version: Geth/v1.9.25-stable-e7872729/linux-amd64/go1.15.6
OS & Version: Linux xxxx 5.4.0-58-generic #64-Ubuntu SMP Wed Dec 9 08:16:25 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

Commit hash : (if develop)

Expected behaviour - not sure

Actual behaviour

INFO [01-04|11:38:52.502] Imported new chain segment blocks=1 txs=157 mgas=12.504 elapsed=874.511ms mgasps=14.298 number=11589126 hash="88e83c…65dc44" dirty=127.90MiB
WARN [01-04|11:38:52.505] tx iteration error error="unexpected EOF"
WARN [01-04|11:38:52.506] tx iteration error error="unexpected EOF"
WARN [01-04|11:38:52.506] tx iteration error error="unexpected EOF"
WARN [01-04|11:38:52.506] tx iteration error error="unexpected EOF"
INFO [01-04|11:38:52.506] Indexed transactions blocks=0 txs=0 tail=10629844 elapsed=2.783ms
INFO [01-04|11:38:57.583] Imported new chain segment blocks=1 txs=130 mgas=12.091 elapsed=1.034s mgasps=11.692 number=11589127 hash="b9984c…8afcb3" dirty=127.90MiB
WARN [01-04|11:38:57.589] tx iteration error error="unexpected EOF"
WARN [01-04|11:38:57.589] tx iteration error error="unexpected EOF"
WARN [01-04|11:38:57.589] tx iteration error error="unexpected EOF"
WARN [01-04|11:38:57.590] tx iteration error error="unexpected EOF"
INFO [01-04|11:38:57.590] Indexed transactions blocks=0 txs=0 tail=10629844 elapsed=3.280ms
INFO [01-04|11:38:58.193] Chain reorg detected number=11589126 hash="88e83c…65dc44" drop=1 dropfrom="b9984c…8afcb3" add=1 addfrom="b7715b…28930c"
INFO [01-04|11:38:58.197] Imported new chain segment blocks=1 txs=128 mgas=12.520 elapsed=611.038ms mgasps=20.489 number=11589127 hash="b7715b…28930c" dirty=127.90MiB
WARN [01-04|11:38:58.198] tx iteration error error="unexpected EOF"
WARN [01-04|11:38:58.199] tx iteration error error="unexpected EOF"
WARN [01-04|11:38:58.199] tx iteration error error="unexpected EOF"
WARN [01-04|11:38:58.199] tx iteration error error="unexpected EOF"
INFO [01-04|11:38:58.199] Indexed transactions blocks=0 txs=0 tail=10629844 elapsed=1.322ms
INFO [01-04|11:39:07.377] Deep froze chain segment blocks=7 elapsed=43.083ms number=11499127 hash="e57594…a6a382"
INFO [01-04|11:39:47.908] Chain reorg detected number=11589126 hash="88e83c…65dc44" drop=1 dropfrom="b7715b…28930c" add=2 addfrom="95fd0e…0f917f"
INFO [01-04|11:39:47.920] Imported new chain segment blocks=1 txs=271 mgas=12.489 elapsed=1.682s mgasps=7.422 number=11589128 hash="95fd0e…0f917f" dirty=127.90MiB
WARN [01-04|11:39:47.922] tx iteration error error="unexpected EOF"
WARN [01-04|11:39:47.923] tx iteration error error="unexpected EOF"
WARN [01-04|11:39:47.923] tx iteration error error="unexpected EOF"
WARN [01-04|11:39:47.923] tx iteration error error="unexpected EOF"

Steps to reproduce the behaviour

geth --http --cache 512 --maxpeers 20 --datadir=/nvm/ethereum/.ethereum --datadir.ancient=/strp_mirr/ethereum/geth/ancient

after geth is synced, constantly produces the Warnings / Errors as per above

Backtrace

[backtrace]

[razimih]

Any idea ? Anybody ?
Does this at every new block ...
What should I look at ? any parameter to try ?...
Is this just a warning ? or some other serious issue....

[ligi]

did you have this from the beginning or did it start at some point?

[razimih]

did you have this from the beginning or did it start at some point?

Hi Ligi, it starts as soon as it gets synced. From the very first block added after being in sync, I get exactly 4 warnings at each new block:
.......
Jan 06 21:55:16 ubsrv20 geth[731]: INFO [01-06|21:55:16.511] Imported new chain segment blocks=1 txs=133 mgas=12.457 elapsed=790.857ms mgasps=15.751 number=11604969 hash="f06f80…47457f" dirty=127.90MiB
Jan 06 21:55:16 ubsrv20 geth[731]: WARN [01-06|21:55:16.514] tx iteration error error="unexpected EOF"
Jan 06 21:55:16 ubsrv20 geth[731]: WARN [01-06|21:55:16.514] tx iteration error error="unexpected EOF"
Jan 06 21:55:16 ubsrv20 geth[731]: WARN [01-06|21:55:16.515] tx iteration error error="unexpected EOF"
Jan 06 21:55:16 ubsrv20 geth[731]: WARN [01-06|21:55:16.515] tx iteration error error="unexpected EOF"
......
Jan 06 22:01:03 ubsrv20 geth[731]: INFO [01-06|22:01:03.256] Imported new chain segment blocks=1 txs=317 mgas=12.464 elapsed=1.002s mgasps=12.436 number=11604995 hash="6eb4c5…ed54ee" dirty=127.90MiB
Jan 06 22:01:03 ubsrv20 geth[731]: WARN [01-06|22:01:03.259] tx iteration error error="unexpected EOF"
Jan 06 22:01:03 ubsrv20 geth[731]: WARN [01-06|22:01:03.260] tx iteration error error="unexpected EOF"
Jan 06 22:01:03 ubsrv20 geth[731]: WARN [01-06|22:01:03.261] tx iteration error error="unexpected EOF"
Jan 06 22:01:03 ubsrv20 geth[731]: WARN [01-06|22:01:03.261] tx iteration error error="unexpected EOF"
Jan 06 22:01:03 ubsrv20 geth[731]: INFO [01-06|22:01:03.261] Indexed transactions blocks=0 txs=0 tail=10629844 elapsed=3.401ms
.....
However, it seems that blocks are imported correctly. But that is just an assumption... Any way to check ? Or any way to get more info about this ?

[ligi]

can you run a console and dump out the block? so do
eth.getBlock('0xA232D4')
Actions that should be taken:

• improve the error message
• fix the error

[razimih]

can you run a console and dump out the block? so do
eth.getBlock('0xA232D4')
Actions that should be taken:

• improve the error message
• fix the error
  Hi, I did:
  geth attach --datadir=/nvm/ethereum/eth1_data --exec 'eth.getBlock('0xA232D4')' > 0xA232D4.txt
  text file is attached. Let me know.
  Thanks
  0xA232D4.txt

[holiman]

One thing we could do to investigate, is to check if the blocks 0xA232D4 and 0xA232D5 crosses a file boundary in the ancients

[holiman]

./build/bin/geth db freezer-index bodies 10629840 10629848
INFO [04-08|13:55:12.856] Maximum peer count                       ETH=50 LES=0 total=50
INFO [04-08|13:55:12.856] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
INFO [04-08|13:55:12.857] Set global gas cap                       cap=25000000
INFO [04-08|13:55:12.857] Opening freezer                          location=/home/martin/.ethereum/geth/chaindata/ancient name=bodies
| number | fileno | offset |
|--------|--------|--------|
|  10629840   |  051   |  1999892244   | 
|  10629841   |  051   |  1999917302   | 
|  10629842   |  051   |  1999944294   | 
|  10629843   |  051   |  1999968778   | 
|  10629844   |  051   |  1999995604   | 
|  10629845   |  052   |  31738   | 
|  10629846   |  052   |  59466   | 
|  10629847   |  052   |  85795   | 
|  10629848   |  052   |  115451   | 
|--------------------------|

Yes, the error indeed did occur on the boundary between files. 10629845 is the first in the bodies.0051.cdat, so I suspect that file somehow was truncated. I have no idea why. @razimih I assume it's water under the bridge now, but do you have any idea what could have happened?

[MariusVanDerWijden]

This issue seems to be quite stale now. I'll close it, if something like this still happens, please open a new issue