Part of #34400
On master, the wallet_fast_rescan.py test will pass even if the fast rescan filters are not updated during wallet rescan. This PR improves the wallet_fast_rescan.py test so that this no longer happens. Testers can verify by commenting out https://github.com/bitcoin/bitcoin/blob/master/src/wallet/wallet.cpp#L1901 and running the wallet_fast_rescan.py test. The test will pass on master but fail on this PR.
The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.
See the guideline for information on the review process.
| Type | Reviewers |
|---|---|
| ACK | rkrux |
If your review is incorrectly listed, please copy-paste <!–meta-tag:bot-skip–> into the comment that the bot should ignore.
Reviewers, this pull request conflicts with the following ones:
If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.
68+ if 'range' not in desc_info:
69+ spk = bytes.fromhex(fixed_key.p2wpkh_script)
70+ self.log.info(f"-> fixed non-range descriptor address {fixed_key.p2wpkh_addr}")
71+ wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
72+ num_txs += 1
73+ self.generate(node, 1)
While it seems fine to mine the transaction related to the non-ranged descriptor in a separate block, I think it’d be thorough to mine a block with transaction(s) unrelated to the wallet at all so that the fast rescan doesn’t fetch it, which can be asserted for in the debug log. Consider the following diff:
0diff --git a/test/functional/wallet_fast_rescan.py b/test/functional/wallet_fast_rescan.py
1index a917a9db32..93078386df 100755
2--- a/test/functional/wallet_fast_rescan.py
3+++ b/test/functional/wallet_fast_rescan.py
4@@ -14,7 +15,7 @@ from test_framework.wallet_util import get_generate_key
5
6
7 KEYPOOL_SIZE = 100 # smaller than default size to speed-up test
8-NUM_BLOCKS = 6 # number of blocks to mine
9+NUM_BLOCKS = 7 # number of blocks to mine
10
11
12 class WalletFastRescanTest(BitcoinTestFramework):
13@@ -32,7 +33,7 @@ class WalletFastRescanTest(BitcoinTestFramework):
14
15 def run_test(self):
16 node = self.nodes[0]
17- wallet = MiniWallet(node)
18+ funding_wallet = MiniWallet(node)
19
20 self.log.info("Create descriptor wallet with backup")
21 WALLET_BACKUP_FILENAME = node.datadir_path / 'wallet.bak'
22@@ -45,7 +46,8 @@ class WalletFastRescanTest(BitcoinTestFramework):
23
24 self.log.info("Create txs sending to end range address of each descriptor, triggering top-ups")
25 num_txs = 0
26- for i in range(NUM_BLOCKS-1):
27+ fast_rescan_messages = []
28+ for i in range(NUM_BLOCKS-2):
29 self.log.info(f"Block {i+1}/{NUM_BLOCKS}")
30 for desc_info in w.listdescriptors()['descriptors']:
31 if 'range' in desc_info:
32@@ -53,28 +55,39 @@ class WalletFastRescanTest(BitcoinTestFramework):
33 addr = w.deriveaddresses(desc_info['desc'], [end_range, end_range])[0]
34 spk = address_to_scriptpubkey(addr)
35 self.log.info(f"-> range [{start_range},{end_range}], last address {addr}")
36- wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
37+ funding_wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
38 num_txs += 1
39 self.generate(node, 1)
40+ chain_info = self.nodes[0].getblockchaininfo()
41+ fast_rescan_messages.append(f"Fast rescan: inspect block {chain_info['blocks']} [{chain_info['bestblockhash']}] (filter matched)")
42
43 self.log.info("Create txs sending to non-ranged descriptors")
44- self.log.info(f"Block {NUM_BLOCKS}/{NUM_BLOCKS}")
45+ self.log.info(f"Block {NUM_BLOCKS-1}/{NUM_BLOCKS}")
46 for desc_info in w.listdescriptors()['descriptors']:
47 if 'range' not in desc_info:
48 spk = bytes.fromhex(fixed_key.p2wpkh_script)
49 self.log.info(f"-> fixed non-range descriptor address {fixed_key.p2wpkh_addr}")
50- wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
51+ funding_wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
52 num_txs += 1
53 self.generate(node, 1)
54+ chain_info = self.nodes[0].getblockchaininfo()
55+ fast_rescan_messages.append(f"Fast rescan: inspect block {chain_info['blocks']} [{chain_info['bestblockhash']}] (filter matched)")
56+
57+ self.log.info("Create tx unrelated to the wallet under consideration")
58+ self.log.info(f"Block {NUM_BLOCKS}/{NUM_BLOCKS}")
59+ funding_wallet.send_self_transfer(from_node=node)
60+ self.generate(node, 1)
61
62 self.log.info("Import wallet backup with block filter index")
63- with node.assert_debug_log(['fast variant using block filters']):
64+ with node.assert_debug_log(['fast variant using block filters', *fast_rescan_messages]):
65 node.restorewallet('rescan_fast', WALLET_BACKUP_FILENAME)
66 txids_fast = self.get_wallet_txids(node, 'rescan_fast')
67
68 self.log.info("Import non-active descriptors with block filter index")
69 node.createwallet(wallet_name='rescan_fast_nonactive', disable_private_keys=True, blank=True)
70- with node.assert_debug_log(['fast variant using block filters']):
71+ with node.assert_debug_log(['fast variant using block filters', *fast_rescan_messages]):
72 w = node.get_wallet_rpc('rescan_fast_nonactive')
73 w.importdescriptors([{"desc": descriptor['desc'], "timestamp": 0} for descriptor in descriptors])
74 txids_fast_nonactive = self.get_wallet_txids(node, 'rescan_fast_nonactive')
MiniWallet instance to funding_wallet to avoid confusion with the other wallets under consideration.
While it seems fine to mine the transaction related to the non-ranged descriptor in a separate block, I think it’d be thorough to mine a block with transaction(s) unrelated to the wallet at all so that the fast rescan doesn’t fetch it, which can be asserted for in the debug log.
This was a good idea, but there is the possibility of false positives with block filters, so a block can be fetched(with a low probability) even if the wallet spk is not in the set.
The above diff also renames the
MiniWalletinstance tofunding_walletto avoid confusion with the other wallets under consideration.
Done
to mine a block with transaction(s) unrelated to the wallet at all so that the fast rescan doesn’t fetch it, which can be asserted for in the debug log.
This was a good idea, but there is the possibility of false positives with block filters, so a block can be fetched(with a low probability) even if the wallet spk is not in the set.
I see that the last portion of my comment was misleading. I didn’t mean to suggest that it should be asserted that the block is not being fetched when the filter didn’t match, something that the suggested diff also doesn’t do. Although the reason for not suggesting it was not because of false positives but because of the lack of such a debug log (there is no log when fetch_block is set to false). Thus, the suggested diff limits the assertions to only filter matches.
57 self.log.info(f"-> range [{start_range},{end_range}], last address {addr}")
58- else:
59- spk = bytes.fromhex(fixed_key.p2wpkh_script)
60- self.log.info(f"-> fixed non-range descriptor address {fixed_key.p2wpkh_addr}")
61 wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
62+ num_txs += 1
0 self.log.info(f"-> range [{start_range},{end_range}], last address {addr}")
1wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
Why do the transactions need to be created and sent in the case range property is not present? It will end up creating a transaction sending to spk of the previous iteration in case range property is not present, which seems incorrect. Consider the following which reads easier too:
0 self.log.info(f"Block {i+1}/{NUM_BLOCKS}")
1- for desc_info in w.listdescriptors()['descriptors']:
2- if 'range' in desc_info:
3- start_range, end_range = desc_info['range']
4- addr = w.deriveaddresses(desc_info['desc'], [end_range, end_range])[0]
5- spk = address_to_scriptpubkey(addr)
6- self.log.info(f"-> range [{start_range},{end_range}], last address {addr}")
7+ descs = [desc_info for desc_info in w.listdescriptors()['descriptors'] if 'range' in desc_info]
8+ for desc_info in descs:
9+ start_range, end_range = desc_info['range']
10+ addr = w.deriveaddresses(desc_info['desc'], [end_range, end_range])[0]
11+ spk = address_to_scriptpubkey(addr)
12+ self.log.info(f"-> range [{start_range},{end_range}], last address {addr}")
13 wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
14 num_txs += 1
15 self.generate(node, 1)
67+ for desc_info in w.listdescriptors()['descriptors']:
68+ if 'range' not in desc_info:
69+ spk = bytes.fromhex(fixed_key.p2wpkh_script)
70+ self.log.info(f"-> fixed non-range descriptor address {fixed_key.p2wpkh_addr}")
71+ wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
72+ num_txs += 1
num_txs will also be reduced with the following diff because unnecessary transactions are being created at the moment.
60- self.log.info(f"-> fixed non-range descriptor address {fixed_key.p2wpkh_addr}")
61 wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
62+ num_txs += 1
63 self.generate(node, 1)
64
65+ self.log.info("Create txs sending to non-ranged descriptors")
0- self.log.info("Create txs sending to non-ranged descriptors")
1+ self.log.info("Create tx sending to non-ranged descriptor")
There should be only one such desc.
65+ self.log.info("Create txs sending to non-ranged descriptors")
66+ self.log.info(f"Block {NUM_BLOCKS}/{NUM_BLOCKS}")
67+ for desc_info in w.listdescriptors()['descriptors']:
68+ if 'range' not in desc_info:
69+ spk = bytes.fromhex(fixed_key.p2wpkh_script)
70+ self.log.info(f"-> fixed non-range descriptor address {fixed_key.p2wpkh_addr}")
This doesn’t actually use the values from the descriptor and instead uses the fixed key, which is not ideal.
0- spk = bytes.fromhex(fixed_key.p2wpkh_script)
1- self.log.info(f"-> fixed non-range descriptor address {fixed_key.p2wpkh_addr}")
2+ addr = w.deriveaddresses(desc_info['desc'])[0]
3+ spk = address_to_scriptpubkey(addr)
4+ self.log.info(f"-> fixed non-range descriptor address {addr}")
40@@ -42,24 +41,32 @@ def run_test(self):
41 fixed_key = get_generate_key()
42 print(w.importdescriptors([{"desc": descsum_create(f"wpkh({fixed_key.privkey})"), "timestamp": "now"}]))
Concept ACK, very nice figuring out the issue in the test. I suggest few changes.
I also wanted to add an assertion checking that the fast rescan is indeed faster than the slow rescan by adding the following time calculation in both restoration with and without blockfilter index. I tried it for multiple extra non-matching blocks so that the fast rescan can bypass fetching them, but I didn’t get deterministic results, so unfortunately had to abandon the idea.
0@@ -82,7 +96,9 @@ class WalletFastRescanTest(BitcoinTestFramework):
1 self.restart_node(0, [f'-keypool={KEYPOOL_SIZE}', '-blockfilterindex=0'])
2 self.log.info("Import wallet backup w/o block filter index")
3 with node.assert_debug_log(['slow variant inspecting all blocks']):
4+ start_time = time.time()
5 node.restorewallet("rescan_slow", WALLET_BACKUP_FILENAME)
6+ print(time.time() - start_time)
7 txids_slow = self.get_wallet_txids(node, 'rescan_slow')
I also wanted to add an assertion checking that the fast rescan is indeed faster than the slow rescan by adding the following time calculation in both restoration with and without blockfilter index. I tried it for multiple extra non-matching blocks so that the fast rescan can bypass fetching them, but I didn’t get deterministic results, so unfortunately had to abandon the idea.
Fast rescan is not always strictly faster. See #25957 (comment). The time to check the filter is significant, and this will make fast rescan slower if the blocks are not big enough.
52+ self.log.info(f"Block 1/{NUM_BLOCKS}")
53+ spk = bytes.fromhex(fixed_key.p2wpkh_script)
54+ self.log.info(f"-> fixed non-range descriptor address {fixed_key.p2wpkh_addr}")
55+ funding_wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
56+ num_txs += 1
57+ self.generate(node, 1)
Is it intentional to not assert for the filter match log for this block?
0--- a/test/functional/wallet_fast_rescan.py
1+++ b/test/functional/wallet_fast_rescan.py
2@@ -44,6 +44,7 @@ class WalletFastRescanTest(BitcoinTestFramework):
3 w.backupwallet(WALLET_BACKUP_FILENAME)
4
5 num_txs = 0
6+ fast_rescan_messages = []
7
8 self.log.info("Create tx sending to non-ranged descriptors")
9 self.log.info(f"Block 1/{NUM_BLOCKS}")
10@@ -52,9 +53,11 @@ class WalletFastRescanTest(BitcoinTestFramework):
11 funding_wallet.send_to(from_node=node, scriptPubKey=spk, amount=10000)
12 num_txs += 1
13 self.generate(node, 1)
14+ chain_info = self.nodes[0].getblockchaininfo()
15+ fast_rescan_messages.append(f"Fast rescan: inspect block {chain_info['blocks']} [{chain_info['bestblockhash']}] (filter matched)")
16
17 self.log.info("Create txs sending to end range address of each descriptor, triggering top-ups")
18- fast_rescan_messages = []
19 for i in range(1, NUM_BLOCKS):
20 self.log.info(f"Block {i+1}/{NUM_BLOCKS}")
21 ranged_descs = [desc for desc in descriptors if 'range' in desc]
The fixed non-range descriptor address ensured that the FastWalletRescanFilter would match all Blocks even if the filter wasn't properly updated.
This commit moves the non-range descriptor tx to a different block, so that the filters must be updated after each TopUp for the test to pass.
Co-authored-by: rkrux <rkrux.connect@gmail.com>
lgtm ACK e7796a5d55cf9c7a5e7f5ff59c261d051acd102b
Thanks for addressing the comments.