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

fa3da8307baa96ea7e51cc6ba4820aca7f93ec32 test: Check debug log as well in p2p_sendtxrcncl.py (MacroFake)
fae0439486e9af428829b4604b3be5bb97b67b24 test: Check correct disconnect reason in p2p_sendtxrcncl.py (MacroFake)
fa590cfaae887c927ffb4af92a15516332428d69 test: Fix intermittent issue in p2p_sendtxrcncl.py (MacroFake)

Pull request description:

  Should fix https://github.com/bitcoin/bitcoin/issues/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 fa3da8307baa96ea7e51cc6ba4820aca7f93ec32

Tree-SHA512: ee2988372223ea22e94e9783ef6d37114a3945991b6d60f0157917f3850fb7077c566564c3771d915ee74ab28202a3b73c6d89ddec6e2c918462db9a3c02e6cf

1 files changed, 23 insertions, 19 deletions

diff --git a/test/functional/p2p_sendtxrcncl.py b/test/functional/p2p_sendtxrcncl.py
index f4c5dd4586..14cd815a30 100755
--- a/test/functional/p2p_sendtxrcncl.py
+++ b/test/functional/p2p_sendtxrcncl.py
@@ -107,37 +107,39 @@ class SendTxRcnclTest(BitcoinTestFramework):
         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 @@ class SendTxRcnclTest(BitcoinTestFramework):
         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, [])