search

smartcontracts / simple-optimism-node

The easiest way to run an Optimism node
MIT License
318 stars 106 forks source link

Error "panic: Cannot recover OVM Context" after forceful restart #68

Closed sanbotto closed 8 months ago

sanbotto commented 1 year ago

The docker containers for the Optimism node in the affected VM are managed with the corresponding docker-compose file, but a service is being used that kills docker in order to restart the containers, so the l2geth one also got forcefully shutdown and it broke (every other container continued to work, at least, AFAICS).

I believe the most important part of l2geth's output is this one:

INFO [04-25|16:10:16.864] Configured rollup client                 url=http://dtl:7878 chain-id=10 ctc-deploy-height=13596466
INFO [04-25|16:10:17.671] Connected to upstream service
INFO [04-25|16:10:17.673] Updating batch index                     old=0xc0005f0f18 new=378390
INFO [04-25|16:10:17.673] Found latest index                       index=50993878
INFO [04-25|16:10:17.674] Block not found, resetting index         new=<nil>  old=50993878
ERROR[04-25|16:10:17.674] Unexpected number of transactions in block count=0
panic: Cannot recover OVM Context

For reference, this is the full output:

+ GETH_DATA_DIR=/geth
+ GETH_CHAINDATA_DIR=/geth/geth/chaindata
+ GETH_KEYSTORE_DIR=/geth/keystore
+ '[' '!' -d /geth/keystore ]
/geth/geth/chaindata exists, checking for hardfork.
Chain config:
+ '[' '!' -d /geth/geth/chaindata ]
+ echo '/geth/geth/chaindata exists, checking for hardfork.'
+ echo 'Chain config:'
+ geth dump-chain-cfg '--datadir=/geth'
INFO [04-25|16:10:16.485] Maximum peer count                       ETH=50 LES=0 total=50
INFO [04-25|16:10:16.486] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
INFO [04-25|16:10:16.486] Allocated cache and file handles         database=/geth/geth/chaindata cache=16.00MiB handles=16
{
  "chainId": 10,
  "homesteadBlock": 0,
  "eip150Block": 0,
  "eip150Hash": "0x0000000000000000000000000000000000000000000000000000000000000000",
  "eip155Block": 0,
  "eip158Block": 0,
  "byzantiumBlock": 0,
  "constantinopleBlock": 0,
  "petersburgBlock": 0,
  "istanbulBlock": 0,
  "muirGlacierBlock": 0,
  "berlinBlock": 3950000,
  "clique": {
    "period": 0,
    "epoch": 30000
  }
}
errexit         on
noglob          off
ignoreeof       off
monitor         off
noexec          off
xtrace          off
verbose         off
noclobber       off
allexport       off
notify          off
nounset         off
vi              off
pipefail        off
INFO [04-25|16:10:16.701] Enabling metrics collection
INFO [04-25|16:10:16.701] Enabling metrics export to InfluxDB
INFO [04-25|16:10:16.702] Maximum peer count                       ETH=50 LES=0 total=50
INFO [04-25|16:10:16.702] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
INFO [04-25|16:10:16.703] Starting peer-to-peer node               instance=Geth/v1.9.10-stable/linux-amd64/go1.18
INFO [04-25|16:10:16.703] Allocated trie memory caches             clean=256.00MiB dirty=256.00MiB
INFO [04-25|16:10:16.703] Allocated cache and file handles         database=/geth/geth/chaindata cache=512.00MiB handles=524288
INFO [04-25|16:10:16.862] Opened ancient database                  database=/geth/geth/chaindata/ancient
INFO [04-25|16:10:16.863] Initialised chain configuration          config="{ChainID: 10 Homestead: 0 DAO: <nil> DAOSupport: false EIP150: 0 EIP155: 0 EIP158: 0 Byzantium: 0 Constantinople: 0 Petersburg: 0 Istanbul: 0, Muir Glacier: 0, Berlin: 3950000, Engine: clique}"
INFO [04-25|16:10:16.863] Initialising Ethereum protocol           versions="[64 63]" network=10 dbversion=7
INFO [04-25|16:10:16.863] Initializing chain from ancient data     number=0 hash=7ca38a…3fa48b total=0  elapsed=91.511µs
INFO [04-25|16:10:16.863] Initialized chain from ancient data      number=0 hash=7ca38a…3fa48b elapsed=148.812µs
INFO [04-25|16:10:16.863] Loaded most recent local header          number=0 hash=7ca38a…3fa48b td=1 age=54y1mo2d
INFO [04-25|16:10:16.864] Loaded most recent local full block      number=0 hash=7ca38a…3fa48b td=1 age=54y1mo2d
INFO [04-25|16:10:16.864] Loaded most recent local fast block      number=0 hash=7ca38a…3fa48b td=1 age=54y1mo2d
INFO [04-25|16:10:16.864] Loaded local transaction journal         transactions=0 dropped=0
INFO [04-25|16:10:16.864] Regenerated local transaction journal    transactions=0 accounts=0
INFO [04-25|16:10:16.864] Running in verifier mode                 sync-backend=l1
INFO [04-25|16:10:16.864] Sanitizing timestamp refresh threshold to 3 minutes
INFO [04-25|16:10:16.864] Configured rollup client                 url=http://dtl:7878 chain-id=10 ctc-deploy-height=13596466
INFO [04-25|16:10:17.671] Connected to upstream service
INFO [04-25|16:10:17.673] Updating batch index                     old=0xc0005f0f18 new=378390
INFO [04-25|16:10:17.673] Found latest index                       index=50993878
INFO [04-25|16:10:17.674] Block not found, resetting index         new=<nil>  old=50993878
ERROR[04-25|16:10:17.674] Unexpected number of transactions in block count=0
panic: Cannot recover OVM Context

goroutine 1 [running]:
github.com/ethereum-optimism/optimism/l2geth/rollup.(*SyncService).initializeLatestL1(0xc000742d00, 0xc0002a80e0)
        /app/l2geth/rollup/sync_service.go:320 +0x1278
github.com/ethereum-optimism/optimism/l2geth/rollup.NewSyncService({0x12d1470?, 0xc000038140?}, {0x9c40, 0x1, 0x1, 0xe4e1c0, {0xc000042043, 0xf}, {0x0, 0x0, ...}, ...}, ...)
        /app/l2geth/rollup/sync_service.go:196 +0xce5
github.com/ethereum-optimism/optimism/l2geth/eth.New(0xc0002a82a0, 0xc000418c00)
        /app/l2geth/eth/backend.go:209 +0x1007
github.com/ethereum-optimism/optimism/l2geth/cmd/utils.RegisterEthService.func2(0xc0005ba630?)
        /app/l2geth/cmd/utils/flags.go:1727 +0x26
github.com/ethereum-optimism/optimism/l2geth/node.(*Node).Start(0xc000148000)
        /app/l2geth/node/node.go:206 +0x5c9
github.com/ethereum-optimism/optimism/l2geth/cmd/utils.StartNode(0xc000148000)
        /app/l2geth/cmd/utils/cmd.go:67 +0x25
main.startNode(0xc000598160?, 0xc000148000)
        /app/l2geth/cmd/geth/main.go:341 +0x65
main.geth(0xc000598160)
        /app/l2geth/cmd/geth/main.go:329 +0xf3
gopkg.in/urfave/cli%2ev1.HandleAction({0xefc760?, 0x11704c0?}, 0xc000165000?)
        /go/pkg/mod/gopkg.in/urfave/cli.v1@v1.20.0/app.go:490 +0x5a
gopkg.in/urfave/cli%2ev1.(*App).Run(0xc0001029c0, {0xc000032a90, 0xd, 0xd})
        /go/pkg/mod/gopkg.in/urfave/cli.v1@v1.20.0/app.go:264 +0x71c
main.main()
        /app/l2geth/cmd/geth/main.go:269 +0x35

The node was created following the README and it was working without any issues until the forced shutdown.

Do you know how to recover from this?

yuichiroaoki commented 1 year ago

Faced the same issue. No idea how to resolve it.