search

bitcoin / bitcoin

Bitcoin Core integration/staging tree
https://bitcoincore.org/en/download
MIT License
77.03k stars 35.58k forks source link

Windows Python: Intermittent issue in p2p_unrequested_blocks.py", line 98, in run_test test_node.send_and_ping(msg_block(blocks_h2[0])) assert self.is_connected AssertionError / AcceptBlock FAILED (time-too-old, block's timestamp is too early) #29897

Open maflcko opened 2 months ago

maflcko commented 2 months ago

https://github.com/bitcoin/bitcoin/actions/runs/8689751788/job/23828088498?pr=29877#step:27:584


node0 2024-04-15T13:27:36.008782Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:4743] [ProcessMessage] [net] received block 20076ff9e9d9bace59d7621747b34dfb4af9b2f75ff499017397854f9fefb930 peer=0 
 node0 2024-04-15T13:27:36.008822Z [D:\a\bitcoin\bitcoin\src\validation.cpp:4145] [AcceptBlockHeader] [validation] AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 20076ff9e9d9bace59d7621747b34dfb4af9b2f75ff499017397854f9fefb930, time-too-old, block's timestamp is too early 
 node0 2024-04-15T13:27:36.008857Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:245] [BlockChecked] [validation] BlockChecked: block hash=20076ff9e9d9bace59d7621747b34dfb4af9b2f75ff499017397854f9fefb930 state=time-too-old, block's timestamp is too early 
 node0 2024-04-15T13:27:36.008883Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:1827] [Misbehaving] [net] Misbehaving: peer=0 (0 -> 100) DISCOURAGE THRESHOLD EXCEEDED 
Error: 2024-04-15T13:27:36.008905Z [D:\a\bitcoin\bitcoin\src\validation.cpp:4396] [ProcessNewBlock] [error] ProcessNewBlock: AcceptBlock FAILED (time-too-old, block's timestamp is too early) 
 node0 2024-04-15T13:27:36.008927Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:5067] [MaybeDiscourageAndDisconnect] [net] Warning: disconnecting but not discouraging local peer 0! 
 node0 2024-04-15T13:27:36.009001Z [D:\a\bitcoin\bitcoin\src\net.cpp:541] [CloseSocketDisconnect] [net] disconnecting peer=0 
 node0 2024-04-15T13:27:36.009142Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:1708] [FinalizeNode] [net] Cleared nodestate for peer=0 
 test  2024-04-15T13:27:36.058000Z TestFramework (ERROR): Assertion failed 
                                   Traceback (most recent call last):
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 132, in main
                                       self.run_test()
                                     File "D:\a\bitcoin\bitcoin/test/functional/p2p_unrequested_blocks.py", line 98, in run_test
                                       test_node.send_and_ping(msg_block(blocks_h2[0]))
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\p2p.py", line 686, in send_and_ping
                                       self.sync_with_ping(timeout=timeout)
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\p2p.py", line 699, in sync_with_ping
                                       self.wait_until(test_function, timeout=timeout)
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\p2p.py", line 586, in wait_until
                                       wait_until_helper_internal(test_function, timeout=timeout, lock=p2p_lock, timeout_factor=self.timeout_factor)
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\util.py", line 279, in wait_until_helper_internal
                                       if predicate():
                                          ^^^^^^^^^^^
                                     File "D:\a\bitcoin\bitcoin\test\functional\test_framework\p2p.py", line 583, in test_function
                                       assert self.is_connected
                                   AssertionError
maflcko commented 2 months ago

This is the known bug on Windows Python, where the time.time() returned is just wrong. See https://github.com/bitcoin/bitcoin/issues/25482#issuecomment-1220756898

maflcko commented 2 months ago
CI log excerpt ``` 2024-04-15T13:27:36.5164046Z test 2024-04-15T13:27:35.999000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:11540: msg_block(block=CBlock(nVersion=4 hashPrevBlock=4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe hashMerkleRoot=894d347901f746841d50a120c07cf7ae0dc1d8afed389e63ad1032d8d4dfbcf1 nTime=Mon Apr 15 13:27:36 2024 nBits=207fffff nNonce=00000000 vtx=[CTransaction(nVersion=2 vin=[CTxIn(prevout=COutPoint(hash=0000000000000000000000000000000000000000000000000000000000000000 n=4294967295) scriptSig=5251 nSequence=4294967295)] vout=[CTxOut(nValue=50.00000000 scriptPubKey=51)] wit=CTxWitness(... (msg truncated) 2024-04-15T13:27:36.5169619Z test 2024-04-15T13:27:35.999000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:11540: msg_ping(nonce=00000000) 2024-04-15T13:27:36.5171638Z test 2024-04-15T13:27:35.999000Z TestFramework.p2p (DEBUG): Send message to 127.0.0.1:11540: msg_ping(nonce=00000002) 2024-04-15T13:27:36.5173897Z test 2024-04-15T13:27:35.999000Z TestFramework.p2p (DEBUG): Closed connection to: 127.0.0.1:11540 2024-04-15T13:27:36.5176109Z node1 2024-04-15T13:27:36.000002Z [D:\a\bitcoin\bitcoin\src\httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:62213 2024-04-15T13:27:36.5178719Z node1 2024-04-15T13:27:36.000098Z [D:\a\bitcoin\bitcoin\src\rpc\request.cpp:187] [parse] [rpc] ThreadRPCServer method=getpeerinfo user=__cookie__ 2024-04-15T13:27:36.5181342Z node0 2024-04-15T13:27:36.001243Z [D:\a\bitcoin\bitcoin\src\httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:62212 2024-04-15T13:27:36.5183988Z node0 2024-04-15T13:27:36.001349Z [D:\a\bitcoin\bitcoin\src\rpc\request.cpp:187] [parse] [rpc] ThreadRPCServer method=generatetoaddress user=__cookie__ 2024-04-15T13:27:36.5186739Z node0 2024-04-15T13:27:36.001459Z [D:\a\bitcoin\bitcoin\src\node\miner.cpp:163] [CreateNewBlock] CreateNewBlock(): block weight: 896 txs: 0 fees: 0 sigops 400 2024-04-15T13:27:36.5189379Z node0 2024-04-15T13:27:36.001518Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2337] [ConnectBlock] [bench] - Sanity checks: 0.00ms [0.00s (0.00ms/blk)] 2024-04-15T13:27:36.5191915Z node0 2024-04-15T13:27:36.001555Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2439] [ConnectBlock] [bench] - Fork checks: 0.04ms [0.00s (0.02ms/blk)] 2024-04-15T13:27:36.5194962Z node0 2024-04-15T13:27:36.001585Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2531] [ConnectBlock] [bench] - Connect 1 transactions: 0.03ms (0.026ms/tx, 0.000ms/txin) [0.00s (0.01ms/blk)] 2024-04-15T13:27:36.5198997Z node0 2024-04-15T13:27:36.001614Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2549] [ConnectBlock] [bench] - Verify 0 txins: 0.06ms (0.000ms/txin) [0.00s (0.03ms/blk)] 2024-04-15T13:27:36.5202246Z node0 2024-04-15T13:27:36.001642Z [D:\a\bitcoin\bitcoin\src\node\miner.cpp:182] [CreateNewBlock] [bench] CreateNewBlock() packages: 0.01ms (0 packages, 0 updated descendants), validity: 0.20ms (total 0.21ms) 2024-04-15T13:27:36.5205650Z node0 2024-04-15T13:27:36.001681Z [D:\a\bitcoin\bitcoin\src\validation.cpp:4209] [AcceptBlockHeader] [validation] Saw new header hash=4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe height=1 2024-04-15T13:27:36.5208302Z node0 2024-04-15T13:27:36.002059Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3007] [ConnectTip] [bench] - Using cached block 2024-04-15T13:27:36.5210424Z node0 2024-04-15T13:27:36.002085Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3017] [ConnectTip] [bench] - Load block from disk: 0.02ms 2024-04-15T13:27:36.5212760Z node0 2024-04-15T13:27:36.002114Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2337] [ConnectBlock] [bench] - Sanity checks: 0.00ms [0.00s (0.00ms/blk)] 2024-04-15T13:27:36.5215173Z node0 2024-04-15T13:27:36.002140Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2439] [ConnectBlock] [bench] - Fork checks: 0.03ms [0.00s (0.02ms/blk)] 2024-04-15T13:27:36.5217906Z node0 2024-04-15T13:27:36.002175Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2531] [ConnectBlock] [bench] - Connect 1 transactions: 0.03ms (0.031ms/tx, 0.000ms/txin) [0.00s (0.02ms/blk)] 2024-04-15T13:27:36.5220782Z node0 2024-04-15T13:27:36.002201Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2549] [ConnectBlock] [bench] - Verify 0 txins: 0.06ms (0.000ms/txin) [0.00s (0.04ms/blk)] 2024-04-15T13:27:36.5223646Z node0 2024-04-15T13:27:36.002630Z [D:\a\bitcoin\bitcoin\src\flatfile.cpp:69] [Allocate] [validation] Pre-allocating up to position 0x100000 in rev00000.dat 2024-04-15T13:27:36.5226339Z node0 2024-04-15T13:27:36.003087Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2563] [ConnectBlock] [bench] - Write undo data: 0.88ms [0.00s (0.29ms/blk)] 2024-04-15T13:27:36.5228941Z node0 2024-04-15T13:27:36.003114Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2578] [ConnectBlock] [bench] - Index writing: 0.04ms [0.00s (0.01ms/blk)] 2024-04-15T13:27:36.5232195Z node0 2024-04-15T13:27:36.003137Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:245] [BlockChecked] [validation] BlockChecked: block hash=4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe state=Valid 2024-04-15T13:27:36.5235317Z node0 2024-04-15T13:27:36.003165Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3036] [ConnectTip] [bench] - Connect total: 1.08ms [0.00s (0.39ms/blk)] 2024-04-15T13:27:36.5237787Z node0 2024-04-15T13:27:36.003193Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3045] [ConnectTip] [bench] - Flush: 0.03ms [0.00s (0.02ms/blk)] 2024-04-15T13:27:36.5240185Z node0 2024-04-15T13:27:36.003215Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3055] [ConnectTip] [bench] - Writing chainstate: 0.02ms [0.00s (0.02ms/blk)] 2024-04-15T13:27:36.5243321Z node0 2024-04-15T13:27:36.003235Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:222] [MempoolTransactionsRemovedForBlock] [validation] Enqueuing MempoolTransactionsRemovedForBlock: block height=1 txs removed=0 2024-04-15T13:27:36.5246495Z node0 2024-04-15T13:27:36.003274Z [D:\a\bitcoin\bitcoin\src\validation.cpp:1848] [IsInitialBlockDownload] Leaving InitialBlockDownload (latching to false) 2024-04-15T13:27:36.5265068Z node0 2024-04-15T13:27:36.003315Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:222] [operator ()] [validation] MempoolTransactionsRemovedForBlock: block height=1 txs removed=0 2024-04-15T13:27:36.5269308Z node0 2024-04-15T13:27:36.003371Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2814] [UpdateTipLog] UpdateTip: new best=4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe height=1 version=0x20000000 log2_work=2.000000 tx=2 date='2024-04-15T13:27:36Z' progress=1.000000 cache=0.3MiB(1txo) 2024-04-15T13:27:36.5272872Z node0 2024-04-15T13:27:36.003394Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3071] [ConnectTip] [bench] - Connect postprocess: 0.18ms [0.00s (0.10ms/blk)] 2024-04-15T13:27:36.5275319Z node0 2024-04-15T13:27:36.003416Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3075] [ConnectTip] [bench] - Connect block: 1.33ms [0.00s (0.65ms/blk)] 2024-04-15T13:27:36.5277892Z node0 2024-04-15T13:27:36.003437Z [D:\a\bitcoin\bitcoin\src\txmempool.cpp:663] [check] [mempool] Checking mempool with 0 transactions and 0 inputs 2024-04-15T13:27:36.5281124Z node0 2024-04-15T13:27:36.003467Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:212] [BlockConnected] [validation] Enqueuing BlockConnected: block hash=4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe block height=1 2024-04-15T13:27:36.5285825Z node0 2024-04-15T13:27:36.003486Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:183] [UpdatedBlockTip] [validation] Enqueuing UpdatedBlockTip: new block hash=4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe fork block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 (in IBD=false) 2024-04-15T13:27:36.5290353Z node0 2024-04-15T13:27:36.003555Z [D:\a\bitcoin\bitcoin\src\policy\fees.cpp:708] [processBlock] [estimatefee] Blockpolicy estimates updated by 0 of 0 block txs, since last block 0 of 0 tracked, mempool map size 0, max target 0 from current 2024-04-15T13:27:36.5294146Z node0 2024-04-15T13:27:36.003588Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:212] [operator ()] [validation] BlockConnected: block hash=4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe block height=1 2024-04-15T13:27:36.5298558Z node0 2024-04-15T13:27:36.003680Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:183] [operator ()] [validation] UpdatedBlockTip: new block hash=4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe fork block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 (in IBD=false) 2024-04-15T13:27:36.5302779Z node0 2024-04-15T13:27:36.003750Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:5781] [SendMessages] [net] SendMessages: sending inv peer=0 hash=4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe 2024-04-15T13:27:36.5305508Z node0 2024-04-15T13:27:36.003776Z [D:\a\bitcoin\bitcoin\src\net.cpp:3738] [PushMessage] [net] sending inv (37 bytes) peer=0 2024-04-15T13:27:36.5307633Z node0 2024-04-15T13:27:36.003862Z [D:\a\bitcoin\bitcoin\src\net.cpp:3738] [PushMessage] [net] sending feefilter (8 bytes) peer=0 2024-04-15T13:27:36.5310103Z node1 2024-04-15T13:27:36.004562Z [D:\a\bitcoin\bitcoin\src\httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:62213 2024-04-15T13:27:36.5312690Z node1 2024-04-15T13:27:36.004621Z [D:\a\bitcoin\bitcoin\src\rpc\request.cpp:187] [parse] [rpc] ThreadRPCServer method=generatetoaddress user=__cookie__ 2024-04-15T13:27:36.5315307Z node1 2024-04-15T13:27:36.004717Z [D:\a\bitcoin\bitcoin\src\node\miner.cpp:163] [CreateNewBlock] CreateNewBlock(): block weight: 896 txs: 0 fees: 0 sigops 400 2024-04-15T13:27:36.5317865Z node1 2024-04-15T13:27:36.004782Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2337] [ConnectBlock] [bench] - Sanity checks: 0.00ms [0.00s (0.00ms/blk)] 2024-04-15T13:27:36.5320353Z node1 2024-04-15T13:27:36.004818Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2439] [ConnectBlock] [bench] - Fork checks: 0.04ms [0.00s (0.02ms/blk)] 2024-04-15T13:27:36.5323095Z node1 2024-04-15T13:27:36.004846Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2531] [ConnectBlock] [bench] - Connect 1 transactions: 0.02ms (0.025ms/tx, 0.000ms/txin) [0.00s (0.01ms/blk)] 2024-04-15T13:27:36.5326568Z node1 2024-04-15T13:27:36.004873Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2549] [ConnectBlock] [bench] - Verify 0 txins: 0.05ms (0.000ms/txin) [0.00s (0.03ms/blk)] 2024-04-15T13:27:36.5329617Z node1 2024-04-15T13:27:36.004899Z [D:\a\bitcoin\bitcoin\src\node\miner.cpp:182] [CreateNewBlock] [bench] CreateNewBlock() packages: 0.00ms (0 packages, 0 updated descendants), validity: 0.20ms (total 0.20ms) 2024-04-15T13:27:36.5332978Z node1 2024-04-15T13:27:36.004933Z [D:\a\bitcoin\bitcoin\src\validation.cpp:4209] [AcceptBlockHeader] [validation] Saw new header hash=54271631f3855807857233b5bad9426412e0c36048efc247375ee75bac099869 height=1 2024-04-15T13:27:36.5361811Z node0 2024-04-15T13:27:36.005013Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:3466] [ProcessMessage] [net] received: getdata (37 bytes) peer=0 2024-04-15T13:27:36.5364132Z node0 2024-04-15T13:27:36.005043Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:4068] [ProcessMessage] [net] received getdata (1 invsz) peer=0 2024-04-15T13:27:36.5366951Z node0 2024-04-15T13:27:36.005067Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:4071] [ProcessMessage] [net] received getdata for: block 4ea0ebae5e05d36fd76d9e8b74df5858d92619c07e759207b4599172704a26fe peer=0 2024-04-15T13:27:36.5369531Z node1 2024-04-15T13:27:36.005308Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3007] [ConnectTip] [bench] - Using cached block 2024-04-15T13:27:36.5371576Z node1 2024-04-15T13:27:36.005335Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3017] [ConnectTip] [bench] - Load block from disk: 0.03ms 2024-04-15T13:27:36.5373824Z node1 2024-04-15T13:27:36.005364Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2337] [ConnectBlock] [bench] - Sanity checks: 0.00ms [0.00s (0.00ms/blk)] 2024-04-15T13:27:36.5376114Z node1 2024-04-15T13:27:36.005395Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2439] [ConnectBlock] [bench] - Fork checks: 0.03ms [0.00s (0.02ms/blk)] 2024-04-15T13:27:36.5378678Z node1 2024-04-15T13:27:36.005423Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2531] [ConnectBlock] [bench] - Connect 1 transactions: 0.02ms (0.024ms/tx, 0.000ms/txin) [0.00s (0.02ms/blk)] 2024-04-15T13:27:36.5381337Z node1 2024-04-15T13:27:36.005449Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2549] [ConnectBlock] [bench] - Verify 0 txins: 0.05ms (0.000ms/txin) [0.00s (0.03ms/blk)] 2024-04-15T13:27:36.5383577Z node0 2024-04-15T13:27:36.005457Z [D:\a\bitcoin\bitcoin\src\net.cpp:3738] [PushMessage] [net] sending block (215 bytes) peer=0 2024-04-15T13:27:36.5385801Z node1 2024-04-15T13:27:36.005844Z [D:\a\bitcoin\bitcoin\src\flatfile.cpp:69] [Allocate] [validation] Pre-allocating up to position 0x100000 in rev00000.dat 2024-04-15T13:27:36.5388175Z node1 2024-04-15T13:27:36.006249Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2563] [ConnectBlock] [bench] - Write undo data: 0.79ms [0.00s (0.26ms/blk)] 2024-04-15T13:27:36.5390504Z node1 2024-04-15T13:27:36.006276Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2578] [ConnectBlock] [bench] - Index writing: 0.04ms [0.00s (0.01ms/blk)] 2024-04-15T13:27:36.5393397Z node1 2024-04-15T13:27:36.006299Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:245] [BlockChecked] [validation] BlockChecked: block hash=54271631f3855807857233b5bad9426412e0c36048efc247375ee75bac099869 state=Valid 2024-04-15T13:27:36.5396259Z node1 2024-04-15T13:27:36.006325Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3036] [ConnectTip] [bench] - Connect total: 0.99ms [0.00s (0.36ms/blk)] 2024-04-15T13:27:36.5398466Z node1 2024-04-15T13:27:36.006354Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3045] [ConnectTip] [bench] - Flush: 0.03ms [0.00s (0.02ms/blk)] 2024-04-15T13:27:36.5400709Z node1 2024-04-15T13:27:36.006375Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3055] [ConnectTip] [bench] - Writing chainstate: 0.02ms [0.00s (0.01ms/blk)] 2024-04-15T13:27:36.5403644Z node1 2024-04-15T13:27:36.006393Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:222] [MempoolTransactionsRemovedForBlock] [validation] Enqueuing MempoolTransactionsRemovedForBlock: block height=1 txs removed=0 2024-04-15T13:27:36.5407804Z node1 2024-04-15T13:27:36.006448Z [D:\a\bitcoin\bitcoin\src\validation.cpp:2814] [UpdateTipLog] UpdateTip: new best=54271631f3855807857233b5bad9426412e0c36048efc247375ee75bac099869 height=1 version=0x20000000 log2_work=2.000000 tx=2 date='2024-04-15T13:27:36Z' progress=1.000000 cache=0.3MiB(1txo) 2024-04-15T13:27:36.5411152Z node1 2024-04-15T13:27:36.006480Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3071] [ConnectTip] [bench] - Connect postprocess: 0.10ms [0.00s (0.08ms/blk)] 2024-04-15T13:27:36.5413544Z node1 2024-04-15T13:27:36.006510Z [D:\a\bitcoin\bitcoin\src\validation.cpp:3075] [ConnectTip] [bench] - Connect block: 1.17ms [0.00s (0.59ms/blk)] 2024-04-15T13:27:36.5415809Z node1 2024-04-15T13:27:36.006538Z [D:\a\bitcoin\bitcoin\src\txmempool.cpp:663] [check] [mempool] Checking mempool with 0 transactions and 0 inputs 2024-04-15T13:27:36.5418419Z node1 2024-04-15T13:27:36.006574Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:222] [operator ()] [validation] MempoolTransactionsRemovedForBlock: block height=1 txs removed=0 2024-04-15T13:27:36.5421716Z node1 2024-04-15T13:27:36.006630Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:212] [BlockConnected] [validation] Enqueuing BlockConnected: block hash=54271631f3855807857233b5bad9426412e0c36048efc247375ee75bac099869 block height=1 2024-04-15T13:27:36.5426115Z node1 2024-04-15T13:27:36.006651Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:183] [UpdatedBlockTip] [validation] Enqueuing UpdatedBlockTip: new block hash=54271631f3855807857233b5bad9426412e0c36048efc247375ee75bac099869 fork block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 (in IBD=true) 2024-04-15T13:27:36.5430407Z node1 2024-04-15T13:27:36.006789Z [D:\a\bitcoin\bitcoin\src\policy\fees.cpp:708] [processBlock] [estimatefee] Blockpolicy estimates updated by 0 of 0 block txs, since last block 0 of 0 tracked, mempool map size 0, max target 0 from current 2024-04-15T13:27:36.5433973Z node1 2024-04-15T13:27:36.006819Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:212] [operator ()] [validation] BlockConnected: block hash=54271631f3855807857233b5bad9426412e0c36048efc247375ee75bac099869 block height=1 2024-04-15T13:27:36.5438131Z node1 2024-04-15T13:27:36.006859Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:183] [operator ()] [validation] UpdatedBlockTip: new block hash=54271631f3855807857233b5bad9426412e0c36048efc247375ee75bac099869 fork block hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 (in IBD=true) 2024-04-15T13:27:36.5441600Z node0 2024-04-15T13:27:36.007167Z [D:\a\bitcoin\bitcoin\src\httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:62212 2024-04-15T13:27:36.5443987Z node0 2024-04-15T13:27:36.007253Z [D:\a\bitcoin\bitcoin\src\rpc\request.cpp:187] [parse] [rpc] ThreadRPCServer method=getbestblockhash user=__cookie__ 2024-04-15T13:27:36.5446369Z node1 2024-04-15T13:27:36.007709Z [D:\a\bitcoin\bitcoin\src\httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:62213 2024-04-15T13:27:36.5448723Z node1 2024-04-15T13:27:36.007795Z [D:\a\bitcoin\bitcoin\src\rpc\request.cpp:187] [parse] [rpc] ThreadRPCServer method=getbestblockhash user=__cookie__ 2024-04-15T13:27:36.5451008Z node0 2024-04-15T13:27:36.008740Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:3466] [ProcessMessage] [net] received: block (144 bytes) peer=0 2024-04-15T13:27:36.5453673Z node0 2024-04-15T13:27:36.008782Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:4743] [ProcessMessage] [net] received block 20076ff9e9d9bace59d7621747b34dfb4af9b2f75ff499017397854f9fefb930 peer=0 2024-04-15T13:27:36.5457601Z node0 2024-04-15T13:27:36.008822Z [D:\a\bitcoin\bitcoin\src\validation.cpp:4145] [AcceptBlockHeader] [validation] AcceptBlockHeader: Consensus::ContextualCheckBlockHeader: 20076ff9e9d9bace59d7621747b34dfb4af9b2f75ff499017397854f9fefb930, time-too-old, block's timestamp is too early 2024-04-15T13:27:36.5461964Z node0 2024-04-15T13:27:36.008857Z [D:\a\bitcoin\bitcoin\src\validationinterface.cpp:245] [BlockChecked] [validation] BlockChecked: block hash=20076ff9e9d9bace59d7621747b34dfb4af9b2f75ff499017397854f9fefb930 state=time-too-old, block's timestamp is too early 2024-04-15T13:27:36.5465216Z node0 2024-04-15T13:27:36.008883Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:1827] [Misbehaving] [net] Misbehaving: peer=0 (0 -> 100) DISCOURAGE THRESHOLD EXCEEDED 2024-04-15T13:27:36.5467987Z node0 2024-04-15T13:27:36.008905Z [D:\a\bitcoin\bitcoin\src\validation.cpp:4396] [ProcessNewBlock] [error] ProcessNewBlock: AcceptBlock FAILED (time-too-old, block's timestamp is too early) 2024-04-15T13:27:36.5470987Z node0 2024-04-15T13:27:36.008927Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:5067] [MaybeDiscourageAndDisconnect] [net] Warning: disconnecting but not discouraging local peer 0! 2024-04-15T13:27:36.5473396Z node0 2024-04-15T13:27:36.009001Z [D:\a\bitcoin\bitcoin\src\net.cpp:541] [CloseSocketDisconnect] [net] disconnecting peer=0 2024-04-15T13:27:36.5475463Z node0 2024-04-15T13:27:36.009142Z [D:\a\bitcoin\bitcoin\src\net_processing.cpp:1708] [FinalizeNode] [net] Cleared nodestate for peer=0 2024-04-15T13:27:36.5477076Z test 2024-04-15T13:27:36.058000Z TestFramework (ERROR): Assertion failed 2024-04-15T13:27:36.5477994Z Traceback (most recent call last): 2024-04-15T13:27:36.5479135Z File "D:\a\bitcoin\bitcoin\test\functional\test_framework\test_framework.py", line 132, in main 2024-04-15T13:27:36.5480198Z self.run_test() 2024-04-15T13:27:36.5481267Z File "D:\a\bitcoin\bitcoin/test/functional/p2p_unrequested_blocks.py", line 98, in run_test 2024-04-15T13:27:36.5482409Z test_node.send_and_ping(msg_block(blocks_h2[0])) 2024-04-15T13:27:36.5483587Z File "D:\a\bitcoin\bitcoin\test\functional\test_framework\p2p.py", line 686, in send_and_ping 2024-04-15T13:27:36.5484691Z self.sync_with_ping(timeout=timeout) 2024-04-15T13:27:36.5485820Z File "D:\a\bitcoin\bitcoin\test\functional\test_framework\p2p.py", line 699, in sync_with_ping 2024-04-15T13:27:36.5486976Z self.wait_until(test_function, timeout=timeout) 2024-04-15T13:27:36.5488111Z File "D:\a\bitcoin\bitcoin\test\functional\test_framework\p2p.py", line 586, in wait_until 2024-04-15T13:27:36.5489656Z wait_until_helper_internal(test_function, timeout=timeout, lock=p2p_lock, timeout_factor=self.timeout_factor) 2024-04-15T13:27:36.5491322Z File "D:\a\bitcoin\bitcoin\test\functional\test_framework\util.py", line 279, in wait_until_helper_internal 2024-04-15T13:27:36.5492484Z if predicate(): 2024-04-15T13:27:36.5493107Z ^^^^^^^^^^^ 2024-04-15T13:27:36.5494155Z File "D:\a\bitcoin\bitcoin\test\functional\test_framework\p2p.py", line 583, in test_function 2024-04-15T13:27:36.5495272Z assert self.is_connected 2024-04-15T13:27:36.5495931Z AssertionError ```