Merge #6708: backport: Merge bitcoin#30252: test: Remove redundant verack check

PastaPastaPasta · PastaPastaPasta · commit 09aa42ef0f20 · 2025-06-03T16:15:59.000-05:00
1163aec Merge bitcoin#30252: test: Remove redundant verack check (merge-script) Pull request description: ## Issue being fixed or feature implemented Functional test p2p_node_network_limited.py is occasionally fails with error while waiting `pong` message: 2025-06-03T08:29:40.701000Z TestFramework (INFO): Mine enough blocks to reach the NODE_NETWORK_LIMITED range. 2025-06-03T08:30:40.761000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: '''' self.wait_until(lambda: check_bytesrecv(find_conn(to_connection, from_connection_subver, inbound=True), 'pong', 29), sleep=0.05) ''' 2025-06-03T08:30:40.762000Z TestFramework (ERROR): Assertion failed Traceback (most recent call last): File "DASH/test/functional/test_framework/test_framework.py", line 162, in main self.run_test() File "DASH/test/functional/p2p_node_network_limited.py", line 69, in run_test self.connect_nodes(0, 1) File "DASH/test/functional/test_framework/test_framework.py", line 736, in connect_nodes File "DASH/test/functional/test_framework/test_framework.py", line 903, in wait_until # Private helper methods. These should not be accessed by the subclass test scripts. ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "DASH/test/functional/test_framework/util.py", line 287, in wait_until_helper raise AssertionError("Predicate {} not true after {} seconds".format(predicate_source, timeout)) AssertionError: Predicate '''' self.wait_until(lambda: check_bytesrecv(find_conn(to_connection, from_connection_subver, inbound=True), 'pong', 29), sleep=0.05) ''' not true after 60.0 seconds ot it fails while just waiting connection: 2025-06-03T08:42:35.518000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: '''' self.wait_until(lambda: find_conn(from_connection, to_connection_subver, inbound=False) is not None) ''' 2025-06-03T08:42:35.518000Z TestFramework (ERROR): Assertion failed Traceback (most recent call last): File "DASH/test/functional/test_framework/test_framework.py", line 162, in main self.run_test() File "DASH/test/functional/p2p_node_network_limited.py", line 83, in run_test self.connect_nodes(0, 2) File "DASH/test/functional/test_framework/test_framework.py", line 726, in connect_nodes self.wait_until(lambda: find_conn(from_connection, to_connection_subver, inbound=False) is not None) File "DASH/test/functional/test_framework/test_framework.py", line 905, in wait_until return wait_until_helper(test_function, timeout=timeout, lock=lock, timeout_factor=self.options.timeout_factor, sleep=sleep, do_assert=do_assert) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "DASH/test/functional/test_framework/util.py", line 287, in wait_until_helper raise AssertionError("Predicate {} not true after {} seconds".format(predicate_source, timeout)) AssertionError: Predicate '''' self.wait_until(lambda: find_conn(from_connection, to_connection_subver, inbound=False) is not None) ''' not true after 60.0 seconds This failure happens, because node 2, once connected to node 0: - requests headers - receive headers - sync headers - request blocks - got disconnected Timeline is here (some lines are omitted) ``` node2 2025-06-03T07:28:25.210493Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: version (148 bytes) peer=0 node2 2025-06-03T07:28:25.211692Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: sendaddrv2 (0 bytes) peer=0 node2 2025-06-03T07:28:25.211715Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: verack (0 bytes) peer=0 node2 2025-06-03T07:28:25.211868Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: getaddr (0 bytes) peer=0 node2 2025-06-03T07:28:25.211966Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: sendheaders2 (0 bytes) peer=0 node2 2025-06-03T07:28:25.211989Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: sendcmpct (9 bytes) peer=0 node2 2025-06-03T07:28:25.212007Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: senddsq (1 bytes) peer=0 node2 2025-06-03T07:28:25.212026Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: ping (8 bytes) peer=0 node2 2025-06-03T07:28:25.212063Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: getheaders2 (677 bytes) peer=0 node2 2025-06-03T07:28:25.221532Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: pong (8 bytes) peer=0 node2 2025-06-03T07:28:25.221574Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: headers2 (11441 bytes) peer=0 ... node2 2025-06-03T07:28:25.432813Z (mocktime: 1417713337) [ msghand] [validationinterface.cpp:270] [NotifyHeaderTip] [validation] NotifyHeaderTip: accepted block header hash=585e13971c392a7042a9ad56355a2e3912329ffa95c7d42cdf69929b9424248d initial=0 node2 2025-06-03T07:28:25.432853Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3032] [HeadersDirectFetchBlocks] [net] Large reorg, won't direct fetch to 585e13971c392a7042a9ad56355a2e3912329ffa95c7d42cdf69929b9424248d (292) node2 2025-06-03T07:28:25.432894Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:6283] [SendMessages] [net] Requesting block 3de6b559afe72b8d41caaa6789031825de056b175a607b5facac4357c696bff2 (1) peer=0 node0 2025-06-03T07:28:25.447535Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:3518] [ProcessMessage] [net] received: getdata (577 bytes) peer=2 node0 2025-06-03T07:28:25.447556Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:4194] [ProcessMessage] [net] received getdata (16 invsz) peer=2 node0 2025-06-03T07:28:25.447574Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:4197] [ProcessMessage] [net] received getdata for: block 3de6b559afe72b8d41caaa6789031825de056b175a607b5facac4357c696bff2 peer=2 node0 2025-06-03T07:28:25.447600Z (mocktime: 1417713337) [ msghand] [net_processing.cpp:2568] [ProcessGetBlockData] [net] Ignore block request below NODE_NETWORK_LIMITED threshold, disconnect peer=2 ``` All of that happen while `connect_nodes` in python code still validates if nodes already connected and it that would be eventually faster that python code moves to blocks syncing, the test will fail. ## What was done? This PR helps `connect_nodes` to work faster to increase chance to complete before nodes will be disconnected. The race is still here but it happens less often. - backport bitcoin#30252 See also https://github.com/dashpay/dash/pull/6631/files which has further improvements for `connect_nodes` by reducing default sleeps from 0.5 to 0.05 ## How Has This Been Tested? This PR should increase reliability of other functional tests as well, because it's not the only test that I have seen failed on connect_nodes; but p2p_node_network_limited.py only one that I tested. To reproduce this issue I run stress benchmark that occupy all cores on my machine and after that run p2p_node_network_limited.py in 40 jobs. This PR decreased amount of failures from 25% error rate to just 10%. ## Breaking Changes N/A ## Checklist: - [x] I have performed a self-review of my own code - [ ] I have commented my code, particularly in hard-to-understand areas - [ ] I have added or updated relevant unit/integration/functional/e2e tests - [ ] I have made corresponding changes to the documentation - [x] I have assigned this pull request to a milestone ACKs for top commit: UdjinM6: utACK 1163aec PastaPastaPasta: utACK 1163aec Tree-SHA512: 3f38ab8b0786468048f12c44b2014bfacf4908f55965c3ef554fc7304043d057603feb99c2ad6f9919da24da7ab40d8480467f6fcfd317aff3072236145d71f2
diff --git a/test/functional/test_framework/test_framework.py b/test/functional/test_framework/test_framework.py
@@ -1,5 +1,5 @@
 #!/usr/bin/env python3
-# Copyright (c) 2014-2020 The Bitcoin Core developers
+# Copyright (c) 2014-present The Bitcoin Core developers
 # Copyright (c) 2014-2025 The Dash Core developers
 # Distributed under the MIT software license, see the accompanying
 # file COPYING or http://www.opensource.org/licenses/mit-license.php.
@@ -718,23 +718,19 @@ def connect_nodes(self, a, b, *, peer_advertises_v2=None):
         def find_conn(node, peer_subversion, inbound):
             return next(filter(lambda peer: peer['subver'] == peer_subversion and peer['inbound'] == inbound, node.getpeerinfo()), None)
 
-        # poll until version handshake complete to avoid race conditions
-        # with transaction relaying
-        # See comments in net_processing:
-        # * Must have a version message before anything else
-        # * Must have a verack message before anything else
         self.wait_until(lambda: find_conn(from_connection, to_connection_subver, inbound=False) is not None)
         self.wait_until(lambda: find_conn(to_connection, from_connection_subver, inbound=True) is not None)
 
         def check_bytesrecv(peer, msg_type, min_bytes_recv):
             assert peer is not None, "Error: peer disconnected"
             return peer['bytesrecv_per_msg'].pop(msg_type, 0) >= min_bytes_recv
 
-        self.wait_until(lambda: check_bytesrecv(find_conn(from_connection, to_connection_subver, inbound=False), 'verack', 21))
-        self.wait_until(lambda: check_bytesrecv(find_conn(to_connection, from_connection_subver, inbound=True), 'verack', 21))
-
-        # The message bytes are counted before processing the message, so make
-        # sure it was fully processed by waiting for a ping.
+        # Poll until version handshake (fSuccessfullyConnected) is complete to
+        # avoid race conditions, because some message types are blocked from
+        # being sent or received before fSuccessfullyConnected.
+        #
+        # As the flag fSuccessfullyConnected is not exposed, check it by
+        # waiting for a pong, which can only happen after the flag was set.
         self.wait_until(lambda: check_bytesrecv(find_conn(from_connection, to_connection_subver, inbound=False), 'pong', 29))
         self.wait_until(lambda: check_bytesrecv(find_conn(to_connection, from_connection_subver, inbound=True), 'pong', 29))
 
