Merge #19304: test: Check that message sends successfully when header is split across two buffers

80d4423 Test buffered valid message (Troy Giorshev)

Pull request description:

  This PR is a tweak of #19302.  This sends a valid message.

  Additionally, this test includes logging in the same vein as #19272.

ACKs for top commit:
  MarcoFalke:
    tested ACK 80d4423 (added an assert(false) to observe deterministic coverage) 🌦
  gzhao408:
    ACK bitcoin/bitcoin@80d4423 👊

Tree-SHA512: 3b1aa5ec480a1661917354788923d64595e2886448c9697ec0606a81293e8b4a4642b2b3cc9afb2206ce6f74e5c6d687308c5ad19cb73c5b354d3071ad8496f8

Author: MarcoFalke

test/functional/p2p_invalid_messages.py

@@ -3,12 +3,14 @@
 # Distributed under the MIT software license, see the accompanying
 # file COPYING or http://www.opensource.org/licenses/mit-license.php.
 """Test node responses to invalid network messages."""
+
 from test_framework.messages import (
     CBlockHeader,
     CInv,
     msg_getdata,
     msg_headers,
     msg_inv,
+    msg_ping,
     MSG_TX,
     ser_string,
 )
@@ -17,6 +19,10 @@
     P2PInterface,
 )
 from test_framework.test_framework import BitcoinTestFramework
+from test_framework.util import (
+    assert_equal,
+    wait_until,
+)
 
 MSG_LIMIT = 4 * 1000 * 1000  # 4MB, per MAX_PROTOCOL_MESSAGE_LENGTH
 VALID_DATA_LIMIT = MSG_LIMIT - 5  # Account for the 5-byte length prefix
@@ -42,13 +48,33 @@ def set_test_params(self):
         self.setup_clean_chain = True
 
     def run_test(self):
+        self.test_buffer()
         self.test_magic_bytes()
         self.test_checksum()
         self.test_size()
         self.test_msgtype()
         self.test_large_inv()
         self.test_resource_exhaustion()
 
+    def test_buffer(self):
+        self.log.info("Test message with header split across two buffers, should be received")
+        conn = self.nodes[0].add_p2p_connection(P2PDataStore())
+        # Create valid message
+        msg = conn.build_message(msg_ping(nonce=12345))
+        cut_pos = 12    # Chosen at an arbitrary position within the header
+        # Send message in two pieces
+        before = int(self.nodes[0].getnettotals()['totalbytesrecv'])
+        conn.send_raw_message(msg[:cut_pos])
+        # Wait until node has processed the first half of the message
+        wait_until(lambda: int(self.nodes[0].getnettotals()['totalbytesrecv']) != before)
+        middle = int(self.nodes[0].getnettotals()['totalbytesrecv'])
+        # If this assert fails, we've hit an unlikely race
+        # where the test framework sent a message in between the two halves
+        assert_equal(middle, before + cut_pos)
+        conn.send_raw_message(msg[cut_pos:])
+        conn.sync_with_ping(timeout=1)
+        self.nodes[0].disconnect_p2ps()
+
     def test_magic_bytes(self):
         conn = self.nodes[0].add_p2p_connection(P2PDataStore())
         with self.nodes[0].assert_debug_log(['PROCESSMESSAGE: INVALID MESSAGESTART badmsg']):
@@ -95,13 +121,13 @@ def test_msgtype(self):
 
     def test_large_inv(self):
         conn = self.nodes[0].add_p2p_connection(P2PInterface())
-        with self.nodes[0].assert_debug_log(['Misbehaving', 'peer=4 (0 -> 20): message inv size() = 50001']):
+        with self.nodes[0].assert_debug_log(['Misbehaving', '(0 -> 20): message inv size() = 50001']):
             msg = msg_inv([CInv(MSG_TX, 1)] * 50001)
             conn.send_and_ping(msg)
-        with self.nodes[0].assert_debug_log(['Misbehaving', 'peer=4 (20 -> 40): message getdata size() = 50001']):
+        with self.nodes[0].assert_debug_log(['Misbehaving', '(20 -> 40): message getdata size() = 50001']):
             msg = msg_getdata([CInv(MSG_TX, 1)] * 50001)
             conn.send_and_ping(msg)
-        with self.nodes[0].assert_debug_log(['Misbehaving', 'peer=4 (40 -> 60): headers message size = 2001']):
+        with self.nodes[0].assert_debug_log(['Misbehaving', '(40 -> 60): headers message size = 2001']):
             msg = msg_headers([CBlockHeader()] * 2001)
             conn.send_and_ping(msg)
         self.nodes[0].disconnect_p2ps()