Merge bitcoin#19272: net, test: invalid p2p messages and test framewo…

…rk improvements

56010f9 test: hoist p2p values to test framework constants (Jon Atack)
75447f0 test: improve msg sends and p2p disconnections in p2p_invalid_messages (Jon Atack)
5796019 test: refactor test_large_inv() into 3 tests with common method (Jon Atack)
e2b21d8 test: add p2p_invalid_messages logging (Jon Atack)
9fa494d net: update misbehavior logging for oversized messages (Jon Atack)

Pull request description:

  ...seen while reviewing bitcoin#19264, bitcoin#19252, bitcoin#19304 and bitcoin#19107:

  in `net_processing.cpp`
  - make the debug logging for oversized message size misbehavior the same for `addr`, `getdata`, `headers` and `inv` messages

  in `p2p_invalid_messages`
  - add missing logging
  - improve assertions/message sends, move cleanup disconnections outside the assertion scopes
  - split a slowish 3-part test into 3 order-independent tests
  - add a few p2p constants to the test framework

ACKs for top commit:
  troygiorshev:
    reACK 56010f9
  MarcoFalke:
    ACK 56010f9 🎛

Tree-SHA512: db67b70278f8d4c318907e105af54b54eb3afd15500f9aa0c98034f6fd4bd1cf9ad1663037bd9b237ff4890f3059b37291a6498d8d6ae2cc38efb9f045f73310

src/net_processing.cpp

@@ -3220,7 +3220,8 @@ void PeerManagerImpl::ProcessMessage(
         vRecv >> vInv;
         if (vInv.size() > MAX_INV_SZ)
         {
-            Misbehaving(pfrom.GetId(), 20, strprintf("message inv size() = %u", vInv.size()));
+            LOCK(cs_main);
+            Misbehaving(pfrom.GetId(), 20, strprintf("inv message size = %u", vInv.size()));
             return;
         }
 
@@ -3313,7 +3314,8 @@ void PeerManagerImpl::ProcessMessage(
         vRecv >> vInv;
         if (vInv.size() > MAX_INV_SZ)
         {
-            Misbehaving(pfrom.GetId(), 20, strprintf("message getdata size() = %u", vInv.size()));
+
+            Misbehaving(pfrom.GetId(), 20, strprintf("getdata message size = %u", vInv.size()));
             return;
         }
 

test/functional/p2p_addr_relay.py

@@ -47,7 +47,7 @@ def run_test(self):
         addr_source = self.nodes[0].add_p2p_connection(P2PInterface())
         msg = msg_addr()
 
-        self.log.info('Send too large addr message')
+        self.log.info('Send too-large addr message')
         msg.addrs = ADDRS * 101
         with self.nodes[0].assert_debug_log(['addr message size = 1010']):
             addr_source.send_and_ping(msg)

test/functional/p2p_invalid_messages.py

@@ -13,6 +13,9 @@
     CInv,
     msg_ping,
     ser_string,
+    MAX_HEADERS_RESULTS,
+    MAX_INV_SIZE,
+    MAX_PROTOCOL_MESSAGE_LENGTH,
     msg_getdata,
     msg_headers,
     msg_inv,
@@ -158,9 +161,12 @@ def run_test(self):
 
         # Node is still up.
         conn = node.add_p2p_connection(P2PDataStore())
+        self.test_oversized_inv_msg()
+        self.test_oversized_getdata_msg()
+        self.test_oversized_headers_msg()
 
     def test_buffer(self):
-        self.log.info("Test message with header split across two buffers, should be received")
+        self.log.info("Test message with header split across two buffers is received")
         conn = self.nodes[0].add_p2p_connection(P2PDataStore())
         # Create valid message
         msg = conn.build_message(msg_ping(nonce=12345))
@@ -179,28 +185,31 @@ def test_buffer(self):
         self.nodes[0].disconnect_p2ps()
 
     def test_magic_bytes(self):
+        self.log.info("Test message with invalid magic bytes disconnects peer")
         conn = self.nodes[0].add_p2p_connection(P2PDataStore())
         with self.nodes[0].assert_debug_log(['HEADER ERROR - MESSAGESTART (badmsg, 2 bytes), received ffffffff']):
             msg = conn.build_message(msg_unrecognized(str_data="d"))
             # modify magic bytes
             msg = b'\xff' * 4 + msg[4:]
             conn.send_raw_message(msg)
             conn.wait_for_disconnect(timeout=5)
-            self.nodes[0].disconnect_p2ps()
+        self.nodes[0].disconnect_p2ps()
 
     def test_checksum(self):
+        self.log.info("Test message with invalid checksum logs an error")
         conn = self.nodes[0].add_p2p_connection(P2PDataStore())
         with self.nodes[0].assert_debug_log(['CHECKSUM ERROR (badmsg, 2 bytes), expected 78df0a04 was ffffffff']):
             msg = conn.build_message(msg_unrecognized(str_data="d"))
             # Checksum is after start bytes (4B), message type (12B), len (4B)
             cut_len = 4 + 12 + 4
             # modify checksum
             msg = msg[:cut_len] + b'\xff' * 4 + msg[cut_len + 4:]
-            self.nodes[0].p2p.send_raw_message(msg)
+            conn.send_raw_message(msg)
             conn.sync_with_ping(timeout=1)
-            self.nodes[0].disconnect_p2ps()
+        self.nodes[0].disconnect_p2ps()
 
     def test_size(self):
+        self.log.info("Test message with oversized payload disconnects peer")
         conn = self.nodes[0].add_p2p_connection(P2PDataStore())
         with self.nodes[0].assert_debug_log(['HEADER ERROR - SIZE (badmsg, 33554433 bytes)']):
             msg = conn.build_message(msg_unrecognized(str_data="d"))
@@ -210,32 +219,20 @@ def test_size(self):
             )
             # modify len to MAX_SIZE + 1
             msg = msg[:cut_len] + struct.pack("<I", 0x02000000 + 1) + msg[cut_len + 4:]
-            self.nodes[0].p2p.send_raw_message(msg)
+            conn.send_raw_message(msg)
             conn.wait_for_disconnect(timeout=5)
-            self.nodes[0].disconnect_p2ps()
+        self.nodes[0].disconnect_p2ps()
 
     def test_msgtype(self):
+        self.log.info("Test message with invalid message type logs an error")
         conn = self.nodes[0].add_p2p_connection(P2PDataStore())
         with self.nodes[0].assert_debug_log(['HEADER ERROR - COMMAND']):
             msg = msg_unrecognized(str_data="d")
             msg = conn.build_message(msg)
             # Modify msgtype
             msg = msg[:7] + b'\x00' + msg[7 + 1:]
-            self.nodes[0].p2p.send_raw_message(msg)
+            conn.send_raw_message(msg)
             conn.sync_with_ping(timeout=1)
-            self.nodes[0].disconnect_p2ps()
-
-    def test_large_inv(self):
-        conn = self.nodes[0].add_p2p_connection(P2PInterface())
-        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', '(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', '(40 -> 60): headers message size = 2001']):
-            msg = msg_headers([CBlockHeader()] * 2001)
-            conn.send_and_ping(msg)
         self.nodes[0].disconnect_p2ps()
 
     def _tweak_msg_data_size(self, message, wrong_size):
@@ -258,6 +255,25 @@ def _tweak_msg_data_size(self, message, wrong_size):
 
         return raw_msg_with_wrong_size
 
+    def test_oversized_msg(self, msg, size):
+        msg_type = msg.msgtype.decode('ascii')
+        self.log.info("Test {} message of size {} is logged as misbehaving".format(msg_type, size))
+        with self.nodes[0].assert_debug_log(['Misbehaving', '{} message size = {}'.format(msg_type, size)]):
+            self.nodes[0].add_p2p_connection(P2PInterface()).send_and_ping(msg)
+        self.nodes[0].disconnect_p2ps()
+
+    def test_oversized_inv_msg(self):
+        size = MAX_INV_SIZE + 1
+        self.test_oversized_msg(msg_inv([CInv(MSG_TX, 1)] * size), size)
+
+    def test_oversized_getdata_msg(self):
+        size = MAX_INV_SIZE + 1
+        self.test_oversized_msg(msg_getdata([CInv(MSG_TX, 1)] * size), size)
+
+    def test_oversized_headers_msg(self):
+        size = MAX_HEADERS_RESULTS + 1
+        self.test_oversized_msg(msg_headers([CBlockHeader()] * size), size)
+
 
 if __name__ == '__main__':
     InvalidMessagesTest().main()

test/functional/test_framework/messages.py

@@ -46,6 +46,10 @@
 
 BIP125_SEQUENCE_NUMBER = 0xfffffffd  # Sequence number that is BIP 125 opt-in and BIP 68-opt-out
 
+MAX_PROTOCOL_MESSAGE_LENGTH = 4000000  # Maximum length of incoming protocol messages
+MAX_HEADERS_RESULTS = 2000  # Number of headers sent in one getheaders result
+MAX_INV_SIZE = 50000  # Maximum number of entries in an 'inv' protocol message
+
 NODE_NETWORK = (1 << 0)
 NODE_BLOOM = (1 << 2)
 NODE_COMPACT_FILTERS = (1 << 6)

test/functional/test_framework/mininode.py

@@ -27,6 +27,7 @@
 from test_framework.messages import (
     CBlockHeader,
     CompressibleBlockHeader,
+    MAX_HEADERS_RESULTS,
     MIN_VERSION_SUPPORTED,
     NODE_HEADERS_COMPRESSED,
     msg_addr,
@@ -620,7 +621,6 @@ def _compute_requested_block_headers(self, locator, hash_stop):
             return
 
         headers_list = [self.block_store[self.last_block_hash]]
-        maxheaders = 2000
         while headers_list[-1].sha256 not in locator.vHave:
             # Walk back through the block store, adding headers to headers_list
             # as we go.
@@ -636,7 +636,7 @@ def _compute_requested_block_headers(self, locator, hash_stop):
                 break
 
         # Truncate the list if there are too many headers
-        headers_list = headers_list[:-maxheaders - 1:-1]
+        headers_list = headers_list[:-MAX_HEADERS_RESULTS - 1:-1]
 
         return headers_list