Pruned node unable to start when a wallet is present #26655

This is the weirdest bug I have seen in a while, as I can't reproduce, but it happens persistently on a server of one of our users.

I tried to delete wallet and recreate it, it doesn't work, still stuck. I tried to remove the wallet and not recreate it, and bitcoin core starts properly.

I uploaded a wallet generated there: https://aois.blob.core.windows.net/public/wallet.tar.gz

I tried to load the wallet on my local node (non-pruned), it works and there is no rescan.

2022-12-08T00:11:47Z No coin database inconsistencies in last 6 blocks (503 transactions)
2022-12-08T00:11:47Z  block index           10522ms
2022-12-08T00:11:47Z init message: Loading wallet…
2022-12-08T00:11:47Z BerkeleyEnvironment::Open: LogDir=C:\Users\NicolasDorier\tmp\database ErrorFile=C:\Users\NicolasDorier\tmp\db.log
2022-12-08T00:11:47Z [default wallet] Wallet File Version = 169900
2022-12-08T00:11:47Z [default wallet] Keys: 2001 plaintext, 0 encrypted, 2001 w/ metadata, 2001 total. Unknown wallet records: 0
2022-12-08T00:11:47Z [default wallet] Wallet completed loading in              60ms
2022-12-08T00:11:47Z [default wallet] setKeyPool.size() = 2000
2022-12-08T00:11:47Z [default wallet] mapWallet.size() = 0
2022-12-08T00:11:47Z [default wallet] m_address_book.size() = 0
2022-12-08T00:11:47Z Unsetting NODE_NETWORK on prune mode
20

On the server of the user the node is pruned, and there is a rescan with error

2022-12-08T00:01:33Z [default wallet] Wallet completed loading in             152ms
2022-12-08T00:01:33Z Error: Prune: last wallet synchronisation goes beyond pruned data. You need to -reindex (download the whole blockchain again in case of pruned node)
Error: Prune: last wallet synchronisation goes beyond pruned data. You need to -reindex (download the whole blockchain again in case of pruned node)

Even though the wallet just got created.

The pruneheight should also be big enough:

getblockchaininfo

{
  "chain": "test",
  "blocks": 2410292,
  "headers": 2410292,
  "bestblockhash": "0000000000000022a51915a9d3473d6185744de708a1bf008a471e702dfc43fc",
  "difficulty": 82946068.46057868,
  "time": 1670458413,
  "mediantime": 1670455720,
  "verificationprogress": 0.9999988037011049,
  "initialblockdownload": false,
  "chainwork": "000000000000000000000000000000000000000000000839f6768de759ba571f",
  "size_on_disk": 8702871138,
  "pruned": true,
  "pruneheight": 1441677,
  "automatic_pruning": true,
  "prune_target_size": 104857600000,
  "warnings": "Unknown new rules activated (versionbit 28)"
}

Anything else I can provide you? I am really at loss about why this specific node is asking for a rescan.

Expected behavior

Node starts properly when a new wallet is just created.

Actual behavior

Node stuck

2022-12-08T00:00:24Z Bitcoin Core version v24.0.0 (release build)
2022-12-08T00:00:24Z Using the 'sse4(1way),sse41(4way)' SHA256 implementation
2022-12-08T00:00:24Z Default data directory /home/bitcoin/.bitcoin
2022-12-08T00:00:24Z Using data directory /home/bitcoin/.bitcoin/testnet3
2022-12-08T00:00:24Z Config file: /home/bitcoin/.bitcoin/bitcoin.conf
2022-12-08T00:00:24Z Config file arg: testnet="1"
2022-12-08T00:00:24Z Config file arg: [test] maxmempool="500"
2022-12-08T00:00:24Z Config file arg: [test] onion="tor:9050"
2022-12-08T00:00:24Z Config file arg: [test] port="39388"
2022-12-08T00:00:24Z Config file arg: [test] printtoconsole="1"
2022-12-08T00:00:24Z Config file arg: [test] prune="100000"
2022-12-08T00:00:24Z Config file arg: [test] rpcallowip="::/0"
2022-12-08T00:00:24Z Config file arg: [test] rpcallowip="0.0.0.0/0"
2022-12-08T00:00:24Z Config file arg: [test] rpcauth=****
2022-12-08T00:00:24Z Config file arg: [test] rpcauth=****
2022-12-08T00:00:24Z Config file arg: [test] rpcbind=****
2022-12-08T00:00:24Z Config file arg: [test] rpcport="43782"
2022-12-08T00:00:24Z Config file arg: [test] walletdir="/walletdata/testnet"
2022-12-08T00:00:24Z Config file arg: [test] whitelist="0.0.0.0/0"
2022-12-08T00:00:24Z Config file arg: [test] zmqpubhashblock="tcp://0.0.0.0:28334"
2022-12-08T00:00:24Z Config file arg: [test] zmqpubrawblock="tcp://0.0.0.0:28332"
2022-12-08T00:00:24Z Config file arg: [test] zmqpubrawtx="tcp://0.0.0.0:28333"
2022-12-08T00:00:24Z Using at most 125 automatic connections (1048576 file descriptors available)
2022-12-08T00:00:24Z Using 16 MiB out of 16 MiB requested for signature cache, able to store 524288 elements
2022-12-08T00:00:24Z Using 16 MiB out of 16 MiB requested for script execution cache, able to store 524288 elements
2022-12-08T00:00:24Z Script verification uses 1 additional threads
2022-12-08T00:00:24Z scheduler thread start
2022-12-08T00:00:24Z WARNING: the RPC server is not safe to expose to untrusted networks such as the public internet
2022-12-08T00:00:24Z [http] creating work queue of depth 16
2022-12-08T00:00:24Z Using random cookie authentication.
2022-12-08T00:00:24Z Generated RPC authentication cookie /home/bitcoin/.bitcoin/testnet3/.cookie
2022-12-08T00:00:24Z Using rpcauth authentication.
2022-12-08T00:00:24Z [http] starting 4 worker threads
2022-12-08T00:00:24Z Using wallet directory /walletdata/testnet
2022-12-08T00:00:24Z init message: Verifying wallet(s)…
2022-12-08T00:00:24Z Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
2022-12-08T00:00:24Z Using wallet /walletdata/testnet/wallet.dat
2022-12-08T00:00:24Z BerkeleyEnvironment::Open: LogDir=/walletdata/testnet/database ErrorFile=/walletdata/testnet/db.log
2022-12-08T00:00:24Z Using /16 prefix for IP bucketing
2022-12-08T00:00:24Z init message: Loading P2P addresses…
2022-12-08T00:00:25Z Loaded 22930 addresses from peers.dat  393ms
2022-12-08T00:00:25Z init message: Loading banlist…
2022-12-08T00:00:25Z SetNetworkActive: true
2022-12-08T00:00:25Z Cache configuration:
2022-12-08T00:00:25Z * Using 2.0 MiB for block index database
2022-12-08T00:00:25Z * Using 8.0 MiB for chain state database
2022-12-08T00:00:25Z * Using 440.0 MiB for in-memory UTXO set (plus up to 476.8 MiB of unused mempool space)
2022-12-08T00:00:25Z init message: Loading block index…
2022-12-08T00:00:25Z Assuming ancestors of block 0000000000000004877fa2d36316398528de4f347df2f8a96f76613a298ce060 have valid signatures.
2022-12-08T00:00:25Z Setting nMinimumChainWork=00000000000000000000000000000000000000000000076f6e7cbd0beade5d20
2022-12-08T00:00:25Z Prune configured to target 100000 MiB on disk for block and undo files.
2022-12-08T00:00:25Z Switching active chainstate to Chainstate [ibd] @ height -1 (null)
2022-12-08T00:00:25Z Opening LevelDB in /home/bitcoin/.bitcoin/testnet3/blocks/index
2022-12-08T00:00:25Z Opened LevelDB successfully
2022-12-08T00:00:25Z Using obfuscation key for /home/bitcoin/.bitcoin/testnet3/blocks/index: 0000000000000000
2022-12-08T00:01:15Z LoadBlockIndexDB: last block file = 211
2022-12-08T00:01:15Z LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=3150, size=89162763, heights=2407141...2410289, time=2022-11-19...2022-12-07)
2022-12-08T00:01:15Z Checking all blk files are present...
2022-12-08T00:01:16Z LoadBlockIndexDB(): Block files have previously been pruned
2022-12-08T00:01:30Z Opening LevelDB in /home/bitcoin/.bitcoin/testnet3/chainstate
2022-12-08T00:01:30Z Opened LevelDB successfully
2022-12-08T00:01:30Z Using obfuscation key for /home/bitcoin/.bitcoin/testnet3/chainstate: dd2d995e0b39a1e4
2022-12-08T00:01:32Z Loaded best chain: hashBestChain=000000000000002e323100923fd63334a2b4e3e087609da60e07bfcb41fc3e66 height=2410289 date=2022-12-07T23:46:07Z progress=0.999998
2022-12-08T00:01:32Z init message: Verifying blocks…
2022-12-08T00:01:32Z Verifying last 6 blocks at level 3
2022-12-08T00:01:32Z [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
2022-12-08T00:01:32Z No coin database inconsistencies in last 6 blocks (433 transactions)
2022-12-08T00:01:32Z  block index           67622ms
2022-12-08T00:01:32Z init message: Loading wallet…
2022-12-08T00:01:32Z BerkeleyEnvironment::Open: LogDir=/walletdata/testnet/database ErrorFile=/walletdata/testnet/db.log
2022-12-08T00:01:32Z [default wallet] Wallet file version = 10500, last client version = 240000
2022-12-08T00:01:33Z [default wallet] Keys: 2001 plaintext, 0 encrypted, 2001 w/ metadata, 2001 total. Unknown wallet records: 0
2022-12-08T00:01:33Z [default wallet] Wallet completed loading in             152ms
2022-12-08T00:01:33Z Error: Prune: last wallet synchronisation goes beyond pruned data. You need to -reindex (download the whole blockchain again in case of pruned node)
Error: Prune: last wallet synchronisation goes beyond pruned data. You need to -reindex (download the whole blockchain again in case of pruned node)
2022-12-08T00:01:33Z Shutdown: In progress...
2022-12-08T00:01:33Z scheduler thread exit
2022-12-08T00:01:34Z Shutdown: done

To reproduce

I can only reproduce on a single instance, I tried to reproduce on my own server and didn't managed to.

bitcoin-wallet "-datadir=/walletdata/testnet" "-legacy" "-wallet=" create

Config

testnet=1
[test]
walletdir=/walletdata/testnet

printtoconsole=1
rpcallowip=::/0
rpcport=43782
rpcbind=0.0.0.0:43782
rpcallowip=0.0.0.0/0
port=39388
whitelist=0.0.0.0/0
maxmempool=500

prune=100000
zmqpubrawblock=tcp://0.0.0.0:28332
zmqpubrawtx=tcp://0.0.0.0:28333
zmqpubhashblock=tcp://0.0.0.0:28334

onion=tor:9050

System information

Bitcoin Core 24.0 amd64 Docker Hub btcpayserver/bitcoin:24.0.

cc @achow101

Even though the wallet just got created.

How was it initially created? Was it with the bitcoin-wallet create command like in your reproduction steps?

The provided wallet lacks a bestblock record which is used to inform Bitcoin Core of the chain that was last scanned with this wallet. Without this record, we assume the worst case which is that a rescan from genesis is required. As pruned nodes are unable to perform a rescan from genesis, such wallets will result in the error shown. However archival nodes may not observe a full rescan as after checking the bestblock record, we will check the key birthdays to determine the scope of the rescan.

Wallets lacking a bestblock record can be created using wallet tool bitcoin-wallet. This is because the wallet tool is a contextless tool - it does not have access to the blockchain. Thus it is unable to insert a correct bestblock record into newly created wallets. Given that your reproduction steps include the usage of the wallet tool, I suspect that the reason for this error is that the user is creating wallets with the wallet tool and then trying to load them into a pruned node.

If the user only needs to create new wallets, they can do so with the createwallet RPC. This should avoid this problem. If the issue is that they need to load a particular wallet that was creating using the wallet tool, then a workaround would be to load the wallet into an archival node to get the bestblock record written, then load the wallet into the pruned node. Alternatively, they could modify the database directly and insert a bestblock record borrowed from a different wallet that could be loaded.

Maybe the wallet could write a bestblock itself, if the birthday is after the last pruned block?

Maybe the wallet could write a bestblock itself, if the birthday is after the last pruned block?

We should just do the birthday check first.

@achow101 this make sense, but now what doesn't make sense is: Why there is no rescan on any other server?

On my own server, following the same steps, there is no issue in restarting. Even if my node is pruned.

Why there is no rescan on any other server?

On my own server, following the same steps, there is no issue in restarting. Even if my node is pruned.

That's odd. I'm able to replicate the issue.

@achow101 I confirm I could reproduce on another server. I don't know why on some server I couldn't.

I am also surprised I only saw this problem once.

I think I will switch to use the RPC API to create the wallet rather than the utility.

Just here to confirm: I switched from creating the wallet through bitcoin-wallet utility to using RPC. It fixes our issue, though it should never have been an issue on the first place and #26679 seems to fix it. (didn't tested it though)