ci: failure in feature_backwards_compatibility.py --descriptors #24400

Seen in https://cirrus-ci.com/task/4695237263097856?logs=ci#L1143:

147/236 - feature_backwards_compatibility.py --descriptors failed, Duration: 49 s
stdout:
2022-02-20T12:49:35.179000Z TestFramework (INFO): Initializing test directory /tmp/cirrus-build/ci/scratch/test_runner/test_runner_₿_🏃_20220220_124152/feature_backwards_compatibility_111
2022-02-20T12:49:41.126000Z TestFramework (INFO): Test wallet backwards compatibility...
2022-02-20T12:50:23.374000Z TestFramework (INFO): Test wallet upgrade path...
2022-02-20T12:50:24.053000Z TestFramework (INFO): Stopping nodes
stderr:
Traceback (most recent call last):
  File "/tmp/cirrus-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/feature_backwards_compatibility.py", line 424, in <module>
    BackwardsCompatibilityTest().main()
  File "/tmp/cirrus-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 155, in main
    exit_code = self.shutdown()
  File "/tmp/cirrus-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 304, in shutdown
    self.stop_nodes()
  File "/tmp/cirrus-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 559, in stop_nodes
    node.wait_until_stopped()
  File "/tmp/cirrus-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_node.py", line 382, in wait_until_stopped
    wait_until_helper(self.is_node_stopped, timeout=timeout, timeout_factor=self.timeout_factor)
  File "/tmp/cirrus-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/util.py", line 265, in wait_until_helper
    if predicate():
  File "/tmp/cirrus-build/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_node.py", line 373, in is_node_stopped
    "Node returned non-zero exit code (%d) when stopping" % return_code)
AssertionError: [node 5] Node returned non-zero exit code (-6) when stopping

 node2 2022-02-20T12:50:24.275854Z [] Shutdown: done 
 test  2022-02-20T12:50:24.313000Z TestFramework.node2 (DEBUG): Node stopped 
 test  2022-02-20T12:50:24.313000Z TestFramework.node3 (DEBUG): Node stopped 
 test  2022-02-20T12:50:24.313000Z TestFramework.node4 (DEBUG): Node stopped 
 node4 stderr Error: Error loading w3_v18: Wallet requires newer version of Bitcoin Core 
 node4 stderr Error: wallet.dat corrupt, salvage failed 
 node4 stderr Error: wallet.dat corrupt, salvage failed 
 node4 stderr Error: wallet.dat corrupt, salvage failed 
 node5 stderr terminate called after throwing an instance of 'std::runtime_error'
  what():  CDB: Error -30974, can't open database u1_v16 

I am also running into this locally sometimes :man_shrugging:

I am also running into this locally sometimes

Same.

Also in https://cirrus-ci.com/task/4742579576111104?logs=ci#L1059

https://cirrus-ci.com/task/6641746820988928?logs=ci#L5124

I'm able to reproduce this failure but I don't understand what is causing it.

I'm using rr (https://github.com/rr-debugger/rr) in 'chaos' mode to reproduce the failure. Chaos mode is basically randomized thread priority. And I execute the test in parallel batches of 5.

This patch is required to make the testsuite work with rr:

<details> <summary>Diff</summary>

diff --git a/test/functional/feature_backwards_compatibility.py b/test/functional/feature_backwards_compatibility.py
index 5fe4a95f6f..d66aa8d32b 100755
--- a/test/functional/feature_backwards_compatibility.py
+++ b/test/functional/feature_backwards_compatibility.py
@@ -38,6 +38,7 @@ class BackwardsCompatibilityTest(BitcoinTestFramework):
     def set_test_params(self):
         self.setup_clean_chain = True
         self.num_nodes = 10
+        self.disable_syscall_sandbox = True
         # Add new version after each release:
         self.extra_args = [
             ["-addresstype=bech32", "-whitelist=noban@127.0.0.1"], # Pre-release: use to mine blocks. noban for immediate tx relay

</details>

seq 100 | xargs -i -P 5 rr record --chaos python test/functional/feature_backwards_compatibility.py --legacy-wallet --timeout-factor=0

After only a few runs I get:

AssertionError: [node 9] Node returned non-zero exit code (-6) when stopping

$ cat node9/stderr/*
terminate called after throwing an instance of 'std::runtime_error'
  what():  CDB: Error -30974, can't open database u1_v16

$ cat node9/regtest/wallets/db.log 
file u1_v16 has LSN 1/2442, past end of log at 1/460
Commonly caused by moving a database from one database environment
to another without clearing the database LSNs, or by removing all of
the log files from a database environment
file u1_v16 has LSN 1/2442, past end of log at 1/460
Commonly caused by moving a database from one database environment
to another without clearing the database LSNs, or by removing all of
the log files from a database environment
DB_ENV->log_flush: LSN of 1/2442 past current end-of-log of 1/460
Database environment corrupt; the wrong log files may have been removed or incompatible database files imported from another environment
PANIC: DB_RUNRECOVERY: Fatal error, run database recovery
u1_v16: unable to flush page: 3
PANIC: fatal region error detected; run recovery
PANIC: fatal region error detected; run recovery
PANIC: fatal region error detected; run recovery

I've tried to use the -detachdb=1 startup option based on this comment #1472 (comment) but no success.

Note that there seems to be two intermittent failures: one with the legacy wallet in https://cirrus-ci.com/task/6641746820988928?logs=ci#L89 where node9 is crashing (Bitcoin Core v0.16.3) and one with the descriptor wallet in https://cirrus-ci.com/task/4695237263097856?logs=ci#L1143 where node5 is crashing.

Is there a race where two nodes read/write the same wallet or the wallet is copied before fully flushed?