Intermittent issue in p2p_handshake.py", line 75, in run_test self.test_desirable_service_flags(node, [NODE_NETWORK | NODE_WITNESS], not true after 2400.0 seconds #29896

issue maflcko openend this issue on April 16, 2024
  1. maflcko commented at 5:24 pm on April 16, 2024: member

    https://cirrus-ci.com/task/5875023322284032?logs=ci#L3873

     0 test  2024-04-16T12:25:11.924000Z TestFramework.p2p (DEBUG): Received message from 0:0: msg_getheaders(locator=CBlockLocator(vHave=[25904390216175313194312162455780078753009692101200952252992871177711616225820, 10439194800033568075353954394040901046437382900627609508673849620975391395575, 40446225147528968444488730747006358517695899943732003474923480031726915305221, 32881632053604177249247854545860335098773301364214891775874295669143030708145, 8274383136340278425284592751131987282275833971901249227378370713913292132329, 91375339536865810244115815573593171857986770160039248524702050... (msg truncated) 
     1 node0 2024-04-16T12:25:11.927559Z [msghand] [net_processing.cpp:3466] [ProcessMessage] [net] received: pong (8 bytes) peer=10 
     2 test  2024-04-16T12:25:11.969000Z TestFramework.p2p (DEBUG): Send message to 0:0: msg_ping(nonce=00000000) 
     3 test  2024-04-16T12:25:11.970000Z TestFramework.p2p (DEBUG): Received message from 0:0: msg_pong(nonce=00000000) 
     4 node0 2024-04-16T12:25:11.970387Z [msghand] [net_processing.cpp:3466] [ProcessMessage] [net] received: ping (8 bytes) peer=10 
     5 node0 2024-04-16T12:25:11.970505Z [msghand] [net.cpp:3738] [PushMessage] [net] sending pong (8 bytes) peer=10 
     6 test  2024-04-16T12:25:11.972000Z TestFramework.p2p (DEBUG): Send message to 0:0: msg_ping(nonce=00000001) 
     7 node0 2024-04-16T12:25:11.972890Z [msghand] [net_processing.cpp:3466] [ProcessMessage] [net] received: ping (8 bytes) peer=10 
     8 node0 2024-04-16T12:25:11.972948Z [msghand] [net.cpp:3738] [PushMessage] [net] sending pong (8 bytes) peer=10 
     9 test  2024-04-16T12:25:11.973000Z TestFramework.p2p (DEBUG): Received message from 0:0: msg_pong(nonce=00000001) 
    10 test  2024-04-16T12:25:12.022000Z TestFramework.p2p (DEBUG): Send message to 0:0: msg_ping(nonce=00000000) 
    11 test  2024-04-16T12:25:12.023000Z TestFramework.p2p (DEBUG): Send message to 0:0: msg_ping(nonce=00000002) 
    12 node0 2024-04-16T12:25:12.023543Z [msghand] [net_processing.cpp:3466] [ProcessMessage] [net] received: ping (8 bytes) peer=10 
    13 node0 2024-04-16T12:25:12.023611Z [msghand] [net.cpp:3738] [PushMessage] [net] sending pong (8 bytes) peer=10 
    14 node0 2024-04-16T12:25:12.023804Z [msghand] [net_processing.cpp:3466] [ProcessMessage] [net] received: ping (8 bytes) peer=10 
    15 node0 2024-04-16T12:25:12.023846Z [msghand] [net.cpp:3738] [PushMessage] [net] sending pong (8 bytes) peer=10 
    16 test  2024-04-16T12:25:12.024000Z TestFramework.p2p (DEBUG): Received message from 0:0: msg_pong(nonce=00000000) 
    17 test  2024-04-16T12:25:12.024000Z TestFramework.p2p (DEBUG): Received message from 0:0: msg_pong(nonce=00000002) 
    18 test  2024-04-16T12:25:12.081000Z TestFramework.p2p (DEBUG): Closed connection to: 0:0 
    19 test  2024-04-16T12:25:12.081000Z TestFramework (INFO):     - services 0x00000009, type "addr-fetch" [connect] 
    20 test  2024-04-16T12:25:12.081000Z TestFramework.p2p (DEBUG): Listening for Bitcoin Node with id: 1 
    21 test  2024-04-16T12:25:12.081000Z TestFramework.node0 (DEBUG): Connecting to 127.0.0.1:14083 addr-fetch 
    22 node0 2024-04-16T12:25:12.082148Z [http] [httpserver.cpp:306] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:49040 
    23 node0 2024-04-16T12:25:12.082319Z [httpworker.2] [rpc/request.cpp:187] [parse] [rpc] ThreadRPCServer method=addconnection user=__cookie__ 
    24 node0 2024-04-16T12:25:12.084499Z [net] [net.cpp:2113] [SocketHandlerConnected] [net] socket closed for peer=10 
    25 node0 2024-04-16T12:25:12.084538Z [net] [net.cpp:541] [CloseSocketDisconnect] [net] disconnecting peer=10 
    26 node0 2024-04-16T12:25:12.084709Z [net] [net_processing.cpp:1708] [FinalizeNode] [net] Cleared nodestate for peer=10 
    27 node0 2024-04-16T12:25:55.592706Z [scheduler] [net.cpp:2325] [StartExtraBlockRelayPeers] [net] enabling extra block-relay-only peers 
    28 node0 2024-04-16T12:40:10.593105Z [scheduler] [net.cpp:2288] [DumpAddresses] [net] Flushed 0 addresses to peers.dat  1ms 
    29 node0 2024-04-16T12:55:10.594382Z [scheduler] [net.cpp:2288] [DumpAddresses] [net] Flushed 0 addresses to peers.dat  1ms 
    30 test  2024-04-16T13:05:12.094000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: '''' 
    31                                           def test_function():
    32                                               if check_connected:
    33                                                   assert self.is_connected
    34                                               return test_function_in()
    35                                   '''
    36 test  2024-04-16T13:05:12.094000Z TestFramework (ERROR): Assertion failed 
    37                                   Traceback (most recent call last):
    38                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 132, in main
    39                                       self.run_test()
    40                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/p2p_handshake.py", line 75, in run_test
    41                                       self.test_desirable_service_flags(node, [NODE_NETWORK | NODE_WITNESS],
    42                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/p2p_handshake.py", line 63, in test_desirable_service_flags
    43                                       self.add_outbound_connection(node, conn_type, services, wait_for_disconnect=False)
    44                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/p2p_handshake.py", line 35, in add_outbound_connection
    45                                       peer = node.add_outbound_p2p_connection(
    46                                              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    47                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_node.py", line 779, in add_outbound_p2p_connection
    48                                       p2p_conn.wait_for_connect()
    49                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/p2p.py", line 590, in wait_for_connect
    50                                       self.wait_until(test_function, timeout=timeout, check_connected=False)
    51                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/p2p.py", line 586, in wait_until
    52                                       wait_until_helper_internal(test_function, timeout=timeout, lock=p2p_lock, timeout_factor=self.timeout_factor)
    53                                     File "/ci_container_base/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/util.py", line 293, in wait_until_helper_internal
    54                                       raise AssertionError("Predicate {} not true after {} seconds".format(predicate_source, timeout))
    55                                   AssertionError: Predicate ''''
    56                                           def test_function():
    57                                               if check_connected:
    58                                                   assert self.is_connected
    59                                               return test_function_in()
    60                                   ''' not true after 2400.0 seconds
    
  2. maflcko added the label Tests on Apr 16, 2024
  3. maflcko added the label CI failed on Apr 16, 2024
  4. stratospher commented at 7:29 am on April 17, 2024: contributor

    looks like this happens in add_outbound_p2p_connection when disconnection isn’t fully over and we’re trying to establish a connection again on same port since p2p_idx=0. will open a fix soon.

    cc @theStack.

  5. stratospher commented at 8:18 am on April 17, 2024: contributor
    see #29898.
  6. maflcko closed this on Apr 23, 2024


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: 2024-12-21 15:12 UTC

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