Looks like the test may overall intermittently fail, because it assumes the tx delay isn’t exponentially distributed, but has a constant delay, sufficient for the test to pass.
I think it would be better to use mocktime to halt the test when needed, so that it can even pass when the delay is zero (or close to it).
I haven’t looked in detail whether this is the same, but there was one instance in the CI: (Possibly the getdata was split into two, so the check didn’t pick it up, because it assumes it to happen in one msg?)
https://github.com/bitcoin/bitcoin/actions/runs/12885576442/job/35924329366?pr=25832#step:7:15913
0 test 2025-01-21T11:21:24.017000Z TestFramework.p2p (DEBUG): Closed connection to: 127.0.0.1:14372
1 test 2025-01-21T11:21:24.017000Z TestFramework.p2p (DEBUG): Received message from 127.0.0.1:14372: msg_getdata(inv=[CInv(type=WitnessTx hash=16df2774cb507f967e367838f263d09c647bcc7818d5c45d886c0ee5b8f45ac7)])
2 node0 2025-01-21T11:21:24.017006Z (mocktime: 2025-01-27T11:30:06Z) [httpworker.13] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getorphantxs user=__cookie__
3 node0 2025-01-21T11:21:24.017297Z (mocktime: 2025-01-27T11:30:06Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
4 node0 2025-01-21T11:21:24.017316Z (mocktime: 2025-01-27T11:30:06Z) [httpworker.14] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=setmocktime user=__cookie__
5 node0 2025-01-21T11:21:24.017368Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [node/txdownloadman_impl.cpp:276] [GetRequestsToSend] [net] Requesting tx 16df2774cb507f967e367838f263d09c647bcc7818d5c45d886c0ee5b8f45ac7 peer=24
6 node0 2025-01-21T11:21:24.017377Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [net.cpp:3874] [PushMessage] [net] sending getdata (37 bytes) peer=24
7 node0 2025-01-21T11:21:24.017449Z (mocktime: 2025-01-27T11:30:10Z) [net] [net.cpp:2188] [SocketHandlerConnected] [net] socket closed, disconnecting peer=23
8 node0 2025-01-21T11:21:24.017467Z (mocktime: 2025-01-27T11:30:10Z) [net] [net_processing.cpp:1633] [FinalizeNode] [net] Cleared nodestate for peer=23
9 node0 2025-01-21T11:21:24.017701Z (mocktime: 2025-01-27T11:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
10 node0 2025-01-21T11:21:24.017722Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.15] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getorphantxs user=__cookie__
11 node0 2025-01-21T11:21:24.221913Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [node/txdownloadman_impl.cpp:276] [GetRequestsToSend] [net] Requesting tx f2777bc29da8d92e6090c69775a12bc7df96a4da2554d086749f8f854872d133 peer=24
12 node0 2025-01-21T11:21:24.221941Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [net.cpp:3874] [PushMessage] [net] sending getdata (37 bytes) peer=24
13 test 2025-01-21T11:21:24.222000Z TestFramework.p2p (DEBUG): Received message from 127.0.0.1:14372: msg_getdata(inv=[CInv(type=WitnessTx hash=f2777bc29da8d92e6090c69775a12bc7df96a4da2554d086749f8f854872d133)])
14 test 2025-01-21T11:28:04.173000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: ''''
15 def test_function():
16 if check_connected:
17 assert self.is_connected
18 return test_function_in()
19 '''
20 test 2025-01-21T11:28:04.176000Z TestFramework.node0 (DEBUG): TestNode.generate() dispatches `generate` call to `generatetoaddress`
21 node0 2025-01-21T11:28:04.179438Z (mocktime: 2025-01-27T11:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
22 node0 2025-01-21T11:28:04.180169Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=generatetoaddress user=__cookie__
23 node0 2025-01-21T11:28:04.180973Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [node/miner.cpp:161] [CreateNewBlock] CreateNewBlock(): block weight: 1319 txs: 1 fees: 31200 sigops 400
24 node0 2025-01-21T11:28:04.181211Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2527] [ConnectBlock] [bench] - Sanity checks: 0.01ms [0.00s (0.00ms/blk)]
25 node0 2025-01-21T11:28:04.181552Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2629] [ConnectBlock] [bench] - Fork checks: 0.38ms [0.00s (0.01ms/blk)]
26 node0 2025-01-21T11:28:04.181650Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2722] [ConnectBlock] [bench] - Connect 2 transactions: 0.10ms (0.048ms/tx, 0.095ms/txin) [0.00s (0.01ms/blk)]
27 node0 2025-01-21T11:28:04.181716Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2744] [ConnectBlock] [bench] - Verify 1 txins: 0.16ms (0.163ms/txin) [0.01s (0.02ms/blk)]
28 node0 2025-01-21T11:28:04.181756Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [node/miner.cpp:180] [CreateNewBlock] [bench] CreateNewBlock() packages: 0.18ms (1 packages, 0 updated descendants), validity: 0.89ms (total 1.07ms)
29 node0 2025-01-21T11:28:04.181838Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:4428] [AcceptBlockHeader] Saw new header hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662 height=394
30 node0 2025-01-21T11:28:04.182065Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validationinterface.cpp:255] [NewPoWValidBlock] [validation] NewPoWValidBlock: block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662
31 node0 2025-01-21T11:28:04.182999Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:3187] [ConnectTip] [bench] - Using cached block
32 node0 2025-01-21T11:28:04.183046Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:3197] [ConnectTip] [bench] - Load block from disk: 0.03ms
33 node0 2025-01-21T11:28:04.183078Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2527] [ConnectBlock] [bench] - Sanity checks: 0.00ms [0.00s (0.00ms/blk)]
34 node0 2025-01-21T11:28:04.183121Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2629] [ConnectBlock] [bench] - Fork checks: 0.04ms [0.00s (0.01ms/blk)]
35 node0 2025-01-21T11:28:04.183176Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2722] [ConnectBlock] [bench] - Connect 2 transactions: 0.05ms (0.026ms/tx, 0.051ms/txin) [0.00s (0.01ms/blk)]
36 node0 2025-01-21T11:28:04.183210Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2744] [ConnectBlock] [bench] - Verify 1 txins: 0.09ms (0.088ms/txin) [0.01s (0.02ms/blk)]
37 node0 2025-01-21T11:28:04.183460Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2759] [ConnectBlock] [bench] - Write undo data: 0.25ms [0.04s (0.11ms/blk)]
38 node0 2025-01-21T11:28:04.183491Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:2774] [ConnectBlock] [bench] - Index writing: 0.03ms [0.00s (0.01ms/blk)]
39 node0 2025-01-21T11:28:04.183525Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validationinterface.cpp:250] [BlockChecked] [validation] BlockChecked: block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662 state=Valid
40 node0 2025-01-21T11:28:04.183575Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:3216] [ConnectTip] [bench] - Connect total: 0.54ms [0.06s (0.15ms/blk)]
41 node0 2025-01-21T11:28:04.183609Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:3225] [ConnectTip] [bench] - Flush: 0.03ms [0.00s (0.00ms/blk)]
42 node0 2025-01-21T11:28:04.183634Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:3235] [ConnectTip] [bench] - Writing chainstate: 0.02ms [0.00s (0.00ms/blk)]
43 node0 2025-01-21T11:28:04.183680Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [txmempool.cpp:1074] [RemoveUnbroadcastTx] [mempool] Removed ded4025fc122f8892f8e1a3ee818c85275956a77843be62b6989b1c3ff5f2e46 from set of unbroadcast txns before confirmation that txn was sent out
44 node0 2025-01-21T11:28:04.183747Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validationinterface.cpp:227] [MempoolTransactionsRemovedForBlock] [validation] Enqueuing MempoolTransactionsRemovedForBlock: block height=394 txs removed=1
45 node0 2025-01-21T11:28:04.183850Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:3006] [UpdateTipLog] UpdateTip: new best=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662 height=394 version=0x30000000 log2_work=9.625709 tx=612 date='2025-01-27T11:30:10Z' progress=1.000000 cache=0.3MiB(5txo)
46 node0 2025-01-21T11:28:04.183901Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:3251] [ConnectTip] [bench] - Connect postprocess: 0.27ms [0.01s (0.02ms/blk)]
47 node0 2025-01-21T11:28:04.183939Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validation.cpp:3255] [ConnectTip] [bench] - Connect block: 0.90ms [0.07s (0.18ms/blk)]
48 node0 2025-01-21T11:28:04.184008Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [txmempool.cpp:700] [check] [mempool] Checking mempool with 0 transactions and 0 inputs
49 node0 2025-01-21T11:28:04.184059Z (mocktime: 2025-01-27T11:30:10Z) [scheduler] [validationinterface.cpp:227] [operator()] [validation] MempoolTransactionsRemovedForBlock: block height=394 txs removed=1
50 node0 2025-01-21T11:28:04.184177Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validationinterface.cpp:217] [BlockConnected] [validation] Enqueuing BlockConnected: block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662 block height=394
51 node0 2025-01-21T11:28:04.184218Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validationinterface.cpp:182] [UpdatedBlockTip] [validation] Enqueuing UpdatedBlockTip: new block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662 fork block hash=4662d66c50b6a655b6971c547619516417c1b422d0718ee24d30f56502410ca3 (in IBD=false)
52 node0 2025-01-21T11:28:04.184286Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.1] [validationinterface.cpp:187] [ActiveTipChange] [validation] ActiveTipChange: new block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662 block height=394
53 node0 2025-01-21T11:28:04.184454Z (mocktime: 2025-01-27T11:30:10Z) [scheduler] [policy/fees.cpp:711] [processBlock] [estimatefee] Blockpolicy estimates updated by 0 of 1 block txs, since last block 0 of 3 tracked, mempool map size 0, max target 11 from current
54 node0 2025-01-21T11:28:04.184501Z (mocktime: 2025-01-27T11:30:10Z) [scheduler] [validationinterface.cpp:217] [operator()] [validation] BlockConnected: block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662 block height=394
55 node0 2025-01-21T11:28:04.185563Z (mocktime: 2025-01-27T11:30:10Z) [scheduler] [validationinterface.cpp:182] [operator()] [validation] UpdatedBlockTip: new block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662 fork block hash=4662d66c50b6a655b6971c547619516417c1b422d0718ee24d30f56502410ca3 (in IBD=false)
56 node0 2025-01-21T11:28:04.185654Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [net_processing.cpp:5649] [SendMessages] [net] SendMessages: sending inv peer=24 hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662
57 node0 2025-01-21T11:28:04.185696Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [net.cpp:3874] [PushMessage] [net] sending inv (37 bytes) peer=24
58 test 2025-01-21T11:28:04.187000Z TestFramework.p2p (DEBUG): Received message from 127.0.0.1:14372: msg_inv(inv=[CInv(type=Block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662)])
59 test 2025-01-21T11:28:04.187000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:14372: msg_getdata(inv=[CInv(type=Block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662)])
60 node0 2025-01-21T11:28:04.188203Z (mocktime: 2025-01-27T11:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
61 node0 2025-01-21T11:28:04.188325Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.0] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getbestblockhash user=__cookie__
62 node0 2025-01-21T11:28:04.188566Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [net_processing.cpp:3380] [ProcessMessage] [net] received: getdata (37 bytes) peer=24
63 node0 2025-01-21T11:28:04.188622Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [net_processing.cpp:3990] [ProcessMessage] [net] received getdata (1 invsz) peer=24
64 node0 2025-01-21T11:28:04.188660Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [net_processing.cpp:3993] [ProcessMessage] [net] received getdata for: block 077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662 peer=24
65 node0 2025-01-21T11:28:04.188706Z (mocktime: 2025-01-27T11:30:10Z) [msghand] [net.cpp:3874] [PushMessage] [net] sending block (311 bytes) peer=24
66 test 2025-01-21T11:28:04.189000Z TestFramework.p2p (DEBUG): Received message from 127.0.0.1:14372: msg_block(block=CBlock(nVersion=805306368 hashPrevBlock=4662d66c50b6a655b6971c547619516417c1b422d0718ee24d30f56502410ca3 hashMerkleRoot=b7943c8d36e59a4b8f042e99f55b71e9da78debc337f2520ac30ffb98be501ff nTime=Mon Jan 27 11:30:10 2025 nBits=207fffff nNonce=00000003 vtx=[CTransaction(version=2 vin=[CTxIn(prevout=COutPoint(hash=0000000000000000000000000000000000000000000000000000000000000000 n=4294967295) scriptSig=028a0100 nSequence=4294967295)] vout=[CTxOut(nValue=12.50031200 scriptPubKey=76a9142b4... (msg truncated)
67 node0 2025-01-21T11:28:04.189053Z (mocktime: 2025-01-27T11:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
68 node0 2025-01-21T11:28:04.189130Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.3] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getrawmempool user=__cookie__
69 node0 2025-01-21T11:28:04.190512Z (mocktime: 2025-01-27T11:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
70 node0 2025-01-21T11:28:04.190644Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.2] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=syncwithvalidationinterfacequeue user=__cookie__
71 test 2025-01-21T11:28:04.191000Z TestFramework.p2p (DEBUG): Closed connection to: 127.0.0.1:14372
72 node0 2025-01-21T11:28:04.191805Z (mocktime: 2025-01-27T11:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
73 node0 2025-01-21T11:28:04.191893Z (mocktime: 2025-01-27T11:30:10Z) [net] [net.cpp:2188] [SocketHandlerConnected] [net] socket closed, disconnecting peer=24
74 node0 2025-01-21T11:28:04.191978Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.5] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getpeerinfo user=__cookie__
75 node0 2025-01-21T11:28:04.192224Z (mocktime: 2025-01-27T11:30:10Z) [net] [txorphanage.cpp:93] [EraseTx] [txpackages] removed orphan tx 55ae42d3c30e22ed3fd70b24bbeb214e67fca0420f1fdc8a508a88b4e386af94 (wtxid=9477fadf8dc360b951c9facff7a0be4c4cf8a7158368d64c963a4765fb1a957c) after 8s
76 node0 2025-01-21T11:28:04.192252Z (mocktime: 2025-01-27T11:30:10Z) [net] [txorphanage.cpp:120] [EraseForPeer] [txpackages] Erased 1 orphan transaction(s) from peer=24
77 node0 2025-01-21T11:28:04.192263Z (mocktime: 2025-01-27T11:30:10Z) [net] [net_processing.cpp:1633] [FinalizeNode] [net] Cleared nodestate for peer=24
78 node0 2025-01-21T11:28:04.192474Z (mocktime: 2025-01-27T11:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
79 node0 2025-01-21T11:28:04.192514Z (mocktime: 2025-01-27T11:30:10Z) [httpworker.4] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=setmocktime user=__cookie__
80 node0 2025-01-21T11:28:04.192867Z (mocktime: 2025-01-27T23:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
81 node0 2025-01-21T11:28:04.192901Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.6] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getorphantxs user=__cookie__
82 node0 2025-01-21T11:28:04.193191Z (mocktime: 2025-01-27T23:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
83 node0 2025-01-21T11:28:04.193223Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.7] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getrawmempool user=__cookie__
84 node0 2025-01-21T11:28:04.194015Z (mocktime: 2025-01-27T23:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
85 node0 2025-01-21T11:28:04.194065Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=scantxoutset user=__cookie__
86 node0 2025-01-21T11:28:04.194263Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block and undo data to disk started
87 node0 2025-01-21T11:28:04.196980Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block and undo data to disk completed (2.69ms)
88 node0 2025-01-21T11:28:04.197024Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block index to disk started
89 node0 2025-01-21T11:28:04.198904Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write block index to disk completed (1.87ms)
90 node0 2025-01-21T11:28:04.198947Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write coins cache to disk (5 coins, 256KiB) started
91 node0 2025-01-21T11:28:04.198985Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [txdb.cpp:148] [BatchWrite] [coindb] Writing final batch of 0.00 MiB
92 node0 2025-01-21T11:28:04.199390Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [txdb.cpp:150] [BatchWrite] [coindb] Committed 3 changed transaction outputs (out of 3) to coin database...
93 node0 2025-01-21T11:28:04.199415Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [logging/timer.h:58] [Log] [bench] FlushStateToDisk: write coins cache to disk (5 coins, 256KiB) completed (0.46ms)
94 node0 2025-01-21T11:28:04.199431Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.8] [validationinterface.cpp:245] [ChainStateFlushed] [validation] Enqueuing ChainStateFlushed: block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662
95 node0 2025-01-21T11:28:04.199489Z (mocktime: 2025-01-27T23:30:10Z) [scheduler] [validationinterface.cpp:245] [operator()] [validation] ChainStateFlushed: block hash=077bf058147704114b908875b7fbfa54065dfe633c6e904276222f6284c18662
96 node0 2025-01-21T11:28:04.202632Z (mocktime: 2025-01-27T23:30:10Z) [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49580
97 node0 2025-01-21T11:28:04.202704Z (mocktime: 2025-01-27T23:30:10Z) [httpworker.10] [rpc/request.cpp:241] [parse] [rpc] ThreadRPCServer method=getrawmempool user=__cookie__
98 test 2025-01-21T11:28:04.203000Z TestFramework (ERROR): Assertion failed
99 Traceback (most recent call last):
100 File "/Users/runner/work/bitcoin/bitcoin/test/functional/test_framework/test_framework.py", line 135, in main
101 self.run_test()
102 ~~~~~~~~~~~~~^^
103 File "/Users/runner/work/bitcoin/bitcoin/ci/scratch/build-aarch64-apple-darwin23.6.0/test/functional/p2p_orphan_handling.py", line 820, in run_test
104 self.test_parents_change()
105 ~~~~~~~~~~~~~~~~~~~~~~~~^^
106 File "/Users/runner/work/bitcoin/bitcoin/ci/scratch/build-aarch64-apple-darwin23.6.0/test/functional/p2p_orphan_handling.py", line 55, in wrapper
107 func(self)
108 ~~~~^^^^^^
109 File "/Users/runner/work/bitcoin/bitcoin/ci/scratch/build-aarch64-apple-darwin23.6.0/test/functional/p2p_orphan_handling.py", line 791, in test_parents_change
110 peer2.wait_for_parent_requests([int(parent_peekaboo_AB["txid"], 16), int(parent_missing["txid"], 16)])
111 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
112 File "/Users/runner/work/bitcoin/bitcoin/ci/scratch/build-aarch64-apple-darwin23.6.0/test/functional/p2p_orphan_handling.py", line 99, in wait_for_parent_requests
113 self.wait_until(test_function, timeout=10)
114 ~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^
115 File "/Users/runner/work/bitcoin/bitcoin/test/functional/test_framework/p2p.py", line 594, in wait_until
116 wait_until_helper_internal(test_function, timeout=timeout, lock=p2p_lock, timeout_factor=self.timeout_factor, check_interval=check_interval)
117 ~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
118 File "/Users/runner/work/bitcoin/bitcoin/test/functional/test_framework/util.py", line 317, in wait_until_helper_internal
119 raise AssertionError("Predicate {} not true after {} seconds".format(predicate_source, timeout))
120 AssertionError: Predicate ''''
121 def test_function():
122 if check_connected:
123 assert self.is_connected
124 return test_function_in()
125 ''' not true after 400.0 seconds
126 test 2025-01-21T11:28:04.208000Z TestFramework (DEBUG): Closing down network thread
127 test 2025-01-21T11:28:04.307000Z TestFramework (INFO): Stopping nodes
128 test 2025-01-21T11:28:04.308000Z TestFramework.node0 (DEBUG): Stopping node
