ci: intermittent timeout in Windows, msvcrt, test cross-built #35022

issue rkrux openend this issue on April 7, 2026
  1. rkrux commented at 9:30 am on April 7, 2026: contributor

    https://github.com/bitcoin/bitcoin/actions/runs/23957112786/job/69878469247?pr=34963#step:10:258

      0457/457 - wallet_txn_doublespend.py --mineblock failed, Duration: 1203 s
      1
      2stdout:
      32026-04-03T18:40:30.840289Z TestFramework (INFO): PRNG seed is: 5561111221944585162
      4
      52026-04-03T18:40:30.892407Z TestFramework (INFO): Initializing test directory D:\a\bitcoin\bitcoin\test_runner__🏃_20260403_183155\wallet_txn_doublespend_205
      6
      72026-04-03T18:40:33.936290Z TestFramework (INFO): Stopping nodes
      8
      9
     10
     11stderr:
     12Traceback (most recent call last):
     13
     14  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\authproxy.py", line 170, in _get_response
     15
     16    http_response = self.__conn.getresponse()
     17
     18  File "C:\hostedtoolcache\windows\Python\3.14.3\x64\Lib\http\client.py", line 1450, in getresponse
     19
     20    response.begin()
     21
     22    ~~~~~~~~~~~~~~^^
     23
     24  File "C:\hostedtoolcache\windows\Python\3.14.3\x64\Lib\http\client.py", line 336, in begin
     25
     26    version, status, reason = self._read_status()
     27
     28                              ~~~~~~~~~~~~~~~~~^^
     29
     30  File "C:\hostedtoolcache\windows\Python\3.14.3\x64\Lib\http\client.py", line 297, in _read_status
     31
     32    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
     33
     34               ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^
     35
     36  File "C:\hostedtoolcache\windows\Python\3.14.3\x64\Lib\socket.py", line 725, in readinto
     37
     38    return self._sock.recv_into(b)
     39
     40           ~~~~~~~~~~~~~~~~~~~~^^^
     41
     42TimeoutError: timed out
     43
     44
     45
     46During handling of the above exception, another exception occurred:
     47
     48
     49
     50Traceback (most recent call last):
     51
     52  File "D:\a\bitcoin\bitcoin/test/functional/wallet_txn_doublespend.py", line 139, in <module>
     53
     54    TxnMallTest(__file__).main()
     55
     56    ~~~~~~~~~~~~~~~~~~~~~~~~~~^^
     57
     58  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 157, in main
     59
     60    exit_code = self.shutdown()
     61
     62  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 290, in shutdown
     63
     64    self.stop_nodes()
     65
     66    ~~~~~~~~~~~~~~~^^
     67
     68  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 532, in stop_nodes
     69
     70    node.stop_node(wait=wait, wait_until_stopped=False)
     71
     72    ~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
     73
     74  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_node.py", line 460, in stop_node
     75
     76    self.stop(wait=wait)
     77
     78    ~~~~~~~~~^^^^^^^^^^^
     79
     80  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\coverage.py", line 50, in __call__
     81
     82    return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
     83
     84  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\authproxy.py", line 133, in __call__
     85
     86    response, status = self._request('POST', self.__url.path, postdata.encode('utf-8'))
     87
     88                       ~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
     89
     90  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\authproxy.py", line 107, in _request
     91
     92    return self._get_response()
     93
     94           ~~~~~~~~~~~~~~~~~~^^
     95
     96  File "D:\a\bitcoin\bitcoin\test\functional\test_framework\authproxy.py", line 172, in _get_response
     97
     98    raise JSONRPCException({
     99
    100    ...<4 lines>...
    101
    102                                          self.__conn.timeout)})
    103
    104test_framework.authproxy.JSONRPCException: {'code': -344, 'message': "'stop' RPC took longer than 1200.000000 seconds. Consider using larger timeout for calls that take longer to return."} [http_status=None]
    105
    106[node 2] Cleaning up leftover process
    107
    108[node 1] Cleaning up leftover process
    109
    110[node 0] Cleaning up leftover process
    

    Could be related to #34731.

  2. rkrux renamed this:
    ci: intermittent timeout while shutting down node in windows
    ci: intermittent timeout while stopping node in windows
    on Apr 7, 2026
  3. rkrux renamed this:
    ci: intermittent timeout while stopping node in windows
    ci: intermittent timeout in windows
    on Apr 7, 2026
  4. rkrux renamed this:
    ci: intermittent timeout in windows
    ci: intermittent timeout in Windows, msvcrt, test cross-built
    on Apr 7, 2026
  5. maflcko commented at 9:46 am on April 7, 2026: member

    Duplicate of #31894? According to the debug log: (See node1):

     0 node1 2026-04-03T18:40:33.885103Z [http_pool_1] [rpc/request.cpp:240] [parse] [rpc] ThreadRPCServer method=getbalance user=__cookie__ 
     1 test  2026-04-03T18:40:33.885491Z TestFramework (DEBUG): Closing down network thread 
     2 test  2026-04-03T18:40:33.936290Z TestFramework (INFO): Stopping nodes 
     3 test  2026-04-03T18:40:33.936442Z TestFramework.node0 (DEBUG): Stopping node 
     4 node0 2026-04-03T18:40:33.936754Z [http] [httpserver.cpp:232] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:64388 
     5 node0 2026-04-03T18:40:33.936840Z [http_pool_0] [rpc/request.cpp:240] [parse] [rpc] ThreadRPCServer method=stop user=__cookie__ 
     6 node0 2026-04-03T18:40:33.936926Z [init] [httpserver.cpp:448] [InterruptHTTPServer] [http] Interrupting HTTP server 
     7 node0 2026-04-03T18:40:33.936977Z [init] [httprpc.cpp:357] [InterruptHTTPRPC] [rpc] Interrupting HTTP RPC server 
     8 node0 2026-04-03T18:40:33.936996Z [http_pool_0] [util/thread.cpp:21] [TraceThread] http_pool_0 thread exit 
     9 node0 2026-04-03T18:40:33.937046Z [init] [rpc/server.cpp:284] [operator()] [rpc] Interrupting RPC 
    10 node0 2026-04-03T18:40:33.937080Z [http_pool_1] [util/thread.cpp:21] [TraceThread] http_pool_1 thread exit 
    11 node0 2026-04-03T18:40:33.937110Z [init] [init.cpp:293] [Shutdown] Shutdown in progress... 
    12 node0 2026-04-03T18:40:33.937145Z [shutoff] [httprpc.cpp:362] [StopHTTPRPC] [rpc] Stopping HTTP RPC server 
    13 node0 2026-04-03T18:40:33.937183Z [shutoff] [httpserver.cpp:705] [UnregisterHTTPHandler] [http] Unregistering HTTP handler for / (exactmatch 1) 
    14 node0 2026-04-03T18:40:33.937208Z [shutoff] [httpserver.cpp:705] [UnregisterHTTPHandler] [http] Unregistering HTTP handler for /wallet/ (exactmatch 0) 
    15 node0 2026-04-03T18:40:33.937237Z [addcon] [util/thread.cpp:21] [TraceThread] addcon thread exit 
    16 node0 2026-04-03T18:40:33.937292Z [shutoff] [rpc/server.cpp:296] [operator()] [rpc] Stopping RPC 
    17 test  2026-04-03T18:40:33.937302Z TestFramework.node1 (DEBUG): Stopping node 
    18 node1 2026-04-03T18:40:33.937605Z [http] [httpserver.cpp:232] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:64390 
    19 node1 2026-04-03T18:40:33.937677Z [http_pool_0] [rpc/request.cpp:240] [parse] [rpc] ThreadRPCServer method=stop user=__cookie__ 
    20 node1 2026-04-03T18:40:33.937729Z [init] [httpserver.cpp:448] [InterruptHTTPServer] [http] Interrupting HTTP server 
    21 node1 2026-04-03T18:40:33.937747Z [init] [httprpc.cpp:357] [InterruptHTTPRPC] [rpc] Interrupting HTTP RPC server 
    22 node1 2026-04-03T18:40:33.937760Z [http_pool_1] [util/thread.cpp:21] [TraceThread] http_pool_1 thread exit 
    23 node1 2026-04-03T18:40:33.937794Z [init] [rpc/server.cpp:284] [operator()] [rpc] Interrupting RPC 
    24 node1 2026-04-03T18:40:33.937815Z [init] [init.cpp:293] [Shutdown] Shutdown in progress... 
    25 node1 2026-04-03T18:40:33.937826Z [shutoff] [httprpc.cpp:362] [StopHTTPRPC] [rpc] Stopping HTTP RPC server 
    26 node1 2026-04-03T18:40:33.937861Z [shutoff] [httpserver.cpp:705] [UnregisterHTTPHandler] [http] Unregistering HTTP handler for / (exactmatch 1) 
    27 node1 2026-04-03T18:40:33.937878Z [shutoff] [httpserver.cpp:705] [UnregisterHTTPHandler] [http] Unregistering HTTP handler for /wallet/ (exactmatch 0) 
    28 node1 2026-04-03T18:40:33.937915Z [shutoff] [rpc/server.cpp:296] [operator()] [rpc] Stopping RPC 
    29 node0 2026-04-03T18:40:33.937923Z [shutoff] [rpc/server.cpp:298] [operator()] [rpc] RPC stopped. 
    30 node1 2026-04-03T18:40:33.937940Z [addcon] [util/thread.cpp:21] [TraceThread] addcon thread exit 
    31 node1 2026-04-03T18:40:33.937960Z [http_pool_0] [util/thread.cpp:21] [TraceThread] http_pool_0 thread exit 
    32 node1 2026-04-03T18:40:33.938111Z [shutoff] [rpc/server.cpp:298] [operator()] [rpc] RPC stopped. 
    33 node1 2026-04-03T18:40:33.938134Z [shutoff] [httpserver.cpp:459] [StopHTTPServer] [http] Stopping HTTP server 
    34 node1 2026-04-03T18:40:33.938142Z [shutoff] [httpserver.cpp:461] [StopHTTPServer] [http] Waiting for HTTP worker threads to exit 
    35 node1 2026-04-03T18:40:33.938398Z [shutoff] [httpserver.cpp:472] [StopHTTPServer] [http] Waiting for 1 connections to stop HTTP server 
    36 node0 2026-04-03T18:40:33.938626Z [shutoff] [httpserver.cpp:459] [StopHTTPServer] [http] Stopping HTTP server 
    37 node1 2026-04-03T18:40:33.938629Z [http] [httpserver.cpp:305] [ThreadHTTP] [http] Exited http event loop 
    38 node0 2026-04-03T18:40:33.938640Z [shutoff] [httpserver.cpp:461] [StopHTTPServer] [http] Waiting for HTTP worker threads to exit 
    39 node0 2026-04-03T18:40:33.939292Z [http] [httpserver.cpp:305] [ThreadHTTP] [http] Exited http event loop 
    40 node0 2026-04-03T18:40:33.939472Z [shutoff] [httpserver.cpp:486] [StopHTTPServer] [http] Waiting for HTTP event thread to exit 
    41 node0 2026-04-03T18:40:33.939701Z [shutoff] [httpserver.cpp:491] [StopHTTPServer] [http] Stopped HTTP server 
    42 node0 2026-04-03T18:40:33.939895Z [shutoff] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [D:\a\bitcoin\bitcoin\test_runner_₿_🏃_20260403_183155\wallet_txn_doublespend_205\node0\regtest\default_wallet\wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
    43 node0 2026-04-03T18:40:33.939962Z [shutoff] [wallet/sqlite.cpp:55] [TraceSqlCallback] [walletdb:trace] [D:\a\bitcoin\bitcoin\test_runner_₿_🏃_20260403_183155\wallet_txn_doublespend_205\node0\regtest\default_wallet\wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
    44 node0 2026-04-03T18:40:33.944147Z [net] [util/thread.cpp:21] [TraceThread] net thread exit 
    45 node1 2026-04-03T18:40:33.959880Z [net] [util/thread.cpp:21] [TraceThread] net thread exit 
    46 node0 2026-04-03T18:40:33.959915Z [shutoff] [wallet/wallet.h:940] [WalletLogPrintf] [default_wallet] Releasing wallet default_wallet.. 
    47 node1 2026-04-03T18:40:33.991237Z [msghand] [util/thread.cpp:21] [TraceThread] msghand thread exit 
    48 node0 2026-04-03T18:40:34.037980Z [msghand] [util/thread.cpp:21] [TraceThread] msghand thread exit 
    49 node0 2026-04-03T18:40:34.039368Z [shutoff] [net.cpp:2406] [DumpAddresses] [net] Flushed 0 addresses to peers.dat 1ms 
    50 node0 2026-04-03T18:40:34.039388Z [shutoff] [net.cpp:3663] [StopNodes] [net] Stopping node, disconnecting peer=0 
    51 node0 2026-04-03T18:40:34.039396Z [shutoff] [net.cpp:561] [CloseSocketDisconnect] [net] Resetting socket for peer=0 
    52 node0 2026-04-03T18:40:34.039541Z [shutoff] [net_processing.cpp:1749] [FinalizeNode] [net] Cleared nodestate for peer=0 
    53 node0 2026-04-03T18:40:34.039626Z [scheduler] [util/thread.cpp:21] [TraceThread] scheduler thread exit 
    54 node0 2026-04-03T18:40:34.040132Z [shutoff] [node/mempool_persist.cpp:195] [DumpMempool] Writing 0 mempool transactions to file... 
    55 node0 2026-04-03T18:40:34.040148Z [shutoff] [node/mempool_persist.cpp:205] [DumpMempool] Writing 0 unbroadcast transactions to file. 
    56 node0 2026-04-03T18:40:34.040637Z [shutoff] [node/mempool_persist.cpp:221] [DumpMempool] Dumped mempool: 0.000s to copy, 0.001s to dump, 27 bytes dumped to file 
    57 node0 2026-04-03T18:40:34.040656Z [shutoff] [policy/fees/block_policy_estimator.cpp:1075] [FlushUnconfirmed] [estimatefee] Recorded 0 unconfirmed txs from mempool in 0.000s 
    58 node0 2026-04-03T18:40:34.042219Z [shutoff] [policy/fees/block_policy_estimator.cpp:975] [FlushFeeEstimates] [estimatefee] Flushed fee estimates to D:\a\bitcoin\bitcoin\test_runner_₿_🏃_20260403_183155\wallet_txn_doublespend_205\node0\regtest\fee_estimates.dat. 
    59 node0 2026-04-03T18:40:34.042237Z [shutoff] [validation.cpp:2774] [FlushStateToDisk] [coindb] Writing chainstate to disk: flush mode=FORCE_FLUSH, prune=0, large=0, critical=0, periodic=0 
    60 node0 2026-04-03T18:40:34.042280Z [shutoff] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block and undo data to disk started 
    61 node0 2026-04-03T18:40:34.046859Z [shutoff] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block and undo data to disk completed (4.56ms) 
    62 node0 2026-04-03T18:40:34.046876Z [shutoff] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block index to disk started 
    63 node0 2026-04-03T18:40:34.047202Z [shutoff] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block index to disk completed (0.31ms) 
    64 node0 2026-04-03T18:40:34.047261Z [shutoff] [logging/timer.h:58] [Log] [bench] BatchWrite: write coins cache to disk (32 out of 32 cached coins) started 
    65 node0 2026-04-03T18:40:34.047284Z [shutoff] [txdb.cpp:161] [BatchWrite] [coindb] Writing final batch of 0.00 MiB 
    66 node0 2026-04-03T18:40:34.047345Z [shutoff] [txdb.cpp:163] [BatchWrite] [coindb] Committed 32 changed transaction outputs (out of 32) to coin database... 
    67 node0 2026-04-03T18:40:34.047355Z [shutoff] [logging/timer.h:58] [Log] [bench] BatchWrite: write coins cache to disk (32 out of 32 cached coins) completed (0.08ms) 
    68 node0 2026-04-03T18:40:34.047391Z [shutoff] [validationinterface.cpp:262] [ChainStateFlushed] [validation] Enqueuing ChainStateFlushed: block hash=310fed4526b9bf749eb8e90e423c1ad400fa692198d5228887c0698bc095510f 
    69 node0 2026-04-03T18:40:34.047403Z [shutoff] [validationinterface.cpp:262] [operator()] [validation] ChainStateFlushed: block hash=310fed4526b9bf749eb8e90e423c1ad400fa692198d5228887c0698bc095510f 
    70 node0 2026-04-03T18:40:34.047416Z [shutoff] [validation.cpp:2774] [FlushStateToDisk] [coindb] Writing chainstate to disk: flush mode=FORCE_FLUSH, prune=0, large=0, critical=0, periodic=0 
    71 node0 2026-04-03T18:40:34.047449Z [shutoff] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block and undo data to disk started 
    72 node0 2026-04-03T18:40:34.047707Z [shutoff] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block and undo data to disk completed (0.25ms) 
    73 node0 2026-04-03T18:40:34.047721Z [shutoff] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block index to disk started 
    74 node0 2026-04-03T18:40:34.048017Z [shutoff] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block index to disk completed (0.28ms) 
    75 node0 2026-04-03T18:40:34.048060Z [shutoff] [logging/timer.h:58] [Log] [bench] BatchWrite: write coins cache to disk (0 out of 0 cached coins) started 
    76 node0 2026-04-03T18:40:34.048073Z [shutoff] [txdb.cpp:161] [BatchWrite] [coindb] Writing final batch of 0.00 MiB 
    77 node0 2026-04-03T18:40:34.048089Z [shutoff] [txdb.cpp:163] [BatchWrite] [coindb] Committed 0 changed transaction outputs (out of 0) to coin database... 
    78 node0 2026-04-03T18:40:34.048097Z [shutoff] [logging/timer.h:58] [Log] [bench] BatchWrite: write coins cache to disk (0 out of 0 cached coins) completed (0.03ms) 
    79 node0 2026-04-03T18:40:34.048124Z [shutoff] [validationinterface.cpp:262] [ChainStateFlushed] [validation] Enqueuing ChainStateFlushed: block hash=310fed4526b9bf749eb8e90e423c1ad400fa692198d5228887c0698bc095510f 
    80 node0 2026-04-03T18:40:34.049894Z [shutoff] [init.cpp:416] [Shutdown] Shutdown done 
    81 node2 2026-04-03T18:41:16.154577Z [scheduler] [net.cpp:2444] [StartExtraBlockRelayPeers] [net] enabling extra block-relay-only peers 
    82 node1 2026-04-03T18:41:16.154650Z [scheduler] [net.cpp:2444] [StartExtraBlockRelayPeers] [net] enabling extra block-relay-only peers 
    83 node2 2026-04-03T18:42:32.888647Z [msghand] [net.cpp:4083] [PushMessage] [net] sending ping (8 bytes) peer=1 
    84 node2 2026-04-03T18:55:31.155948Z [scheduler] [net.cpp:2406] [DumpAddresses] [net] Flushed 0 addresses to peers.dat 1ms 
    85 node1 2026-04-03T18:55:31.156022Z [scheduler] [net.cpp:2406] [DumpAddresses] [net] Flushed 0 addresses to peers.dat 1ms 
    
  6. rkrux commented at 9:49 am on April 7, 2026: contributor
    Taking a look at the other one.
  7. maflcko added the label CI failed on Apr 7, 2026


rkrux maflcko

Labels
CI failed


github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2026-04-08 00:13 UTC

This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me