Geth crashes on start-up

[robmcl4]

System information

Geth version: 1.12.1-stable-9c216bd6
CL client & version: lighthouse @ v4.3.0-dfcb336
OS & Version: Linux (docker container)

Expected behaviour

Geth starts normally

Actual behaviour

geth logs the following, then crashes:

INFO [08-10|22:49:51.505] Starting Geth on Ethereum mainnet... 
INFO [08-10|22:49:51.506] Bumping default cache on mainnet         provided=1024 updated=4096
INFO [08-10|22:49:51.506] Enabling metrics collection 
INFO [08-10|22:49:51.506] Enabling stand-alone metrics HTTP endpoint address=0.0.0.0:6060
INFO [08-10|22:49:51.506] Starting metrics server                  addr=http://0.0.0.0:6060/debug/metrics
WARN [08-10|22:49:51.509] Config field is deprecated and won't have an effect name=ethconfig.Config.TrieCleanCacheRejournal
WARN [08-10|22:49:51.509] Config field is deprecated and won't have an effect name=ethconfig.Config.TrieCleanCacheJournal
INFO [08-10|22:49:51.527] Maximum peer count                       ETH=500 LES=0 total=500
INFO [08-10|22:49:51.531] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
INFO [08-10|22:49:51.535] Enabling recording of key preimages since archive mode is used 
INFO [08-10|22:49:51.536] Set global gas cap                       cap=50,000,000
INFO [08-10|22:49:51.538] Initializing the KZG library             backend=gokzg
INFO [08-10|22:49:51.629] Allocated trie memory caches             clean=1.20GiB dirty=0.00B
INFO [08-10|22:50:01.973] Using leveldb as the backing database 
INFO [08-10|22:50:01.973] Allocated cache and file handles         database=/mount/geth/ethdb2/geth/chaindata cache=2.00GiB handles=524,288
INFO [08-10|22:51:09.650] Using LevelDB as the backing database 
INFO [08-10|22:51:09.650] Found legacy ancient chain path          location=/mount/geth/ethdb2/geth/chaindata/ancient
INFO [08-10|22:51:09.707] Opened ancient database                  database=/mount/geth/ethdb2/geth/chaindata/ancient readonly=false
panic: runtime error: index out of range [7] with length 7

goroutine 4675 [running]:
github.com/ethereum/go-ethereum/ethdb/leveldb.(*Database).meter(0xc000002900, 0xd?)
	github.com/ethereum/go-ethereum/ethdb/leveldb/leveldb.go:365 +0xb46
created by github.com/ethereum/go-ethereum/ethdb/leveldb.NewCustom
	github.com/ethereum/go-ethereum/ethdb/leveldb/leveldb.go:155 +0x9aa

Steps to reproduce the behaviour

Start geth.

Backtrace

goroutine 4675 [running]:
github.com/ethereum/go-ethereum/ethdb/leveldb.(*Database).meter(0xc000002900, 0xd?)
	github.com/ethereum/go-ethereum/ethdb/leveldb/leveldb.go:365 +0xb46
created by github.com/ethereum/go-ethereum/ethdb/leveldb.NewCustom
	github.com/ethereum/go-ethereum/ethdb/leveldb/leveldb.go:155 +0x9aa

When submitting logs: please submit them as text and not screenshots.

[robmcl4]

We are running a full archive node using the leveldb backend.

It appears to crash here: https://github.com/ethereum/go-ethereum/blob/master/ethdb/leveldb/leveldb.go#L365C13-L365C13

[robmcl4]

I believe that this issue is caused by #27643, and in particular this segment: 863f6da#diff-e708c5e803ad5ce947336bfe82e80ba6f9eac1d99c5032066a52c7566ac41461R78

Is it possible that my leveldb has more than 7 levels? This node is somewhat old (first sync'd late-2021)

[jsvisa]

@robmcl4 How large is your leveldb size?

From leveldb's design doc, it has at most 7 levels

In leveldb immutable are stored on the disk which can be shared by different cluster nodes. There are totally 7 levels plus at most two in-memory tables. The procedure can be described as firstly the system buffers write operations in an in-memory table called MEMTable and flushes data to disk when it becomes full.

Ref https://dbdb.io/db/leveldb#:~:text=In%20leveldb%20immutable%20are%20stored,disk%20when%20it%20becomes%20full.

Is it possible that https://github.com/syndtr/goleveldb has exceed this limit?

[robmcl4]

Do you know a good way to check this? I turned verbosity all the way up and didn't see anything relevant logged.

[robmcl4]

Total size of chaindata is 15T according to du -sh. Not sure how to check leveldb size.

[jsvisa]

Do you know a good way to check this? I turned verbosity all the way up and didn't see anything relevant logged.

Maybe you can try it with geth db stats --datadir xxx

[robmcl4]

Same exception, seems to be an issue blocking me from getting the stats. Perhaps I should make a small go program to read that value off?

$ ./geth db stats --datadir /data/geth/ethdb2
INFO [08-10|18:27:06.511] Maximum peer count                       ETH=50 LES=0 total=50
INFO [08-10|18:27:06.513] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
INFO [08-10|18:27:06.518] Set global gas cap                       cap=50,000,000
INFO [08-10|18:27:06.518] Initializing the KZG library             backend=gokzg
INFO [08-10|18:27:15.410] Using leveldb as the backing database 
INFO [08-10|18:27:15.410] Allocated cache and file handles         database=/data/geth/ethdb2/geth/chaindata cache=512.00MiB handles=524,288 readonly=true
INFO [08-10|18:27:48.124] Using LevelDB as the backing database 
INFO [08-10|18:27:48.124] Found legacy ancient chain path          location=/data/geth/ethdb2/geth/chaindata/ancient
INFO [08-10|18:27:48.138] Opened ancient database                  database=/data/geth/ethdb2/geth/chaindata/ancient readonly=true
panic: runtime error: index out of range [7] with length 7

goroutine 4500 [running]:
github.com/ethereum/go-ethereum/ethdb/leveldb.(*Database).meter(0xc000274a80, 0x7ab?)
	github.com/ethereum/go-ethereum/ethdb/leveldb/leveldb.go:365 +0xb46
created by github.com/ethereum/go-ethereum/ethdb/leveldb.NewCustom
	github.com/ethereum/go-ethereum/ethdb/leveldb/leveldb.go:155 +0x9aa

[jsvisa]

@robmcl4 sorry for that, as #27643 is merged in v1.12.1, maybe you can try the same command(geth db stats xxx) with v1.12.0

[robmcl4]

Got it. I actually went ahead and wrote a small program to maybe help, here is that output:

Program:

package main

import (
	"fmt"
	"github.com/syndtr/goleveldb/leveldb"
)

func main() {
	fmt.Println("Hello World")

	db, err := leveldb.OpenFile("/data/geth/ethdb2/geth/chaindata", nil)

	if err != nil {
		fmt.Println("error opening database")
		return
	}

	fmt.Println("opened database")

	stats := leveldb.DBStats{}
	db.Stats(&stats)

	fmt.Println("lt: ", stats.LevelTablesCounts)
}

Output:

Hello World
opened database
lt:  [3 51 609 6576 60155 736002 5127951 1802311]

[robmcl4]

BTW geth db stats xxx seems to not recognize the alternative data dir:

$ ./geth db stats /data/geth/ethdb2
INFO [08-10|18:38:36.435] Maximum peer count                       ETH=50 LES=0 total=50
INFO [08-10|18:38:36.438] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
INFO [08-10|18:38:36.442] Set global gas cap                       cap=50,000,000
INFO [08-10|18:38:36.442] Initializing the KZG library             backend=gokzg
INFO [08-10|18:38:36.490] Defaulting to pebble as the backing database 
INFO [08-10|18:38:36.490] Allocated cache and file handles         database=/root/.ethereum/geth/chaindata cache=512.00MiB handles=524,288

[jsvisa]

BTW geth db stats xxx seems to not recognize the alternative data dir:

you need to specify it with --datadir /data/geth/ethdb2

and thanks for that report, I'm trying to fix on that

[jsvisa]

@robmcl4 could you please try with this branch https://github.com/jsvisa/go-ethereum/tree/leveldb-more-than-7

If you are running with docker, you can pull this image jsvisa/go-ethereum:v20230811(for linux x86_64)

[robmcl4]

Uptime is 15min and counting, currently re-syncing. This seems solved, I will report back when sync occurs.

[robmcl4]

Geth has sync'd, I believe that fixed the issue.