erigon import does not process PoS blocks

[fjl]

System information

Erigon version: v2.56.1

Expected behaviour

erigon import with a chain file should run all blocks in the file and set the head to the last valid block.

Actual behaviour

Running erigon import chain.rlp will only process blocks up to the merge. Blocks after the PoS transition are not imported.

This issue causes hive test failures. As we are continuing to update more hive tests to a PoS-enabled chain, erigon will not be able to execute those tests. So I'd appreciate getting this fixed.

Steps to reproduce the behaviour

Downloading the test chain:

~/d/e/erigon-testscript >> curl -L -o genesis.json https://github.com/ethereum/go-ethereum/raw/1010a79c7cbcdb4741e9f30e8cdc19c679ad7377/cmd/devp2p/internal/ethtest/testdata/genesis.json
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100  4104  100  4104    0     0   8015      0 --:--:-- --:--:-- --:--:-- 15604
~/d/e/erigon-testscript >> curl -L -o chain.rlp https://github.com/ethereum/go-ethereum/raw/1010a79c7cbcdb4741e9f30e8cdc19c679ad7377/cmd/devp2p/internal/ethtest/testdata/chain.rlp
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100  333k  100  333k    0     0   513k      0 --:--:-- --:--:-- --:--:-- 3478k

Initializing the database:

~/d/e/erigon-testscript >> ./erigon init --datadir data genesis.json 
INFO[01-09|13:09:24.062] logging to file system                   log dir=data/logs file prefix=erigon log level=info json=false
INFO[01-09|13:09:24.063] Opening Database                         label=chaindata path=/Users/fjl/develop/eth/erigon-testscript/data/chaindata
INFO[01-09|13:09:24.066] [db] open                                lable=chaindata sizeLimit=2TB pageSize=16384
INFO[01-09|13:09:24.076] Re-Opening DB in exclusive mode to apply migrations 
INFO[01-09|13:09:24.084] [db] open                                lable=chaindata sizeLimit=2TB pageSize=16384
INFO[01-09|13:09:24.084] Apply migration                          name=db_schema_version5
INFO[01-09|13:09:24.084] Applied migration                        name=db_schema_version5
INFO[01-09|13:09:24.084] Apply migration                          name=txs_begin_end
INFO[01-09|13:09:24.084] Applied migration                        name=txs_begin_end
INFO[01-09|13:09:24.084] Apply migration                          name=txs_v3
INFO[01-09|13:09:24.091] Applied migration                        name=txs_v3
INFO[01-09|13:09:24.091] Apply migration                          name=prohibit_new_downloads_lock
INFO[01-09|13:09:24.091] Applied migration                        name=prohibit_new_downloads_lock
INFO[01-09|13:09:24.091] Updated DB schema to                     version=6.1.0
INFO[01-09|13:09:24.099] [db] open                                lable=chaindata sizeLimit=2TB pageSize=16384
INFO[01-09|13:09:24.116] Writing custom genesis block             hash=0x3d35e0b689cdd20720592d9a4d0d208de0612ebcb46e391141501e7d55d55b42
INFO[01-09|13:09:24.124] Successfully wrote genesis state         hash=0x3d35e0b689cdd20720592d9a4d0d208de0612ebcb46e391141501e7d55d55b42

Importing chain.rlp. Note that the import ends at block 72, which is incorrect. The last block
in chain.rlp is block 500.

~/d/e/erigon-testscript >> ./erigon --datadir data --fakepow import chain.rlp 
INFO[01-09|13:10:30.073] logging to file system                   log dir=data/logs file prefix=erigon log level=info json=false
INFO[01-09|13:10:30.073] Starting Erigon on Ethereum mainnet... 
INFO[01-09|13:10:30.074] Maximum peer count                       ETH=100 total=100
INFO[01-09|13:10:30.074] starting HTTP APIs                       APIs=eth,erigon,engine
INFO[01-09|13:10:30.074] torrent verbosity                        level=WRN
INFO[01-09|13:10:32.180] Set global gas cap                       cap=50000000
INFO[01-09|13:10:32.234] [Downloader] Running with                ipv6-enabled=true ipv4-enabled=true download.rate=16mb upload.rate=4mb
INFO[01-09|13:10:32.234] Opening Database                         label=chaindata path=/Users/fjl/develop/eth/erigon-testscript/data/chaindata
INFO[01-09|13:10:32.236] [db] open                                lable=chaindata sizeLimit=12TB pageSize=16384
INFO[01-09|13:10:32.236] Initialised chain configuration          config="{ChainID: 3503995874084926, Homestead: 0, DAO: <nil>, Tangerine Whistle: 6, Spurious Dragon: 12, Byzantium: 18, Constantinople: 24, Petersburg: 30, Istanbul: 36, Muir Glacier: 42, Berlin: 48, London: 54, Arrow Glacier: 60, Gray Glacier: 66, Terminal Total Difficulty: 9454784, Merge Netsplit: 72, Shanghai: 780, Cancun: 840, Prague: <nil>, Engine: ethash}" genesis=0x3d35e0b689cdd20720592d9a4d0d208de0612ebcb46e391141501e7d55d55b42
INFO[01-09|13:10:32.243] Initialising Ethereum protocol           network=1
WARN[01-09|13:10:32.243] Ethash used in fake mode 
INFO[01-09|13:10:32.244] Starting private RPC server              on=127.0.0.1:9090
INFO[01-09|13:10:32.244] new subscription to logs established 
INFO[01-09|13:10:32.245] rpc filters: subscribing to Erigon events 
INFO[01-09|13:10:32.245] new subscription to newHeaders established 
INFO[01-09|13:10:32.245] New txs subscriber joined 
INFO[01-09|13:10:32.245] Importing blockchain                     file=chain.rlp
INFO[01-09|13:10:32.245] Reading JWT secret                       path=/Users/fjl/develop/eth/erigon-testscript/data/jwt.hex
INFO[01-09|13:10:32.245] HTTP endpoint opened for Engine API      url=127.0.0.1:8551 ws=true ws.compression=true
INFO[01-09|13:10:32.245] JsonRpc endpoint opened                  ws=false ws.compression=true grpc=false http.url=127.0.0.1:8545
INFO[01-09|13:10:32.252] [2/15 Headers] Waiting for headers...    from=5
INFO[01-09|13:10:32.255] [txpool] Started 
INFO[01-09|13:10:32.299] [2/15 Headers] Processed                 highest=72 age=54y9mo3w headers=67 in=0.047 blk/sec=1420
INFO[01-09|13:10:32.299] [5/15 Bodies] Processing bodies...       from=5 to=72
INFO[01-09|13:10:32.301] [5/15 Bodies] Processed                  highest=72 blocks=67 in=0.002 blk/sec=37911
INFO[01-09|13:10:32.301] [6/15 Senders] Started                   from=0 to=72
INFO[01-09|13:10:32.306] [7/15 Execution] Blocks execution        from=0 to=72
INFO[01-09|13:10:32.310] [7/15 Execution] Completed on            block=72
INFO[01-09|13:10:32.310] [8/15 HashState] Promoting plain state   from=0 to=72
INFO[01-09|13:10:32.349] [9/15 IntermediateHashes] Generating intermediate hashes from=0 to=72
INFO[01-09|13:10:32.349] [9/15 IntermediateHashes] Regeneration trie hashes started 
INFO[01-09|13:10:32.349] [9/15 IntermediateHashes] Trie root      hash=0x74035b613e4ea1072fd029f35d0fa5b26fbfaa54cabebcec88b9ee07cca321ae
INFO[01-09|13:10:32.350] [9/15 IntermediateHashes] Regeneration ended 
WARN[01-09|13:10:32.361] NAT ExternalIP resolution has failed, try to pass a different --nat option err="no UPnP or NAT-PMP router discovered"
INFO[01-09|13:10:32.377] Started P2P networking                   version=68 self=enode://2c30e61eeaaf26a007d99d6db05d34867c0f7a8995970f10beb2c06b85b4b669eb6aadf74165b2748fe7273b0aa812de2a60fb384810dfa1f5d9b58707d207d8@127.0.0.1:30303 name=erigon/v2.56.1/darwin-arm64/go1.20.7
WARN[01-09|13:10:32.396] NAT ExternalIP resolution has failed, try to pass a different --nat option err="no UPnP or NAT-PMP router discovered"
INFO[01-09|13:10:32.404] Started P2P networking                   version=67 self=enode://2c30e61eeaaf26a007d99d6db05d34867c0f7a8995970f10beb2c06b85b4b669eb6aadf74165b2748fe7273b0aa812de2a60fb384810dfa1f5d9b58707d207d8@127.0.0.1:30304 name=erigon/v2.56.1/darwin-arm64/go1.20.7
INFO[01-09|13:10:32.404] RPC Daemon notified of new headers       from=5 to=72 hash=0xf0a50b18d597552b6ad8a711f4ac1f7ab225d59daa74137f689256a16a0ff809 header sending=65.5µs log sending=333ns
INFO[01-09|13:10:32.404] [snapshots] Prune Blocks                 to=1 limit=100

[fjl]

Just fyi, when I brought this up in Discord about two months back, we initially suspected it might be related to --fakepow. But the issue also occurs with a fully signed and valid Clique chain, so it's likely not related to this flag.

[somnathb1]

I think the importChain functionality cannot transition into merge at the moment in Erigon

[fjl]

Any news about this? We have now converted the rpc-compat tests to use a post-merge chain, and the issue also affects these tests.

[racytech]

Not yet, sorry, I'll do this asap

[yperbasis]

Fixed by PR #9431

[fjl]

Very nice!

[fjl]

@racytech I have redeployed hive1 and hive2 to test this change, but it looks like the issue is not fixed. There is a crash in the import:

[INFO] [02-14|13:22:59.457] Successfully wrote genesis state         hash=0x414c637788e37e9f65ed2c6ee962d32aeea39722ad50ee764e712fabebd69118
Loading initial blockchain...
Loading initial blockchain...
[INFO] [02-14|13:22:59.644] logging to file system                   log dir=/erigon-hive-datadir/logs file prefix=erigon log level=info json=false
[INFO] [02-14|13:22:59.646] Maximum peer count                       ETH=100 total=100
[INFO] [02-14|13:22:59.646] starting HTTP APIs                       port=8545 APIs=eth,erigon,engine
[INFO] [02-14|13:22:59.647] torrent verbosity                        level=WRN
[INFO] [02-14|13:23:01.750] Set global gas cap                       cap=50000000
[INFO] [02-14|13:23:01.751] [Downloader] Running with                ipv6-enabled=true ipv4-enabled=true download.rate=16mb upload.rate=4mb
[INFO] [02-14|13:23:01.751] Opening Database                         label=chaindata path=/erigon-hive-datadir/chaindata
mdbx_setup_dxb:15946 filesize mismatch (expect 143360b/35p, have 16777216b/4096p)
[INFO] [02-14|13:23:01.762] [db] open                                lable=chaindata sizeLimit=2GB pageSize=4096
[INFO] [02-14|13:23:01.781] Initialised chain configuration          config="{ChainID: 3503995874084926, Homestead: 0, DAO: <nil>, Tangerine Whistle: 0, Spurious Dragon: 0, Byzantium: 0, Constantinople: 0, Petersburg: 0, Istanbul: 0, Muir Glacier: 0, Berlin: 0, London: 0, Arrow Glacier: 0, Gray Glacier: 0, Terminal Total Difficulty: 131072, Merge Netsplit: 0, Shanghai: 0, Cancun: 0, Prague: <nil>, Engine: ethash}" genesis=0x414c637788e37e9f65ed2c6ee962d32aeea39722ad50ee764e712fabebd69118
[INFO] [02-14|13:23:01.800] Initialising Ethereum protocol           network=3503995874084926
[WARN] [02-14|13:23:01.800] Ethash used in fake mode 
[INFO] [02-14|13:23:01.816] Starting private RPC server              on=127.0.0.1:9090
[INFO] [02-14|13:23:01.816] new subscription to logs established 
[EROR] [02-14|13:23:01.817] catch panic                              err="runtime error: invalid memory address or nil pointer dereference" stack="[main.go:29 panic.go:914 panic.go:261 signal_unix.go:861 import_cmd.go:77 make_app.go:111 command.go:279 command.go:272 app.go:337 app.go:311 main.go:34 proc.go:267 asm_amd64.s:1650]"

[fjl]

This crash is still happening.

[racytech]

It appears that here https://hivetests.ethdevops.io/viewer.html?suiteid=1711397722-d50036babc50796ef1719e295f3b3136.json&suitename=consensus&testid=2&file=%2Fresults%2Ferigon%2Fclient-12ec110ba712b8b92ee6437fe3f0de96b485e7a2ee13e8c2100e0c88c9302063.log it uses 0001.rlp it would be nice if I had it, because for the above chain.rlp and genesis.json I am not having any problems.

Unlike before, the error occurs not before importing PoS blocks but before importing PoW blocks as well. So the error is different this time.