test: Fix intermittent failure in p2p_v2_misbehaving.py

The ellswift bytes are computed in the NetworkThread and sent in
the MainThread. Add a `wait_until()` to make sure that ellswift
computation is completed in NetworkThread before sending it in
the MainThread. Also use mocktime for more robust disconnection
checking.

Author: stratospher

test/functional/p2p_v2_misbehaving.py

@@ -4,6 +4,7 @@
 # file COPYING or http://www.opensource.org/licenses/mit-license.php.
 
 import random
+import time
 from enum import Enum
 
 from test_framework.messages import MAGIC_BYTES
@@ -128,6 +129,10 @@ def set_test_params(self):
         self.num_nodes = 1
         self.extra_args = [["-v2transport=1", "-peertimeout=3"]]
 
+    def mock_forward(self, delta):
+        self.mock_time += delta
+        self.nodes[0].setmocktime(self.mock_time)
+
     def run_test(self):
         self.test_earlykeyresponse()
         self.test_v2disconnection()
@@ -136,25 +141,34 @@ def test_earlykeyresponse(self):
         self.log.info('Sending ellswift bytes in parts to ensure that response from responder is received only when')
         self.log.info('ellswift bytes have a mismatch from the 16 bytes(network magic followed by "version\\x00\\x00\\x00\\x00\\x00")')
         node0 = self.nodes[0]
+        self.mock_time = int(time.time())
+        self.mock_forward(0)
         self.log.info('Sending first 4 bytes of ellswift which match network magic')
         self.log.info('If a response is received, assertion failure would happen in our custom data_received() function')
         peer1 = node0.add_p2p_connection(MisbehavingV2Peer(TestType.EARLY_KEY_RESPONSE), wait_for_verack=False, send_version=False, supports_v2_p2p=True, wait_for_v2_handshake=False)
         peer1.send_raw_message(MAGIC_BYTES['regtest'])
         self.log.info('Sending remaining ellswift and garbage which are different from V1_PREFIX. Since a response is')
         self.log.info('expected now, our custom data_received() function wouldn\'t result in assertion failure')
         peer1.v2_state.can_data_be_received = True
+        self.wait_until(lambda: peer1.v2_state.ellswift_ours)
         peer1.send_raw_message(peer1.v2_state.ellswift_ours[4:] + peer1.v2_state.sent_garbage)
+        self.mock_forward(3)
+        # `InactivityCheck()` displays a different net log message compared to the one specified below if `sendSet` isn't populated.
+        #  Make a passing connection so that there's time to populate `sendSet` for consistent logging.
+        peer2 = node0.add_p2p_connection(P2PInterface())
+        assert peer2.is_connected
         with node0.assert_debug_log(['V2 handshake timeout peer=0']):
-            peer1.wait_for_disconnect(timeout=5)
+            self.mock_forward(1)  # `InactivityCheck()` triggers now
+            peer1.wait_for_disconnect(timeout=1)
         self.log.info('successful disconnection since modified ellswift was sent as response')
 
     def test_v2disconnection(self):
         # test v2 disconnection scenarios
         node0 = self.nodes[0]
         expected_debug_message = [
             [],  # EARLY_KEY_RESPONSE
-            ["V2 transport error: missing garbage terminator, peer=1"],  # EXCESS_GARBAGE
-            ["V2 handshake timeout peer=2"],  # WRONG_GARBAGE_TERMINATOR
+            ["V2 transport error: missing garbage terminator, peer=2"],  # EXCESS_GARBAGE
+            ["V2 handshake timeout peer=4"],  # WRONG_GARBAGE_TERMINATOR
             ["V2 transport error: packet decryption failure"],  # WRONG_GARBAGE
             ["V2 transport error: packet decryption failure"],  # SEND_NO_AAD
             [],  # SEND_NON_EMPTY_VERSION_PACKET
@@ -167,8 +181,16 @@ def test_v2disconnection(self):
                 self.log.info(f"No disconnection for {test_type.name}")
             else:
                 with node0.assert_debug_log(expected_debug_message[test_type.value], timeout=5):
-                    peer = node0.add_p2p_connection(MisbehavingV2Peer(test_type), wait_for_verack=False, send_version=False, supports_v2_p2p=True, expect_success=False)
-                    peer.wait_for_disconnect()
+                    self.mock_time = int(time.time())
+                    self.mock_forward(0)
+                    peer1 = node0.add_p2p_connection(MisbehavingV2Peer(test_type), wait_for_verack=False, send_version=False, supports_v2_p2p=True, expect_success=False)
+                    # `InactivityCheck()` displays a different net log message compared to the one specified below if `sendSet` isn't populated.
+                    # Make a passing connection so that there's time to populate `sendSet` for consistent logging
+                    # and for more robust disconnection checking.
+                    peer2 = node0.add_p2p_connection(P2PInterface())
+                    assert peer2.is_connected
+                    self.mock_forward(4)  # `InactivityCheck()` triggers now
+                    peer1.wait_for_disconnect()
                 self.log.info(f"Expected disconnection for {test_type.name}")