canonical block #12291468 unknown

[liuhuanhui]

System information

Geth version: Geth/v1.10.2-stable-97d11b01/linux-amd64/go1.16.3
OS & Version: Centos docker
Commit hash : (if develop)

Expected behaviour

ERROR[04-29|04:07:16.857] Section processing failed type=bloombits error="canonical block #12291468 unknown"

[ligi]

Can you please provide more log (especially of the start) - and ideally in text-form - not as a screenshot?
Did you have a crash or unclean shutdown of geth before?

[holiman]

Could you please try (from a geth console -- geth attach or geth --datadir <datadir> attach

eth.getBlock("0xbb8d8c")

[liuhuanhui]

Could you please try (from a geth console -- geth attach or geth --datadir <datadir> attach

eth.getBlock("0xbb8d8c")

~/.ethereum # geth attach geth.ipc 
Welcome to the Geth JavaScript console!

instance: Geth/v1.10.2-stable-97d11b01/linux-amd64/go1.16.3
coinbase: 0xb05146ed865f0ab592dd763bd84a2191700f3dfb
at block: 12334166 (Thu Apr 29 2021 07:59:33 GMT+0000 (UTC))
 datadir: /root/.ethereum
 modules: admin:1.0 debug:1.0 eth:1.0 ethash:1.0 miner:1.0 net:1.0 personal:1.0 rpc:1.0 txpool:1.0 web3:1.0

To exit, press ctrl-d
> eth.getBlock("0xbb8d8c")
Error: invalid argument 0: hex string has length 6, want 64 for common.Hash
        at web3.js:6347:37(47)
        at web3.js:5081:62(37)
        at <eval>:1:13(4)

[liuhuanhui]

Can you please provide more log (especially of the start) - and ideally in text-form - not as a screenshot?
Did you have a crash or unclean shutdown of geth before?

The following is my startup log, which I have had before，But my block seems to be synchronized to the latest and can be used normally

INFO [04-29|08:04:08.247] Starting Geth on Ethereum mainnet... 
INFO [04-29|08:04:08.247] Bumping default cache on mainnet         provided=1024 updated=4096
INFO [04-29|08:04:08.248] Maximum peer count                       ETH=50 LES=0 total=50
WARN [04-29|08:04:08.248] The flag --rpc is deprecated and will be removed June 2021, please use --http 
WARN [04-29|08:04:08.248] The flag --rpcaddr is deprecated and will be removed June 2021, please use --http.addr 
WARN [04-29|08:04:08.248] The flag --rpcport is deprecated and will be removed June 2021, please use --http.port 
WARN [04-29|08:04:08.248] The flag --rpcapi is deprecated and will be removed June 2021, please use --http.api 
INFO [04-29|08:04:08.249] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
WARN [04-29|08:04:08.249] Option nousb is deprecated and USB is deactivated by default. Use --usb to enable 
INFO [04-29|08:04:08.251] Set global gas cap                       cap=25000000
INFO [04-29|08:04:08.251] Allocated trie memory caches             clean=614.00MiB dirty=1024.00MiB
INFO [04-29|08:04:08.251] Allocated cache and file handles         database=/root/.ethereum/geth/chaindata cache=2.00GiB handles=524288
INFO [04-29|08:04:08.779] Opened ancient database                  database=/root/.ethereum/geth/chaindata/ancient readonly=false
INFO [04-29|08:04:08.782] Initialised chain configuration          config="{ChainID: 1 Homestead: 1150000 DAO: 1920000 DAOSupport: true EIP150: 2463000 EIP155: 2675000 EIP158: 2675000 Byzantium: 4370000 Constantinople: 7280000 Petersburg: 7280000 Istanbul: 9069000, Muir Glacier: 9200000, Berlin: 12244000, YOLO v3: <nil>, Engine: ethash}"
INFO [04-29|08:04:09.053] Disk storage enabled for ethash caches   dir=/root/.ethereum/geth/ethash count=3
INFO [04-29|08:04:09.053] Disk storage enabled for ethash DAGs     dir=/root/.ethash               count=2
INFO [04-29|08:04:09.054] Initialising Ethereum protocol           network=1 dbversion=8
INFO [04-29|08:04:09.233] Loaded most recent local header          number=12334172 hash="f45092…d2f662" td=23937998409209203081774 age=2m28s
INFO [04-29|08:04:09.233] Loaded most recent local full block      number=12329904 hash="6eab81…f5cf18" td=23906784139692418298496 age=15h59m57s
INFO [04-29|08:04:09.233] Loaded most recent local fast block      number=12334172 hash="f45092…d2f662" td=23937998409209203081774 age=2m28s
INFO [04-29|08:04:09.233] Loaded last fast-sync pivot marker       number=12329904
WARN [04-29|08:04:09.234] Enabling snapshot recovery               chainhead=12329904 diskbase=12334164
WARN [04-29|08:04:09.241] Snapshot is not continuous with chain    snaproot="5fe2c7…bc48a5" chainroot="945b47…99b921"
INFO [04-29|08:04:09.242] Loaded local transaction journal         transactions=0 dropped=0
INFO [04-29|08:04:09.242] Upgrading chain index                    type=bloombits percentage=99
INFO [04-29|08:04:09.242] Regenerated local transaction journal    transactions=0 accounts=0
WARN [04-29|08:04:09.242] Switch sync mode from fast sync to full sync 
INFO [04-29|08:04:09.242] Trie missing, state snapshotting paused  root="1b10f9…16606a" in="20fce2…7f7553" at="036b63…bb3db0" accounts=16746119 slots=71308740 storage=5.94GiB elapsed="225.093µs"
WARN [04-29|08:04:09.242] Old unclean shutdowns found              count=1
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-21T05:32:38+0000 age=1w1d2h
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-21T05:34:41+0000 age=1w1d2h
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-21T06:07:41+0000 age=1w1d1h
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-21T06:08:16+0000 age=1w1d1h
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-22T06:08:52+0000 age=1w1h55m
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-24T06:58:03+0000 age=5d1h6m
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-28T03:05:24+0000 age=1d4h58m
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-28T08:32:19+0000 age=23h31m50s
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-29T03:33:51+0000 age=4h30m18s
WARN [04-29|08:04:09.242] Unclean shutdown detected                booted=2021-04-29T04:07:16+0000 age=3h56m53s
INFO [04-29|08:04:09.242] Starting peer-to-peer node               instance=Geth/v1.10.2-stable-97d11b01/linux-amd64/go1.16.3
INFO [04-29|08:04:09.264] New local node record                    seq=34 id=53abad22cd53a0b3 ip=127.0.0.1 udp=30303 tcp=30303
INFO [04-29|08:04:09.265] Started P2P networking                   self=enode://7bce932f1e72e54280ff741765f7382116145090c31cd5ecdb9fedef5c82679d927a56aa508598d26adf79f37fa268ef974e24527ef5604141b8733927e5b97e@127.0.0.1:30303
INFO [04-29|08:04:09.266] IPC endpoint opened                      url=/root/.ethereum/geth.ipc
INFO [04-29|08:04:09.266] HTTP server started                      endpoint=[::]:8545 prefix= cors= vhosts=localhost
ERROR[04-29|08:04:09.345] Section processing failed                type=bloombits error="canonical block #12291468 unknown"
INFO [04-29|08:04:19.336] Looking for peers                        peercount=0 tried=26 static=0

INFO [04-29|08:04:22.410] Block synchronisation started 
INFO [04-29|08:04:23.038] New local node record                    seq=35 id=53abad22cd53a0b3 ip=1.14.155.119 udp=36460 tcp=30303
INFO [04-29|08:04:25.884] Downloader queue stats                   receiptTasks=0 blockTasks=8 itemSize=12.49KiB throttle=5247
INFO [04-29|08:04:28.956] Importing heavy sidechain segment        blocks=1182 start=12329905 end=12331086
INFO [04-29|08:04:29.943] Looking for peers                        peercount=1 tried=24 static=0
INFO [04-29|08:04:38.583] Imported new chain segment               blocks=3    txs=733 mgas=44.692 elapsed=9.625s      mgasps=4.643 number=12329907 hash="b6d4c3…8ec22e" age=15h59m22s dirty=5.60MiB
INFO [04-29|08:04:40.027] Looking for peers                        peercount=1 tried=38 static=0
INFO [04-29|08:04:46.779] Imported new chain segment               blocks=6    txs=1529 mgas=89.497 elapsed=8.196s      mgasps=10.919 number=12329913 hash="f54cb4…6797c6" age=15h57m12s dirty=17.15MiB
INFO [04-29|08:04:50.214] Looking for peers                        peercount=2 tried=41 static=0

[holiman]

Please try eth.getBlock(12291468) instead

[liuhuanhui]

Please try eth.getBlock(12291468) instead

get result is null
> eth.getBlock(12291468) null

[holiman]

So, the missing block is 12329904-12291468 =38436 blocks behind the current, meaning it has been moved to the freezer. However, I would guess that it has been corrupted.
We fixed a freezer corruption bug in #22728 . It would be nice to know if that's indeed the case.

If so, the location where the index thinks the header should reside is occupied by something else -- or even does not exist.
If you turn your node off, can you please try this?

geth db freezer-index headers 12291466 12291470

Also, your node reports a lot of unclean shutdowns. I don't know how you usually run the node, but you should ensure that you give it sufficient time to shut down, and not just blindly kill the process.

[liuhuanhui]

geth db freezer-index headers 12291466 12291470

Sorry, I use the ethereum/client-go node running by docker, I have no way to stop the geth program, and then execute: geth db freezer-index headers 12291466 12291470
Because I stopped the geth program, the docker container exited.

[wenshunbiao]

So, the missing block is 12329904-12291468 =38436 blocks behind the current, meaning it has been moved to the freezer. However, I would guess that it has been corrupted.
We fixed a freezer corruption bug in #22728 . It would be nice to know if that's indeed the case.

If so, the location where the index thinks the header should reside is occupied by something else -- or even does not exist.
If you turn your node off, can you please try this?

geth db freezer-index headers 12291466 12291470

Also, your node reports a lot of unclean shutdowns. I don't know how you usually run the node, but you should ensure that you give it sufficient time to shut down, and not just blindly kill the process.

I have never found information on how to stop geth running in the manual. I always stop the process by sending a kill signal to geth. Do you know a more elegant way to stop it?

[holiman]

I have never found information on how to stop geth running in the manual. I always stop the process by sending a kill signal to geth. Do you know a more elegant way to stop it?

Yes, you can send it the SIGINT

[user@work ~]$ kill -s SIGQUIT `pidof geth` # Kills it and produces a stacktrace
[user@work ~]$ kill -s SIGKILL `pidof geth` # Kills it hard
[user@work ~]$ kill -s SIGINT `pidof geth` # Sends the interrupt signal, triggering graceful shutdown

[mauser001]

I also have this error message spamming my logs:
My pc (win10) crashed yesterday, not sure if this caused the problem.
Geth seems to be running despite this error and is on the latest block. I am using geth for my prysm beacon chain.

INFO [05-06|11:52:03.496] Generating state snapshot root=77c5c2..1fa2c1 at=a79cf0..f43718 accounts=85,931,906 slots=284,087,962 storage=24.24GiB elapsed=1h55m49.673s eta=1h1m4.753s INFO [05-06|11:52:04.373] Aborting state snapshot generation root=77c5c2..1fa2c1 in=a7a44b..9364c0 at=290dec..f3e563 accounts=85,946,804 slots=284,117,748 storage=24.24GiB elapsed=1h55m50.550s eta=1h1m3.396s INFO [05-06|11:52:04.380] Resuming state snapshot generation root=32a965..9c6fc5 in=a7a44b..9364c0 at=290dec..f3e563 accounts=85,946,804 slots=284,117,748 storage=24.24GiB elapsed=1h55m50.557s eta=1h1m3.4s INFO [05-06|11:52:04.390] Imported new chain segment blocks=1 txs=211 mgas=14.965 elapsed=213.186ms mgasps=70.196 number=12,380,037 hash=13b605..358f70 dirty=514.38MiB INFO [05-06|11:52:04.391] Upgrading chain index type=bloombits percentage=99 INFO [05-06|11:52:04.394] Unindexed transactions blocks=1 txs=122 tail=10,030,038 elapsed=2.754ms ERROR[05-06|11:52:04.426] Section processing failed type=bloombits error="canonical block #12342062 unknown"

Edit: Updated to the latest version today - did not help