Skip to content

Commit 5a6bb24

Browse files
committed
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.
1 parent 9adebe1 commit 5a6bb24

File tree

1 file changed

+23
-5
lines changed

1 file changed

+23
-5
lines changed

test/functional/p2p_v2_misbehaving.py

+23-5
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
# file COPYING or http://www.opensource.org/licenses/mit-license.php.
55

66
import random
7+
import time
78
from enum import Enum
89

910
from test_framework.messages import MAGIC_BYTES
@@ -136,25 +137,34 @@ def test_earlykeyresponse(self):
136137
self.log.info('Sending ellswift bytes in parts to ensure that response from responder is received only when')
137138
self.log.info('ellswift bytes have a mismatch from the 16 bytes(network magic followed by "version\\x00\\x00\\x00\\x00\\x00")')
138139
node0 = self.nodes[0]
140+
node0.setmocktime(int(time.time()))
139141
self.log.info('Sending first 4 bytes of ellswift which match network magic')
140142
self.log.info('If a response is received, assertion failure would happen in our custom data_received() function')
141143
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)
142144
peer1.send_raw_message(MAGIC_BYTES['regtest'])
143145
self.log.info('Sending remaining ellswift and garbage which are different from V1_PREFIX. Since a response is')
144146
self.log.info('expected now, our custom data_received() function wouldn\'t result in assertion failure')
145147
peer1.v2_state.can_data_be_received = True
148+
self.wait_until(lambda: peer1.v2_state.ellswift_ours)
146149
peer1.send_raw_message(peer1.v2_state.ellswift_ours[4:] + peer1.v2_state.sent_garbage)
150+
node0.bumpmocktime(3)
151+
# `InactivityCheck()` displays a different net log message "socket no message in first %i seconds"
152+
# instead of the expected net log message if `sendSet` isn't set by this point of time.
153+
# Make a passing connection so that `sendSet` gets time to be set for consistent logging
154+
peer2 = node0.add_p2p_connection(P2PInterface())
155+
assert peer2.is_connected
147156
with node0.assert_debug_log(['V2 handshake timeout peer=0']):
148-
peer1.wait_for_disconnect(timeout=5)
157+
node0.bumpmocktime(1) # `InactivityCheck()` triggers now
158+
peer1.wait_for_disconnect(timeout=1)
149159
self.log.info('successful disconnection since modified ellswift was sent as response')
150160

151161
def test_v2disconnection(self):
152162
# test v2 disconnection scenarios
153163
node0 = self.nodes[0]
154164
expected_debug_message = [
155165
[], # EARLY_KEY_RESPONSE
156-
["V2 transport error: missing garbage terminator, peer=1"], # EXCESS_GARBAGE
157-
["V2 handshake timeout peer=2"], # WRONG_GARBAGE_TERMINATOR
166+
["V2 transport error: missing garbage terminator, peer=2"], # EXCESS_GARBAGE
167+
["V2 handshake timeout peer=4"], # WRONG_GARBAGE_TERMINATOR
158168
["V2 transport error: packet decryption failure"], # WRONG_GARBAGE
159169
["V2 transport error: packet decryption failure"], # SEND_NO_AAD
160170
[], # SEND_NON_EMPTY_VERSION_PACKET
@@ -167,8 +177,16 @@ def test_v2disconnection(self):
167177
self.log.info(f"No disconnection for {test_type.name}")
168178
else:
169179
with node0.assert_debug_log(expected_debug_message[test_type.value], timeout=5):
170-
peer = node0.add_p2p_connection(MisbehavingV2Peer(test_type), wait_for_verack=False, send_version=False, supports_v2_p2p=True, expect_success=False)
171-
peer.wait_for_disconnect()
180+
node0.setmocktime(int(time.time()))
181+
peer1 = node0.add_p2p_connection(MisbehavingV2Peer(test_type), wait_for_verack=False, send_version=False, supports_v2_p2p=True, expect_success=False)
182+
# `InactivityCheck()` displays a different net log message "socket no message in first %i seconds"
183+
# instead of the expected net log message if `sendSet` isn't set by this point of time.
184+
# Make a passing connection so that `sendSet` gets time to be set for consistent logging
185+
# and for more robust disconnection checking.
186+
peer2 = node0.add_p2p_connection(P2PInterface())
187+
assert peer2.is_connected
188+
node0.bumpmocktime(4) # `InactivityCheck()` triggers now
189+
peer1.wait_for_disconnect()
172190
self.log.info(f"Expected disconnection for {test_type.name}")
173191

174192

0 commit comments

Comments
 (0)