test: Implicitly sync after generate* to preempt races and intermittent test failures #22567

The most frequent failure in functional tests are intermittent races. Fixing such bugs is cumbersome because it involves:

• Noticing the failure
• Fetching and reading the log to determine the test case that failed
• Adding a self.sync_all() where it was forgotten
• Spamming out a pr and waiting for review, which is already sparse

Also, writing a linter to catch those is not possible, nor is review effective in finding these bugs prior to merge.

Fix all future intermittent races caused by a missing sync_block call by calling sync_all implicitly after each generate*, unless opted out. This ensures that the code is race-free (with regards to blocks) when the tests pass once, instead of our current approach where the code can never be guaranteed to be race-free.

This is exactly identical functionality like #20362 (comment), but implemented differently.

Here the sync happens in the test framework, which makes the diff larger. In the other pull the sync happens in the test node.

<!--e57a25ab6845829454e8d69fc972939a-->

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

<!--174a7506f384e20aa4161008e828411d-->

Conflicts

Reviewers, this pull request conflicts with the following ones:

• #23371 (test: MiniWallet: add P2TR support and use it per default by theStack)
• #23365 (index: Fix backwards search for bestblock by mzumsande)
• #23127 (tests: Use test framework utils where possible by vincenzopalazzo)
• #23075 (refactoring: Fee estimation functional test cleanups by darosior)
• #22364 (wallet: Make a tr() descriptor by default [DO NOT MERGE UNTIL TAPROOT ACTIVATES] by achow101)
• #21726 (Improve Indices on pruned nodes via prune blockers by fjahr)
• #21283 (Implement BIP 370 PSBTv2 by achow101)
• #19461 (multiprocess: Add bitcoin-gui -ipcconnect option by ryanofsky)
• #19460 (multiprocess: Add bitcoin-wallet -ipcconnect option by ryanofsky)
• #10102 (Multiprocess bitcoin by ryanofsky)

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.

Strong Concept ACK

Intermittent test failures are the worst!

Strong concept ACK.

But I am getting certain failures when I am running all the tests together with test/function/test_runner.py -j 10.

I am not sure if that's something to do with this PR or it's some issue at my end.

• They are also happening in master.
• Failed tests are passing when I run them independently.

Failure summary :

wallet_watchonly.py --legacy-wallet                | ✓ Passed  | 22 s
wallet_watchonly.py --usecli --legacy-wallet       | ✓ Passed  | 25 s
feature_backwards_compatibility.py --descriptors   | ○ Skipped | 0 s
feature_backwards_compatibility.py --legacy-wallet | ○ Skipped | 0 s
feature_taproot.py --previous_release              | ○ Skipped | 0 s
mempool_compatibility.py                           | ○ Skipped | 0 s
wallet_upgradewallet.py --legacy-wallet            | ○ Skipped | 0 s
feature_coinstatsindex.py                          | ✖ Failed  | 68 s
feature_config_args.py                             | ✖ Failed  | 28 s
rpc_invalidateblock.py                             | ✖ Failed  | 63 s
wallet_backup.py --legacy-wallet                   | ✖ Failed  | 317 s
wallet_dump.py --legacy-wallet                     | ✖ Failed  | 168 s

One sample failure log:

202/215 - feature_config_args.py failed, Duration: 28 s

stdout:
2021-07-29T13:11:46.329000Z TestFramework (INFO): Initializing test directory /tmp/test_runner_₿_🏃_20210729_182102/feature_config_args_9
2021-07-29T13:12:00.419000Z TestFramework (INFO): Test config args logging
2021-07-29T13:12:02.455000Z TestFramework (INFO): Test seed peers
2021-07-29T13:12:12.318000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/home/raj/github-repo/mybitcoin/bitcoin/test/functional/test_framework/test_framework.py", line 128, in main
    self.run_test()
  File "/home/raj/github-repo/mybitcoin/bitcoin/test/functional/feature_config_args.py", line 221, in run_test
    self.test_seed_peers()
  File "/home/raj/github-repo/mybitcoin/bitcoin/test/functional/feature_config_args.py", line 186, in test_seed_peers
    self.start_node(0, extra_args=['-dnsseed=0', '-fixedseeds=1'])
  File "/usr/lib/python3.8/contextlib.py", line 120, in __exit__
    next(self.gen)
  File "/home/raj/github-repo/mybitcoin/bitcoin/test/functional/test_framework/test_node.py", line 408, in assert_debug_log
    self._raise_assertion_error('Expected messages "{}" does not partially match log:\n\n{}\n\n'.format(str(expected_msgs), print_log))
  File "/home/raj/github-repo/mybitcoin/bitcoin/test/functional/test_framework/test_node.py", line 166, in _raise_assertion_error
    raise AssertionError(self._node_msg(msg))
AssertionError: [node 0] Expected messages "['Loaded 0 addresses from peers.dat', 'DNS seeding disabled', 'Adding fixed seeds as -dnsseed=0, -addnode is not provided and all -seednode(s) attempted\n']" does not partially match log:

Concept ACK

Is it correct to say the tests will be more upfront in catching syncing issues because, other than being race-free, the syncing happens within the test framework? Versus #20362. Just trying to understand the tradeoffs here despite the bigger diff.

Either way, I'm all in favor to merging this one ASAP to avoid an impending avalanche of conflicting PRs :)

I am not sure if that's something to do with this PR or it's some issue at my end. They are also happening in master. Failed tests are passing when I run them independently.

If the tests also fail on master, then it can't be due to this PR. You can file an issue and hope it makes someone fix the issue or fix the issue yourself.

Is it correct to say the tests will be more upfront in catching syncing issues because, other than being race-free, the syncing happens within the test framework? Versus #20362.

As explained in the first comment (https://github.com/bitcoin/bitcoin/pull/22567#issuecomment-888162973), the two are supposed to be functionally identical.

Concept ACK

Concept ACK

Note to myself about the follow-up: #22741 (review) and commit fac7f6102feb1eb1c47ea8cb1c75c4f4dbf2f6b0

Maybe name the sync_fun param simply sync; it seems just as clear (people will see what type of values are passed) and is shorter.

Looks like two tests needed updated copyrights; scripted-diff check fails in the last commit 09fbdc3085520c6:

$ test/lint/commit-script-check.sh f4e12fd..09fbdc3

diff --git a/test/functional/rpc_signmessagewithprivkey.py b/test/functional/rpc_signmessagewithprivkey.py
index 27aee44d25..80555eab75 100755
--- a/test/functional/rpc_signmessagewithprivkey.py
+++ b/test/functional/rpc_signmessagewithprivkey.py
@@ -1,5 +1,5 @@
 #!/usr/bin/env python3
-# Copyright (c) 2016-2020 The Bitcoin Core developers
+# Copyright (c) 2016-2021 The Bitcoin Core developers
 # Distributed under the MIT software license, see the accompanying
 # file COPYING or http://www.opensource.org/licenses/mit-license.php.
 """Test RPC commands for signing messages with private key."""
diff --git a/test/functional/wallet_signmessagewithaddress.py b/test/functional/wallet_signmessagewithaddress.py
index bf6f95e3f1..74a8f2eef2 100755
--- a/test/functional/wallet_signmessagewithaddress.py
+++ b/test/functional/wallet_signmessagewithaddress.py
@@ -1,5 +1,5 @@
 #!/usr/bin/env python3
-# Copyright (c) 2016-2019 The Bitcoin Core developers
+# Copyright (c) 2016-2021 The Bitcoin Core developers
 # Distributed under the MIT software license, see the accompanying
 # file COPYING or http://www.opensource.org/licenses/mit-license.php.
 """Test Wallet commands for signing and verifying messages."""
Failed

I've archived the discussion here and created a follow-up for the remaining (scripted-diff) changes: #23474

Maybe name the sync_fun param simply sync; it seems just as clear (people will see what type of values are passed) and is shorter.

Sounds acceptable. Should I add a scripted-diff for that to the other pull?