test: wallet_reorgsrestore.py failure under valgrind #32493

issue fanquake openend this issue on May 14, 2025

fanquake commented at 10:15 am on May 14, 2025: member

I see this consistently when running the native_valgrind CI:

  0node0 2025-05-14T10:02:50.888348Z [init] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] Wallet completed loading in              61ms 
  1 node0 2025-05-14T10:02:50.889127Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: BEGIN TRANSACTION 
  2 node0 2025-05-14T10:02:50.889588Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
  3 node0 2025-05-14T10:02:50.889965Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: COMMIT TRANSACTION 
  4 node0 2025-05-14T10:02:50.890780Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: BEGIN TRANSACTION 
  5 node0 2025-05-14T10:02:50.891224Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
  6 node0 2025-05-14T10:02:50.891602Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: COMMIT TRANSACTION 
  7 node0 2025-05-14T10:02:50.892422Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: BEGIN TRANSACTION 
  8 node0 2025-05-14T10:02:50.892865Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
  9 node0 2025-05-14T10:02:50.893253Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: COMMIT TRANSACTION 
 10 node0 2025-05-14T10:02:50.894021Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: BEGIN TRANSACTION 
 11 node0 2025-05-14T10:02:50.894440Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
 12 node0 2025-05-14T10:02:50.894808Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: COMMIT TRANSACTION 
 13 node0 2025-05-14T10:02:50.895605Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: BEGIN TRANSACTION 
 14 node0 2025-05-14T10:02:50.896039Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
 15 node0 2025-05-14T10:02:50.896394Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: COMMIT TRANSACTION 
 16 node0 2025-05-14T10:02:50.897229Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: BEGIN TRANSACTION 
 17 node0 2025-05-14T10:02:50.897680Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
 18 node0 2025-05-14T10:02:50.898098Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: COMMIT TRANSACTION 
 19 node0 2025-05-14T10:02:50.898850Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: BEGIN TRANSACTION 
 20 node0 2025-05-14T10:02:50.899271Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
 21 node0 2025-05-14T10:02:50.899633Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: COMMIT TRANSACTION 
 22 node0 2025-05-14T10:02:50.900392Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: BEGIN TRANSACTION 
 23 node0 2025-05-14T10:02:50.900808Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
 24 node0 2025-05-14T10:02:50.901176Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: COMMIT TRANSACTION 
 25 node0 2025-05-14T10:02:50.902018Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: SELECT value FROM main WHERE key = x'0962657374626c6f636b' 
 26 node0 2025-05-14T10:02:50.902278Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: SELECT value FROM main WHERE key = x'1262657374626c6f636b5f6e6f6d65726b6c65' 
 27 node0 2025-05-14T10:02:50.903082Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: SELECT value FROM main WHERE key = x'0962657374626c6f636b' 
 28 node0 2025-05-14T10:02:50.903344Z [init] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: SELECT value FROM main WHERE key = x'1262657374626c6f636b5f6e6f6d65726b6c65' 
 29 node0 2025-05-14T10:02:50.903656Z [init] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] setKeyPool.size() = 8 
 30 node0 2025-05-14T10:02:50.903793Z [init] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] mapWallet.size() = 1 
 31 node0 2025-05-14T10:02:50.903915Z [init] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] m_address_book.size() = 1 
 32 node0 2025-05-14T10:02:50.905339Z [init] [init.cpp:1776] [AppInitMain] Setting NODE_NETWORK on non-prune mode 
 33 node0 2025-05-14T10:02:50.927907Z [init] [init.cpp:1886] [AppInitMain] block tree size = 228 
 34 node0 2025-05-14T10:02:50.928705Z [init] [init.cpp:1899] [AppInitMain] nBestHeight = 216 
 35 node0 2025-05-14T10:02:50.944147Z [init] [net.cpp:3168] [BindListenPort] Bound to 127.0.0.1:11000 
 36 node0 2025-05-14T10:02:50.949620Z [init] [noui.cpp:57] [noui_InitMessage] init message: Starting network threads… 
 37 node0 2025-05-14T10:02:50.967599Z [init] [net.cpp:3358] [Start] DNS seeding disabled 
 38 node0 2025-05-14T10:02:51.000689Z [init] [noui.cpp:57] [noui_InitMessage] init message: Done loading 
 39 node0 2025-05-14T10:02:51.010548Z [addcon] [util/thread.cpp:20] [TraceThread] addcon thread start 
 40 node0 2025-05-14T10:02:51.018558Z [initload] [util/thread.cpp:20] [TraceThread] initload thread start 
 41 node0 2025-05-14T10:02:51.025885Z [net] [util/thread.cpp:20] [TraceThread] net thread start 
 42 node0 2025-05-14T10:02:51.033665Z [msghand] [util/thread.cpp:20] [TraceThread] msghand thread start 
 43 node0 2025-05-14T10:02:51.040718Z [initload] [node/mempool_persist.cpp:73] [LoadMempool] Loading 0 mempool transactions from file... 
 44 node0 2025-05-14T10:02:51.044378Z [initload] [node/mempool_persist.cpp:145] [LoadMempool] Imported mempool transactions from file: 0 succeeded, 0 failed, 0 expired, 0 already there, 0 waiting for initial broadcast 
 45 node0 2025-05-14T10:02:51.045906Z [initload] [util/thread.cpp:22] [TraceThread] initload thread exit 
 46 node0 2025-05-14T10:02:51.049424Z [http] [httpserver.cpp:305] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:57014 
 47 node0 2025-05-14T10:02:51.050474Z [httpworker.8] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__ 
 48 node0 2025-05-14T10:02:51.090088Z [http] [httpserver.cpp:305] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:57014 
 49 node0 2025-05-14T10:02:51.091232Z [httpworker.4] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getmempoolinfo user=__cookie__ 
 50 test  2025-05-14T10:02:51.148000Z TestFramework.node0 (DEBUG): RPC successfully started 
 51 node0 2025-05-14T10:02:51.152352Z [http] [httpserver.cpp:305] [http_request_cb] [http] Received a POST request for /wallet/reorg_crash from 127.0.0.1:57014 
 52 node0 2025-05-14T10:02:51.155482Z [httpworker.9] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getwalletinfo user=__cookie__ 
 53 node0 2025-05-14T10:02:51.188559Z [http] [httpserver.cpp:305] [http_request_cb] [http] Received a POST request for /wallet/reorg_crash from 127.0.0.1:57014 
 54 node0 2025-05-14T10:02:51.189474Z [httpworker.2] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getbestblockhash user=__cookie__ 
 55 node0 2025-05-14T10:02:51.193212Z [http] [httpserver.cpp:305] [http_request_cb] [http] Received a POST request for /wallet/reorg_crash from 127.0.0.1:57014 
 56 node0 2025-05-14T10:02:51.194768Z [httpworker.13] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=invalidateblock user=__cookie__ 
 57 node0 2025-05-14T10:02:51.231913Z [httpworker.13] [validation.cpp:3052] [DisconnectTip] [bench] - Disconnect block: 18.37ms 
 58 node0 2025-05-14T10:02:51.247598Z [httpworker.13] [validation.cpp:2040] [IsInitialBlockDownload] Leaving InitialBlockDownload (latching to false) 
 59 node0 2025-05-14T10:02:51.257342Z [httpworker.13] [validation.cpp:2967] [UpdateTipLog] UpdateTip: new best=5613be1333f0f3305a83b733ffb5aca47778c6d38954ca181e8a271e9a256fcf height=215 version=0x30000000 log2_work=8.754888 tx=219 date='2025-05-14T10:02:30Z' progress=1.000000 cache=0.3MiB(1txo) 
 60 node0 2025-05-14T10:02:51.261048Z [httpworker.13] [validationinterface.cpp:235] [BlockDisconnected] [validation] Enqueuing BlockDisconnected: block hash=52ddf4d829b618e6614f6377915b7e20e3848ec6457f61ef997a8b95182dd2a2 block height=216 
 61 node0 2025-05-14T10:02:51.288049Z [httpworker.13] [validation.cpp:2078] [InvalidChainFound] InvalidChainFound: invalid block=52ddf4d829b618e6614f6377915b7e20e3848ec6457f61ef997a8b95182dd2a2  height=216  log2_work=8.761551  date=2025-05-14T10:02:41Z 
 62 node0 2025-05-14T10:02:51.289738Z [httpworker.13] [validation.cpp:2083] [InvalidChainFound] InvalidChainFound:  current best=5613be1333f0f3305a83b733ffb5aca47778c6d38954ca181e8a271e9a256fcf  height=215  log2_work=8.754888  date=2025-05-14T10:02:30Z 
 63 node0 2025-05-14T10:02:51.299740Z [httpworker.13] [validationinterface.cpp:187] [ActiveTipChange] [validation] ActiveTipChange: new block hash=5613be1333f0f3305a83b733ffb5aca47778c6d38954ca181e8a271e9a256fcf block height=215 
 64 node0 2025-05-14T10:02:51.309128Z [scheduler] [validationinterface.cpp:235] [operator()] [validation] BlockDisconnected: block hash=52ddf4d829b618e6614f6377915b7e20e3848ec6457f61ef997a8b95182dd2a2 block height=216 
 65 node0 2025-05-14T10:02:51.339554Z [scheduler] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: BEGIN TRANSACTION 
 66 node0 2025-05-14T10:02:51.340926Z [scheduler] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
 67 node0 2025-05-14T10:02:51.352258Z [scheduler] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: COMMIT TRANSACTION 
 68 node0 2025-05-14T10:02:51.379444Z [scheduler] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
 69 node0 2025-05-14T10:02:51.383478Z [scheduler] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] AddToWallet a206802b6f3fb1bfc0c475cf6fdf1821fa2ffb87cf9223a58c8a62355ee831e4  update Inactive (abandoned=1) 
 70 node0 2025-05-14T10:02:51.384177Z [scheduler] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest/reorg_crash/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
 71 node0 2025-05-14T10:02:51.390525Z [http] [httpserver.cpp:305] [http_request_cb] [http] Received a POST request for /wallet/reorg_crash from 127.0.0.1:57014 
 72 node0 2025-05-14T10:02:51.392793Z [httpworker.1] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=syncwithvalidationinterfacequeue user=__cookie__ 
 73 node0 2025-05-14T10:02:51.404657Z [http] [httpserver.cpp:305] [http_request_cb] [http] Received a POST request for /wallet/reorg_crash from 127.0.0.1:57014 
 74 node0 2025-05-14T10:02:51.405706Z [httpworker.15] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getwalletinfo user=__cookie__ 
 75 node0 2025-05-14T10:02:51.414251Z [http] [httpserver.cpp:305] [http_request_cb] [http] Received a POST request for /wallet/reorg_crash from 127.0.0.1:57014 
 76 node0 2025-05-14T10:02:51.417299Z [httpworker.10] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getblock user=__cookie__ 
 77 node0 2025-05-14T10:02:51.497784Z [http] [httpserver.cpp:305] [http_request_cb] [http] Received a POST request for /wallet/reorg_crash from 127.0.0.1:57014 
 78 node0 2025-05-14T10:02:51.499049Z [httpworker.12] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=gettransaction user=__cookie__ 
 79 test  2025-05-14T10:02:51.629000Z TestFramework.node0 (DEBUG): Node stopped 
 80 test  2025-05-14T10:02:51.629000Z TestFramework.utils (DEBUG): Deleting leftover cookie file 
 81 test  2025-05-14T10:02:51.630000Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up 
 82 test  2025-05-14T10:02:55.888000Z TestFramework (ERROR): Unexpected exception caught during testing 
 83                                   Traceback (most recent call last):
 84                                     File "/ci_container_base/test/functional/test_framework/test_framework.py", line 183, in main
 85                                       self.run_test()
 86                                     File "/ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/test/functional/wallet_reorgsrestore.py", line 214, in run_test
 87                                       self.test_reorg_handling_during_unclean_shutdown()
 88                                     File "/ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/test/functional/wallet_reorgsrestore.py", line 119, in test_reorg_handling_during_unclean_shutdown
 89                                       self.start_node(0)
 90                                     File "/ci_container_base/test/functional/test_framework/test_framework.py", line 583, in start_node
 91                                       node.wait_for_rpc_connection()
 92                                     File "/ci_container_base/test/functional/test_framework/test_node.py", line 275, in wait_for_rpc_connection
 93                                       raise FailedToStartError(self._node_msg(
 94                                   test_framework.test_node.FailedToStartError: [node 0] bitcoind exited with status 1 during initialization. Error: Cannot obtain a lock on directory /tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest. Bitcoin Core is probably already running.
 95                                   ************************
 96 test  2025-05-14T10:02:55.890000Z TestFramework (DEBUG): Closing down network thread 
 97 test  2025-05-14T10:02:55.941000Z TestFramework (INFO): Not stopping nodes as test failed. The dangling processes will be cleaned up later. 
 98 test  2025-05-14T10:02:55.941000Z TestFramework (WARNING): Not cleaning up dir /tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0 
 99 test  2025-05-14T10:02:55.941000Z TestFramework (ERROR): Test failed. Test logging available at /tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/test_framework.log 
100 test  2025-05-14T10:02:55.941000Z TestFramework (ERROR): 
101 test  2025-05-14T10:02:55.941000Z TestFramework (ERROR): Hint: Call /ci_container_base/test/functional/combine_logs.py '/tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0' to consolidate all logs 
102 test  2025-05-14T10:02:55.941000Z TestFramework (ERROR): 
103 test  2025-05-14T10:02:55.942000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log. 
104 test  2025-05-14T10:02:55.942000Z TestFramework (ERROR): https://github.com/bitcoin/bitcoin/issues 
105 test  2025-05-14T10:02:55.942000Z TestFramework (ERROR): 
106 node0 2025-05-14T10:03:36.019830Z [scheduler] [net.cpp:2427] [StartExtraBlockRelayPeers] [net] enabling extra block-relay-only peers 
107
108 node0 stderr Error: Cannot obtain a lock on directory /tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0/node0/regtest. Bitcoin Core is probably already running.

Looks similar to #32066, which was fixed in #32069. cc @furszy @mzumsande.

maflcko added the label CI failed on May 14, 2025
maflcko added the label Tests on May 14, 2025
maflcko commented at 12:02 pm on May 14, 2025: member

Does it always happen, or did this start at some point in the git history?

maflcko commented at 6:12 pm on May 14, 2025: member

Ubuntu Archives were down today, so I applied some patches before reproducing:

 0diff --git a/ci/test/01_base_install.sh b/ci/test/01_base_install.sh
 1index 1344563268..49aeeacf53 100755
 2--- a/ci/test/01_base_install.sh
 3+++ b/ci/test/01_base_install.sh
 4@@ -21,6 +21,9 @@ if [ -n "$DPKG_ADD_ARCH" ]; then
 5   dpkg --add-architecture "$DPKG_ADD_ARCH"
 6 fi
 7 
 8+apt update && apt install ca-certificates -y
 9+echo -e "# Packages and Updates from the Hetzner Ubuntu Mirror\ndeb https://mirror.hetzner.com/ubuntu/packages noble main restricted universe multiverse\ndeb https://mirror.hetzner.com/ubuntu/packages noble-updates main restricted universe multiverse\ndeb https://mirror.hetzner.com/ubuntu/packages noble-backports main restricted universe multiverse\ndeb https://mirror.hetzner.com/ubuntu/packages noble-security main restricted universe multiverse" | tee /etc/apt/sources.list.d/hetzner-mirror.list
10+
11 if [ -n "${APT_LLVM_V}" ]; then
12   ${CI_RETRY_EXE} apt-get update
13   ${CI_RETRY_EXE} apt-get install curl -y
14diff --git a/ci/test/03_test_script.sh b/ci/test/03_test_script.sh
15index 3dd44807c9..ace5413458 100755
16--- a/ci/test/03_test_script.sh
17+++ b/ci/test/03_test_script.sh
18@@ -155,7 +155,7 @@ fi
19 if [ "$RUN_FUNCTIONAL_TESTS" = "true" ]; then
20   # parses TEST_RUNNER_EXTRA as an array which allows for multiple arguments such as TEST_RUNNER_EXTRA='--exclude "rpc_bind.py --ipv6"'
21   eval "TEST_RUNNER_EXTRA=($TEST_RUNNER_EXTRA)"
22-  LD_LIBRARY_PATH="${DEPENDS_DIR}/${HOST}/lib" test/functional/test_runner.py --ci "${MAKEJOBS}" --tmpdirprefix "${BASE_SCRATCH_DIR}"/test_runner/ --ansi --combinedlogslen=99999999 --timeout-factor="${TEST_RUNNER_TIMEOUT_FACTOR}" "${TEST_RUNNER_EXTRA[@]}" --quiet --failfast
23+  LD_LIBRARY_PATH="${DEPENDS_DIR}/${HOST}/lib" test/functional/test_runner.py --ci "${MAKEJOBS}" --tmpdirprefix "${BASE_SCRATCH_DIR}"/test_runner/ --ansi --combinedlogslen=99999999 --timeout-factor="${TEST_RUNNER_TIMEOUT_FACTOR}" "wallet_reorgsrestore.py" --quiet --failfast
24 fi
25 
26 if [ "${RUN_TIDY}" = "true" ]; then

My command:

env -i HOME="$HOME" PATH="$PATH" USER="$USER" RUN_UNIT_TESTS=false CCACHE_DIR=/ccache_dir CCACHE_MAXSIZE=5500M MAKEJOBS="-j$(nproc)" FILE_ENV="./ci/test/00_setup_env_native_valgrind.sh" ./ci/test_run_all.sh

The result:

11f8ab140fe63857f6a93b81021efda8f90ceeda is the first bad commit

0commit 11f8ab140fe63857f6a93b81021efda8f90ceeda
1Date:   Tue Feb 18 19:07:04 2025 -0300
2
3    test: wallet, coverage for crash on dup block disconnection during unclean shutdown
4
5 test/functional/wallet_reorgsrestore.py | 52 +++++++++++++++++++++++++++++++++
6 1 file changed, 52 insertions(+)

maflcko commented at 6:40 pm on May 14, 2025: member

It is a bit confusing, because it passes fine outside of the CI system.
maflcko commented at 10:59 am on May 15, 2025: member

I guess it is the same reason that feature_init.py was disabled in the CI only
furszy commented at 3:21 pm on May 15, 2025: member

We could try expanding the shutdown procedure to ensure the app’s lock can be acquired before returning. This would guarantee that the process can be re-initiated at any time afterward. Thinking of something like: https://github.com/furszy/bitcoin-core/commit/c6c9723f523c74615d784788b51e3365c5bee7c0

If this fails, it would mean the lock file is not being released at all after the process is killed (so far, we only can guess that during Valgrind runs, the lock release process might be taking longer).
fanquake closed this on May 15, 2025
fanquake referenced this in commit bdc1cef1de on May 15, 2025

Contributors
fanquake maflcko furszy

Labels
Tests CI failed