-
Notifications
You must be signed in to change notification settings - Fork 37.7k
Closed
Description
I see this consistently when running the native_valgrind
CI:
node0 2025-05-14T10:02:50.888348Z [init] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] Wallet completed loading in 61ms
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
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(?, ?)
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
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
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(?, ?)
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
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
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(?, ?)
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
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
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(?, ?)
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
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
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(?, ?)
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
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
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(?, ?)
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
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
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(?, ?)
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
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
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(?, ?)
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
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'
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'
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'
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'
node0 2025-05-14T10:02:50.903656Z [init] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] setKeyPool.size() = 8
node0 2025-05-14T10:02:50.903793Z [init] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] mapWallet.size() = 1
node0 2025-05-14T10:02:50.903915Z [init] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] m_address_book.size() = 1
node0 2025-05-14T10:02:50.905339Z [init] [init.cpp:1776] [AppInitMain] Setting NODE_NETWORK on non-prune mode
node0 2025-05-14T10:02:50.927907Z [init] [init.cpp:1886] [AppInitMain] block tree size = 228
node0 2025-05-14T10:02:50.928705Z [init] [init.cpp:1899] [AppInitMain] nBestHeight = 216
node0 2025-05-14T10:02:50.944147Z [init] [net.cpp:3168] [BindListenPort] Bound to 127.0.0.1:11000
node0 2025-05-14T10:02:50.949620Z [init] [noui.cpp:57] [noui_InitMessage] init message: Starting network threads…
node0 2025-05-14T10:02:50.967599Z [init] [net.cpp:3358] [Start] DNS seeding disabled
node0 2025-05-14T10:02:51.000689Z [init] [noui.cpp:57] [noui_InitMessage] init message: Done loading
node0 2025-05-14T10:02:51.010548Z [addcon] [util/thread.cpp:20] [TraceThread] addcon thread start
node0 2025-05-14T10:02:51.018558Z [initload] [util/thread.cpp:20] [TraceThread] initload thread start
node0 2025-05-14T10:02:51.025885Z [net] [util/thread.cpp:20] [TraceThread] net thread start
node0 2025-05-14T10:02:51.033665Z [msghand] [util/thread.cpp:20] [TraceThread] msghand thread start
node0 2025-05-14T10:02:51.040718Z [initload] [node/mempool_persist.cpp:73] [LoadMempool] Loading 0 mempool transactions from file...
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
node0 2025-05-14T10:02:51.045906Z [initload] [util/thread.cpp:22] [TraceThread] initload thread exit
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
node0 2025-05-14T10:02:51.050474Z [httpworker.8] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getblockcount user=__cookie__
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
node0 2025-05-14T10:02:51.091232Z [httpworker.4] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getmempoolinfo user=__cookie__
test 2025-05-14T10:02:51.148000Z TestFramework.node0 (DEBUG): RPC successfully started
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
node0 2025-05-14T10:02:51.155482Z [httpworker.9] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getwalletinfo user=__cookie__
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
node0 2025-05-14T10:02:51.189474Z [httpworker.2] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getbestblockhash user=__cookie__
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
node0 2025-05-14T10:02:51.194768Z [httpworker.13] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=invalidateblock user=__cookie__
node0 2025-05-14T10:02:51.231913Z [httpworker.13] [validation.cpp:3052] [DisconnectTip] [bench] - Disconnect block: 18.37ms
node0 2025-05-14T10:02:51.247598Z [httpworker.13] [validation.cpp:2040] [IsInitialBlockDownload] Leaving InitialBlockDownload (latching to false)
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)
node0 2025-05-14T10:02:51.261048Z [httpworker.13] [validationinterface.cpp:235] [BlockDisconnected] [validation] Enqueuing BlockDisconnected: block hash=52ddf4d829b618e6614f6377915b7e20e3848ec6457f61ef997a8b95182dd2a2 block height=216
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
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
node0 2025-05-14T10:02:51.299740Z [httpworker.13] [validationinterface.cpp:187] [ActiveTipChange] [validation] ActiveTipChange: new block hash=5613be1333f0f3305a83b733ffb5aca47778c6d38954ca181e8a271e9a256fcf block height=215
node0 2025-05-14T10:02:51.309128Z [scheduler] [validationinterface.cpp:235] [operator()] [validation] BlockDisconnected: block hash=52ddf4d829b618e6614f6377915b7e20e3848ec6457f61ef997a8b95182dd2a2 block height=216
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
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(?, ?)
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
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(?, ?)
node0 2025-05-14T10:02:51.383478Z [scheduler] [wallet/wallet.h:924] [WalletLogPrintf] [reorg_crash] AddToWallet a206802b6f3fb1bfc0c475cf6fdf1821fa2ffb87cf9223a58c8a62355ee831e4 update Inactive (abandoned=1)
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(?, ?)
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
node0 2025-05-14T10:02:51.392793Z [httpworker.1] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=syncwithvalidationinterfacequeue user=__cookie__
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
node0 2025-05-14T10:02:51.405706Z [httpworker.15] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getwalletinfo user=__cookie__
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
node0 2025-05-14T10:02:51.417299Z [httpworker.10] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getblock user=__cookie__
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
node0 2025-05-14T10:02:51.499049Z [httpworker.12] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=gettransaction user=__cookie__
test 2025-05-14T10:02:51.629000Z TestFramework.node0 (DEBUG): Node stopped
test 2025-05-14T10:02:51.629000Z TestFramework.utils (DEBUG): Deleting leftover cookie file
test 2025-05-14T10:02:51.630000Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up
test 2025-05-14T10:02:55.888000Z TestFramework (ERROR): Unexpected exception caught during testing
Traceback (most recent call last):
File "/ci_container_base/test/functional/test_framework/test_framework.py", line 183, in main
self.run_test()
File "/ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/test/functional/wallet_reorgsrestore.py", line 214, in run_test
self.test_reorg_handling_during_unclean_shutdown()
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
self.start_node(0)
File "/ci_container_base/test/functional/test_framework/test_framework.py", line 583, in start_node
node.wait_for_rpc_connection()
File "/ci_container_base/test/functional/test_framework/test_node.py", line 275, in wait_for_rpc_connection
raise FailedToStartError(self._node_msg(
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.
************************
test 2025-05-14T10:02:55.890000Z TestFramework (DEBUG): Closing down network thread
test 2025-05-14T10:02:55.941000Z TestFramework (INFO): Not stopping nodes as test failed. The dangling processes will be cleaned up later.
test 2025-05-14T10:02:55.941000Z TestFramework (WARNING): Not cleaning up dir /tmp/test_runner_₿_🏃_20250514_100134/wallet_reorgsrestore_0
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
test 2025-05-14T10:02:55.941000Z TestFramework (ERROR):
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
test 2025-05-14T10:02:55.941000Z TestFramework (ERROR):
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.
test 2025-05-14T10:02:55.942000Z TestFramework (ERROR): https://github.com/bitcoin/bitcoin/issues
test 2025-05-14T10:02:55.942000Z TestFramework (ERROR):
node0 2025-05-14T10:03:36.019830Z [scheduler] [net.cpp:2427] [StartExtraBlockRelayPeers] [net] enabling extra block-relay-only peers
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.