[BUG][Clique] Database has receipts with a legacy format on fresh node, cannot restart node

[DubbaThony]

System information

Debian 11 server (CPX21 @ hetzner)

Geth
Version: 1.10.21-stable
Git Commit: 6710942
Git Commit Date: 20220727
Architecture: amd64
Go Version: go1.18.4
Operating System: linux

Node type: Archive

Context

I set up private clique PoA chain, it works until first geth shutdown (I tested this on my archive node, not brave enough to try to shut down my sealer to check if it would die too).

The node the issue apeared on is Archive node.

Expected behaviour

After node clean shut down, the node should be able to stand back up

Actual behaviour

After node clean shutdown, upon restart node complains it's transaction receipts are in legacy format. Running suggested command does not change behaviour.

Steps to reproduce the behaviour

1. Setup private PoA chain based on Clique
2. Attach node (with geth init.. etc) to it with archive database
3. Let the node run and see it functioning correctly
4. Stop the node (ie. via SIGINT)
5. Re-run the node

Backtrace

Logs (complete since working node -> broken node -> attempted to use migrate command -> still broken)

INFO [08-08|21:23:20.003] Imported new chain segment               blocks=1    txs=0 mgas=0.000 elapsed="384.406µs" mgasps=0.000  number=175,200 hash=e564e9..31ebe8 dirty=0.00B
^CINFO [08-08|21:23:21.024] Got interrupt, shutting down...
INFO [08-08|21:23:21.026] HTTP server stopped                      endpoint=192.168.1.7:8545
INFO [08-08|21:23:21.027] HTTP server stopped                      endpoint=192.168.1.7:8546
INFO [08-08|21:23:21.027] Stats daemon stopped
WARN [08-08|21:23:21.027] Failed to retrieve stats server message  err="read tcp 192.168.1.7:49948->192.168.1.7:3000: use of closed network connection"
INFO [08-08|21:23:21.028] Ethereum protocol stopped
INFO [08-08|21:23:21.028] Transaction pool stopped
INFO [08-08|21:23:21.028] Writing clean trie cache to disk         path=/var/geth/geth/triecache threads=3
INFO [08-08|21:23:21.037] Persisted the clean trie cache           path=/var/geth/geth/triecache elapsed=8.345ms
INFO [08-08|21:23:21.037] Blockchain stopped
root@PoACtrl ~/run # ./start.sh
INFO [08-08|21:23:24.826] Starting Geth on Ethereum mainnet...
INFO [08-08|21:23:24.827] Bumping default cache on mainnet         provided=1024 updated=4096
INFO [08-08|21:23:24.828] Maximum peer count                       ETH=6 LES=0 total=6
INFO [08-08|21:23:24.830] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
WARN [08-08|21:23:24.833] Sanitizing cache to Go's GC limits       provided=4096 updated=1278
INFO [08-08|21:23:24.834] Enabling recording of key preimages since archive mode is used
INFO [08-08|21:23:24.834] Set global gas cap                       cap=50,000,000
INFO [08-08|21:23:24.838] Allocated trie memory caches             clean=382.00MiB dirty=0.00B
INFO [08-08|21:23:24.838] Allocated cache and file handles         database=/var/geth/geth/chaindata cache=637.00MiB handles=524,288
INFO [08-08|21:23:26.813] Opened ancient database                  database=/var/geth/geth/chaindata/ancient readonly=false
INFO [08-08|21:23:26.816]
INFO [08-08|21:23:26.816] ---------------------------------------------------------------------------------------------------------------------------------------------------------
INFO [08-08|21:23:26.816] Chain ID:  31072022 (unknown)
INFO [08-08|21:23:26.816] Consensus: Clique (proof-of-authority)
INFO [08-08|21:23:26.816]
INFO [08-08|21:23:26.816] Pre-Merge hard forks:
INFO [08-08|21:23:26.816]  - Homestead:                   0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/homestead.md)
INFO [08-08|21:23:26.816]  - Tangerine Whistle (EIP 150): 0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/tangerine-whistle.md)
INFO [08-08|21:23:26.817]  - Spurious Dragon/1 (EIP 155): 0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/spurious-dragon.md)
INFO [08-08|21:23:26.817]  - Spurious Dragon/2 (EIP 158): 0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/spurious-dragon.md)
INFO [08-08|21:23:26.817]  - Byzantium:                   0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/byzantium.md)
INFO [08-08|21:23:26.817]  - Constantinople:              0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/constantinople.md)
INFO [08-08|21:23:26.817]  - Petersburg:                  0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/petersburg.md)
INFO [08-08|21:23:26.817]  - Istanbul:                    0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/istanbul.md)
INFO [08-08|21:23:26.817]  - Berlin:                      <nil> (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/berlin.md)
INFO [08-08|21:23:26.817]  - London:                      <nil> (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/london.md)
INFO [08-08|21:23:26.817]
INFO [08-08|21:23:26.817] Merge not configured!
INFO [08-08|21:23:26.817]  - Hard-fork specification: https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/paris.md)
INFO [08-08|21:23:26.817] ---------------------------------------------------------------------------------------------------------------------------------------------------------
INFO [08-08|21:23:26.817]
INFO [08-08|21:23:26.817] Initialising Ethereum protocol           network=1 dbversion=8
INFO [08-08|21:23:27.732] Loaded most recent local header          number=175,200 hash=e564e9..31ebe8 td=350,401 age=7s
INFO [08-08|21:23:27.732] Loaded most recent local full block      number=175,200 hash=e564e9..31ebe8 td=350,401 age=7s
INFO [08-08|21:23:27.732] Loaded most recent local fast block      number=175,200 hash=e564e9..31ebe8 td=350,401 age=7s
INFO [08-08|21:23:27.750] Loaded local transaction journal         transactions=0 dropped=0
INFO [08-08|21:23:27.750] Regenerated local transaction journal    transactions=0 accounts=0
INFO [08-08|21:23:27.750] Gasprice oracle is ignoring threshold set threshold=2
INFO [08-08|21:23:28.290] Deep froze chain segment                 blocks=30001 elapsed=1.473s number=30000   hash=5e4aed..fdab8b
INFO [08-08|21:23:28.290] Freezer shutting down
Fatal: Database has receipts with a legacy format. Please run `geth db freezer-migrate`.
root@PoACtrl ~/run # geth --datadir /var/geth db freezer-migrate
INFO [08-08|21:27:32.516] Maximum peer count                       ETH=50 LES=0 total=50
INFO [08-08|21:27:32.516] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
INFO [08-08|21:27:32.517] Set global gas cap                       cap=50,000,000
INFO [08-08|21:27:32.518] Allocated cache and file handles         database=/var/geth/geth/chaindata cache=512.00MiB handles=524,288
INFO [08-08|21:27:32.703] Opened ancient database                  database=/var/geth/geth/chaindata/ancient readonly=false
INFO [08-08|21:27:32.755] Starting migration                       ancients=30001 firstLegacy=0
INFO [08-08|21:27:33.869] Replacing old table files with migrated ones elapsed=67.530ms
INFO [08-08|21:27:34.215] Deep froze chain segment                 blocks=30001 elapsed=1.507s   number=60001 hash=620305..92ea57
INFO [08-08|21:27:34.215] Freezer shutting down
INFO [08-08|21:27:34.257] Migration finished                       duration=1.501712628s
root@PoACtrl ~/run # ./start.sh
INFO [08-08|21:27:36.424] Starting Geth on Ethereum mainnet...
INFO [08-08|21:27:36.425] Bumping default cache on mainnet         provided=1024 updated=4096
INFO [08-08|21:27:36.427] Maximum peer count                       ETH=6 LES=0 total=6
INFO [08-08|21:27:36.428] Smartcard socket not found, disabling    err="stat /run/pcscd/pcscd.comm: no such file or directory"
WARN [08-08|21:27:36.430] Sanitizing cache to Go's GC limits       provided=4096 updated=1278
INFO [08-08|21:27:36.430] Enabling recording of key preimages since archive mode is used
INFO [08-08|21:27:36.431] Set global gas cap                       cap=50,000,000
INFO [08-08|21:27:36.432] Allocated trie memory caches             clean=382.00MiB dirty=0.00B
INFO [08-08|21:27:36.432] Allocated cache and file handles         database=/var/geth/geth/chaindata cache=637.00MiB handles=524,288
INFO [08-08|21:27:36.595] Opened ancient database                  database=/var/geth/geth/chaindata/ancient readonly=false
INFO [08-08|21:27:36.597]
INFO [08-08|21:27:36.597] ---------------------------------------------------------------------------------------------------------------------------------------------------------
INFO [08-08|21:27:36.597] Chain ID:  31072022 (unknown)
INFO [08-08|21:27:36.597] Consensus: Clique (proof-of-authority)
INFO [08-08|21:27:36.597]
INFO [08-08|21:27:36.597] Pre-Merge hard forks:
INFO [08-08|21:27:36.597]  - Homestead:                   0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/homestead.md)
INFO [08-08|21:27:36.597]  - Tangerine Whistle (EIP 150): 0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/tangerine-whistle.md)
INFO [08-08|21:27:36.597]  - Spurious Dragon/1 (EIP 155): 0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/spurious-dragon.md)
INFO [08-08|21:27:36.597]  - Spurious Dragon/2 (EIP 158): 0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/spurious-dragon.md)
INFO [08-08|21:27:36.597]  - Byzantium:                   0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/byzantium.md)
INFO [08-08|21:27:36.597]  - Constantinople:              0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/constantinople.md)
INFO [08-08|21:27:36.597]  - Petersburg:                  0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/petersburg.md)
INFO [08-08|21:27:36.597]  - Istanbul:                    0        (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/istanbul.md)
INFO [08-08|21:27:36.597]  - Berlin:                      <nil> (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/berlin.md)
INFO [08-08|21:27:36.597]  - London:                      <nil> (https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/london.md)
INFO [08-08|21:27:36.597]
INFO [08-08|21:27:36.597] Merge not configured!
INFO [08-08|21:27:36.597]  - Hard-fork specification: https://github.com/ethereum/execution-specs/blob/master/network-upgrades/mainnet-upgrades/paris.md)
INFO [08-08|21:27:36.597] ---------------------------------------------------------------------------------------------------------------------------------------------------------
INFO [08-08|21:27:36.597]
INFO [08-08|21:27:36.598] Initialising Ethereum protocol           network=1 dbversion=8
INFO [08-08|21:27:37.151] Loaded most recent local header          number=175,200 hash=e564e9..31ebe8 td=350,401 age=4m17s
INFO [08-08|21:27:37.151] Loaded most recent local full block      number=175,200 hash=e564e9..31ebe8 td=350,401 age=4m17s
INFO [08-08|21:27:37.151] Loaded most recent local fast block      number=175,200 hash=e564e9..31ebe8 td=350,401 age=4m17s
INFO [08-08|21:27:37.169] Loaded local transaction journal         transactions=0 dropped=0
INFO [08-08|21:27:37.169] Regenerated local transaction journal    transactions=0 accounts=0
INFO [08-08|21:27:37.169] Gasprice oracle is ignoring threshold set threshold=2
WARN [08-08|21:27:37.169] Unclean shutdown detected                booted=2022-08-08T21:23:27+0000 age=4m10s
INFO [08-08|21:27:37.537] Deep froze chain segment                 blocks=25199 elapsed=940.793ms number=85200   hash=fb9dd0..e55b0a
INFO [08-08|21:27:37.537] Freezer shutting down
Fatal: Database has receipts with a legacy format. Please run `geth db freezer-migrate`.
root@PoACtrl ~/run #

`genesis.json`

{
  "config": {
    "chainId": 31072022,
    "homesteadBlock": 0,
    "eip150Block": 0,
    "eip150Hash": "0x0000000000000000000000000000000000000000000000000000000000000000",
    "eip155Block": 0,
    "eip158Block": 0,
    "byzantiumBlock": 0,
    "constantinopleBlock": 0,
    "petersburgBlock": 0,
    "istanbulBlock": 0,
    "clique": {
      "period": 4,
      "epoch": 30000
    }
  },
  "nonce": "0x0",
  "timestamp": "0x62E6CD48",
  "extraData": "0x000000000000000000000000000000000000000000000000000000000000000001000007865ade114f9f827a8e2531d1f2debc9a0200000181cc3b13659c62216820d4bec34187c503000009a0accfcd3bb4fc273de274aedc295be70400000a697d73435a5cde5ad0a24773bcb5aea105000004f738ac3509fbbfec2a0591ef646137370000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000",
  "gasLimit": "0x47b760",
  "difficulty": "0x1",
  "mixHash": "0x0000000000000000000000000000000000000000000000000000000000000000",
  "coinbase": "0x0000000000000000000000000000000000000000",
  "alloc": {"_comment":"for brieviety I removed alloc, it's single address + 00 to FF addresses"
  },
  "number": "0x0",
  "gasUsed": "0x0",
  "parentHash": "0x0000000000000000000000000000000000000000000000000000000000000000",
  "baseFeePerGas": null
}

I can provide configuration.toml file that I use to run geth, if requested

Edit: I found out about --ignore-legacy-receipts (thank you for having these things in commit names / descriptions, really helpfull!) that works around the issue. Issue is still valid though, these receipts shouldn't be written to the database in the first place (entire chain was bootstrapped with geth 1.10.21)

[holiman]

Might be related to #24724

[s1na]

Can you please re-compile with this patch and see if it still halts on start? @karalabe pointed out an issue in the legacy detection function: if there are no non-empty receipts in the freezer, the detection gives a false positive. Which we think might be your case. Or did you have receipts in the first 30k (or even 60k) blocks?

diff --git a/cmd/geth/config.go b/cmd/geth/config.go
index 2562de8ae..519868de8 100644
--- a/cmd/geth/config.go
+++ b/cmd/geth/config.go
@@ -173,12 +173,13 @@ func makeFullNode(ctx *cli.Context) (*node.Node, ethapi.Backend) {
 		if cfg.Eth.NetworkId == 1 && ghash == params.MainnetGenesisHash {
 			firstIdx = 46147
 		}
-		isLegacy, _, err := dbHasLegacyReceipts(eth.ChainDb(), firstIdx)
+		isLegacy, firstLegacy, err := dbHasLegacyReceipts(eth.ChainDb(), firstIdx)
 		if err != nil {
 			log.Error("Failed to check db for legacy receipts", "err", err)
 		} else if isLegacy {
 			stack.Close()
-			utils.Fatalf("Database has receipts with a legacy format. Please run `geth db freezer-migrate`.")
+			log.Error("Database has receipts with a legacy format", "firstLegacy", firstLegacy)
+			utils.Fatalf("Aborting. Please run `geth db freezer-migrate`.")
 		}
 	}
 	// Configure GraphQL if requested
diff --git a/cmd/geth/dbcmd.go b/cmd/geth/dbcmd.go
index ab7427712..bb53a632e 100644
--- a/cmd/geth/dbcmd.go
+++ b/cmd/geth/dbcmd.go
@@ -822,11 +822,15 @@ func dbHasLegacyReceipts(db ethdb.Database, firstIdx uint64) (bool, uint64, erro
 			}
 		}
 	}
-	// Is first non-empty receipt legacy?
 	first, err := db.Ancient("receipts", firstIdx)
 	if err != nil {
 		return false, 0, err
 	}
+	// We looped over all receipts and they were all empty
+	if bytes.Equal(first, emptyRLPList) {
+		return false, 0, nil
+	}
+	// Is first non-empty receipt legacy?
 	legacy, err = types.IsLegacyStoredReceipts(first)
 	return legacy, firstIdx, err
 }

[DubbaThony]

Sure, I will do this later today.

And yes, in first 30k blocks I dont think I have any receipts, I usually spin up private network and let it sit for few days to ensure it's set up correctly and works.

[DubbaThony]

Sorry for late reply.

The patch seems to make node run correctly, I can include logs but there is nothing unusal after the patch.

[holiman]

@s1na did you ever PR that patch?

[DubbaThony]

Since @s1na provided working patch, I wouldn't want this issue to get forgotten as fix is already known. Is there any way I could help to push this forward?