Pruned node unable to start when a wallet is present

NicolasDorier commented at 0:14 am on December 8, 2022: contributor

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.

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

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

02022-12-08T00:01:33Z [default wallet] Wallet completed loading in             152ms
12022-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)
2Error: 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:

0getblockchaininfo

 0{
 1  "chain": "test",
 2  "blocks": 2410292,
 3  "headers": 2410292,
 4  "bestblockhash": "0000000000000022a51915a9d3473d6185744de708a1bf008a471e702dfc43fc",
 5  "difficulty": 82946068.46057868,
 6  "time": 1670458413,
 7  "mediantime": 1670455720,
 8  "verificationprogress": 0.9999988037011049,
 9  "initialblockdownload": false,
10  "chainwork": "000000000000000000000000000000000000000000000839f6768de759ba571f",
11  "size_on_disk": 8702871138,
12  "pruned": true,
13  "pruneheight": 1441677,
14  "automatic_pruning": true,
15  "prune_target_size": 104857600000,
16  "warnings": "Unknown new rules activated (versionbit 28)"
17}

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

 02022-12-08T00:00:24Z Bitcoin Core version v24.0.0 (release build)
 12022-12-08T00:00:24Z Using the 'sse4(1way),sse41(4way)' SHA256 implementation
 22022-12-08T00:00:24Z Default data directory /home/bitcoin/.bitcoin
 32022-12-08T00:00:24Z Using data directory /home/bitcoin/.bitcoin/testnet3
 42022-12-08T00:00:24Z Config file: /home/bitcoin/.bitcoin/bitcoin.conf
 52022-12-08T00:00:24Z Config file arg: testnet="1"
 62022-12-08T00:00:24Z Config file arg: [test] maxmempool="500"
 72022-12-08T00:00:24Z Config file arg: [test] onion="tor:9050"
 82022-12-08T00:00:24Z Config file arg: [test] port="39388"
 92022-12-08T00:00:24Z Config file arg: [test] printtoconsole="1"
102022-12-08T00:00:24Z Config file arg: [test] prune="100000"
112022-12-08T00:00:24Z Config file arg: [test] rpcallowip="::/0"
122022-12-08T00:00:24Z Config file arg: [test] rpcallowip="0.0.0.0/0"
132022-12-08T00:00:24Z Config file arg: [test] rpcauth=****
142022-12-08T00:00:24Z Config file arg: [test] rpcauth=****
152022-12-08T00:00:24Z Config file arg: [test] rpcbind=****
162022-12-08T00:00:24Z Config file arg: [test] rpcport="43782"
172022-12-08T00:00:24Z Config file arg: [test] walletdir="/walletdata/testnet"
182022-12-08T00:00:24Z Config file arg: [test] whitelist="0.0.0.0/0"
192022-12-08T00:00:24Z Config file arg: [test] zmqpubhashblock="tcp://0.0.0.0:28334"
202022-12-08T00:00:24Z Config file arg: [test] zmqpubrawblock="tcp://0.0.0.0:28332"
212022-12-08T00:00:24Z Config file arg: [test] zmqpubrawtx="tcp://0.0.0.0:28333"
222022-12-08T00:00:24Z Using at most 125 automatic connections (1048576 file descriptors available)
232022-12-08T00:00:24Z Using 16 MiB out of 16 MiB requested for signature cache, able to store 524288 elements
242022-12-08T00:00:24Z Using 16 MiB out of 16 MiB requested for script execution cache, able to store 524288 elements
252022-12-08T00:00:24Z Script verification uses 1 additional threads
262022-12-08T00:00:24Z scheduler thread start
272022-12-08T00:00:24Z WARNING: the RPC server is not safe to expose to untrusted networks such as the public internet
282022-12-08T00:00:24Z [http] creating work queue of depth 16
292022-12-08T00:00:24Z Using random cookie authentication.
302022-12-08T00:00:24Z Generated RPC authentication cookie /home/bitcoin/.bitcoin/testnet3/.cookie
312022-12-08T00:00:24Z Using rpcauth authentication.
322022-12-08T00:00:24Z [http] starting 4 worker threads
332022-12-08T00:00:24Z Using wallet directory /walletdata/testnet
342022-12-08T00:00:24Z init message: Verifying wallet(s)…
352022-12-08T00:00:24Z Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
362022-12-08T00:00:24Z Using wallet /walletdata/testnet/wallet.dat
372022-12-08T00:00:24Z BerkeleyEnvironment::Open: LogDir=/walletdata/testnet/database ErrorFile=/walletdata/testnet/db.log
382022-12-08T00:00:24Z Using /16 prefix for IP bucketing
392022-12-08T00:00:24Z init message: Loading P2P addresses…
402022-12-08T00:00:25Z Loaded 22930 addresses from peers.dat  393ms
412022-12-08T00:00:25Z init message: Loading banlist…
422022-12-08T00:00:25Z SetNetworkActive: true
432022-12-08T00:00:25Z Cache configuration:
442022-12-08T00:00:25Z * Using 2.0 MiB for block index database
452022-12-08T00:00:25Z * Using 8.0 MiB for chain state database
462022-12-08T00:00:25Z * Using 440.0 MiB for in-memory UTXO set (plus up to 476.8 MiB of unused mempool space)
472022-12-08T00:00:25Z init message: Loading block index…
482022-12-08T00:00:25Z Assuming ancestors of block 0000000000000004877fa2d36316398528de4f347df2f8a96f76613a298ce060 have valid signatures.
492022-12-08T00:00:25Z Setting nMinimumChainWork=00000000000000000000000000000000000000000000076f6e7cbd0beade5d20
502022-12-08T00:00:25Z Prune configured to target 100000 MiB on disk for block and undo files.
512022-12-08T00:00:25Z Switching active chainstate to Chainstate [ibd] @ height -1 (null)
522022-12-08T00:00:25Z Opening LevelDB in /home/bitcoin/.bitcoin/testnet3/blocks/index
532022-12-08T00:00:25Z Opened LevelDB successfully
542022-12-08T00:00:25Z Using obfuscation key for /home/bitcoin/.bitcoin/testnet3/blocks/index: 0000000000000000
552022-12-08T00:01:15Z LoadBlockIndexDB: last block file = 211
562022-12-08T00:01:15Z LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=3150, size=89162763, heights=2407141...2410289, time=2022-11-19...2022-12-07)
572022-12-08T00:01:15Z Checking all blk files are present...
582022-12-08T00:01:16Z LoadBlockIndexDB(): Block files have previously been pruned
592022-12-08T00:01:30Z Opening LevelDB in /home/bitcoin/.bitcoin/testnet3/chainstate
602022-12-08T00:01:30Z Opened LevelDB successfully
612022-12-08T00:01:30Z Using obfuscation key for /home/bitcoin/.bitcoin/testnet3/chainstate: dd2d995e0b39a1e4
622022-12-08T00:01:32Z Loaded best chain: hashBestChain=000000000000002e323100923fd63334a2b4e3e087609da60e07bfcb41fc3e66 height=2410289 date=2022-12-07T23:46:07Z progress=0.999998
632022-12-08T00:01:32Z init message: Verifying blocks…
642022-12-08T00:01:32Z Verifying last 6 blocks at level 3
652022-12-08T00:01:32Z [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
662022-12-08T00:01:32Z No coin database inconsistencies in last 6 blocks (433 transactions)
672022-12-08T00:01:32Z  block index           67622ms
682022-12-08T00:01:32Z init message: Loading wallet…
692022-12-08T00:01:32Z BerkeleyEnvironment::Open: LogDir=/walletdata/testnet/database ErrorFile=/walletdata/testnet/db.log
702022-12-08T00:01:32Z [default wallet] Wallet file version = 10500, last client version = 240000
712022-12-08T00:01:33Z [default wallet] Keys: 2001 plaintext, 0 encrypted, 2001 w/ metadata, 2001 total. Unknown wallet records: 0
722022-12-08T00:01:33Z [default wallet] Wallet completed loading in             152ms
732022-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)
74Error: Prune: last wallet synchronisation goes beyond pruned data. You need to -reindex (download the whole blockchain again in case of pruned node)
752022-12-08T00:01:33Z Shutdown: In progress...
762022-12-08T00:01:33Z scheduler thread exit
772022-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.

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

Config

 0testnet=1
 1[test]
 2walletdir=/walletdata/testnet
 3
 4printtoconsole=1
 5rpcallowip=::/0
 6rpcport=43782
 7rpcbind=0.0.0.0:43782
 8rpcallowip=0.0.0.0/0
 9port=39388
10whitelist=0.0.0.0/0
11maxmempool=500
12
13prune=100000
14zmqpubrawblock=tcp://0.0.0.0:28332
15zmqpubrawtx=tcp://0.0.0.0:28333
16zmqpubhashblock=tcp://0.0.0.0:28334
17
18onion=tor:9050

System information

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

NicolasDorier added the label Bug on Dec 8, 2022

maflcko added the label Wallet on Dec 8, 2022

fanquake commented at 12:40 pm on December 8, 2022: member

cc @achow101

john-moffett commented at 4:24 pm on December 8, 2022: contributor

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?

achow101 commented at 4:58 pm on December 8, 2022: member

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.

maflcko commented at 5:18 pm on December 8, 2022: member

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

achow101 commented at 10:51 pm on December 8, 2022: member

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.

NicolasDorier commented at 8:07 am on December 9, 2022: contributor

@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.

achow101 commented at 10:06 pm on December 9, 2022: member

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.

NicolasDorier commented at 11:27 am on December 10, 2022: contributor

@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.

NicolasDorier commented at 11:32 am on December 10, 2022: contributor

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

NicolasDorier commented at 8:01 am on December 12, 2022: contributor

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)

achow101 closed this on Jan 11, 2023

sidhujag referenced this in commit 6b56fce29a on Jan 11, 2023

bitcoin locked this on Jan 11, 2024

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