Merge bitcoin#26381: test: Fix intermittent issue in p2p_sendtxrcncl.py

fa3da83 test: Check debug log as well in p2p_sendtxrcncl.py (MacroFake)
fae0439 test: Check correct disconnect reason in p2p_sendtxrcncl.py (MacroFake)
fa590cf test: Fix intermittent issue in p2p_sendtxrcncl.py (MacroFake)

Pull request description:

  Should fix bitcoin#26364

  I can't reproduce this, but my guess would be that `PeerNoVerack::on_version`, which sends the `wtxidrelay` message, is executed in the event loop and thus may run after the main thread sending `msg_verack`.

  Also, fix another bug.

  Finally, add some `assert_debug_log` to ensure the right code branch is executed (and not some random, unrelated disconnect).

ACKs for top commit:
  naumenkogs:
    ACK fa3da83

Tree-SHA512: ee2988372223ea22e94e9783ef6d37114a3945991b6d60f0157917f3850fb7077c566564c3771d915ee74ab28202a3b73c6d89ddec6e2c918462db9a3c02e6cf

Author: MacroFake

test/functional/p2p_sendtxrcncl.py

@@ -107,37 +107,39 @@ def run_test(self):
         peer.send_message(create_sendtxrcncl_msg())
         self.wait_until(lambda : "sendtxrcncl" in self.nodes[0].getpeerinfo()[-1]["bytesrecv_per_msg"])
         self.log.info('second SENDTXRCNCL triggers a disconnect')
-        peer.send_message(create_sendtxrcncl_msg())
-        peer.wait_for_disconnect()
+        with self.nodes[0].assert_debug_log(["(sendtxrcncl received from already registered peer); disconnecting"]):
+            peer.send_message(create_sendtxrcncl_msg())
+            peer.wait_for_disconnect()
 
         self.log.info('SENDTXRCNCL with initiator=responder=0 triggers a disconnect')
         sendtxrcncl_no_role = create_sendtxrcncl_msg()
         sendtxrcncl_no_role.initiator = False
         sendtxrcncl_no_role.responder = False
         peer = self.nodes[0].add_p2p_connection(PeerNoVerack(), send_version=True, wait_for_verack=False)
-        peer.send_message(sendtxrcncl_no_role)
-        peer.wait_for_disconnect()
+        with self.nodes[0].assert_debug_log(["txreconciliation protocol violation"]):
+            peer.send_message(sendtxrcncl_no_role)
+            peer.wait_for_disconnect()
 
         self.log.info('SENDTXRCNCL with initiator=0 and responder=1 from inbound triggers a disconnect')
         sendtxrcncl_wrong_role = create_sendtxrcncl_msg(initiator=False)
         peer = self.nodes[0].add_p2p_connection(PeerNoVerack(), send_version=True, wait_for_verack=False)
-        peer.send_message(sendtxrcncl_wrong_role)
-        peer.wait_for_disconnect()
+        with self.nodes[0].assert_debug_log(["txreconciliation protocol violation"]):
+            peer.send_message(sendtxrcncl_wrong_role)
+            peer.wait_for_disconnect()
 
         self.log.info('SENDTXRCNCL with version=0 triggers a disconnect')
         sendtxrcncl_low_version = create_sendtxrcncl_msg()
         sendtxrcncl_low_version.version = 0
         peer = self.nodes[0].add_p2p_connection(PeerNoVerack(), send_version=True, wait_for_verack=False)
-        peer.send_message(sendtxrcncl_low_version)
-        peer.wait_for_disconnect()
+        with self.nodes[0].assert_debug_log(["txreconciliation protocol violation"]):
+            peer.send_message(sendtxrcncl_low_version)
+            peer.wait_for_disconnect()
 
         self.log.info('sending SENDTXRCNCL after sending VERACK triggers a disconnect')
-        # We use PeerNoVerack even though verack is sent right after, to make sure it was actually
-        # sent before sendtxrcncl is sent.
-        peer = self.nodes[0].add_p2p_connection(PeerNoVerack(), send_version=True, wait_for_verack=False)
-        peer.send_and_ping(msg_verack())
-        peer.send_message(create_sendtxrcncl_msg())
-        peer.wait_for_disconnect()
+        peer = self.nodes[0].add_p2p_connection(P2PInterface())
+        with self.nodes[0].assert_debug_log(["sendtxrcncl received after verack"]):
+            peer.send_message(create_sendtxrcncl_msg())
+            peer.wait_for_disconnect()
 
         self.log.info('SENDTXRCNCL without WTXIDRELAY is ignored (recon state is erased after VERACK)')
         peer = self.nodes[0].add_p2p_connection(PeerNoVerack(wtxidrelay=False), send_version=True, wait_for_verack=False)
@@ -164,15 +166,17 @@ def run_test(self):
         self.log.info('SENDTXRCNCL if block-relay-only triggers a disconnect')
         peer = self.nodes[0].add_outbound_p2p_connection(
             PeerNoVerack(), wait_for_verack=False, p2p_idx=3, connection_type="block-relay-only")
-        peer.send_message(create_sendtxrcncl_msg(initiator=False))
-        peer.wait_for_disconnect()
+        with self.nodes[0].assert_debug_log(["we indicated no tx relay; disconnecting"]):
+            peer.send_message(create_sendtxrcncl_msg(initiator=False))
+            peer.wait_for_disconnect()
 
         self.log.info('SENDTXRCNCL with initiator=1 and responder=0 from outbound triggers a disconnect')
         sendtxrcncl_wrong_role = create_sendtxrcncl_msg(initiator=True)
         peer = self.nodes[0].add_outbound_p2p_connection(
-            P2PInterface(), wait_for_verack=False, p2p_idx=4, connection_type="outbound-full-relay")
-        peer.send_message(sendtxrcncl_wrong_role)
-        peer.wait_for_disconnect()
+            PeerNoVerack(), wait_for_verack=False, p2p_idx=4, connection_type="outbound-full-relay")
+        with self.nodes[0].assert_debug_log(["txreconciliation protocol violation"]):
+            peer.send_message(sendtxrcncl_wrong_role)
+            peer.wait_for_disconnect()
 
         self.log.info('SENDTXRCNCL not sent if -txreconciliation flag is not set')
         self.restart_node(0, [])