From 955eee76803c098978cf0bbc7f1f6d3c230544e2 Mon Sep 17 00:00:00 2001 From: "W. J. van der Laan" Date: Thu, 6 May 2021 17:25:17 +0200 Subject: [PATCH 1/2] net: Sanitize message type for logging - Use `SanitizeString` when logging message errors to make sure that the message type is sanitized. - For the `MESSAGESTART` error don't inspect and log header details at all: receiving invalid start bytes makes it likely that the packet isn't even formatted as valid P2P message. Logging the four unexpected start bytes should be enough. - Update `p2p_invalid_messages.py` test to check this. Issue reported by gmaxwell. --- src/net.cpp | 6 +++--- test/functional/p2p_invalid_messages.py | 4 ++-- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/src/net.cpp b/src/net.cpp index f55d3e2418f..02e36724939 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -687,13 +687,13 @@ int V1TransportDeserializer::readHeader(Span msg_bytes) // Check start string, network magic if (memcmp(hdr.pchMessageStart, m_chain_params.MessageStart(), CMessageHeader::MESSAGE_START_SIZE) != 0) { - LogPrint(BCLog::NET, "HEADER ERROR - MESSAGESTART (%s, %u bytes), received %s, peer=%d\n", hdr.GetCommand(), hdr.nMessageSize, HexStr(hdr.pchMessageStart), m_node_id); + LogPrint(BCLog::NET, "HEADER ERROR - MESSAGESTART received %s, peer=%d\n", HexStr(hdr.pchMessageStart), m_node_id); return -1; } // reject messages larger than MAX_SIZE or MAX_PROTOCOL_MESSAGE_LENGTH if (hdr.nMessageSize > MAX_SIZE || hdr.nMessageSize > MAX_PROTOCOL_MESSAGE_LENGTH) { - LogPrint(BCLog::NET, "HEADER ERROR - SIZE (%s, %u bytes), peer=%d\n", hdr.GetCommand(), hdr.nMessageSize, m_node_id); + LogPrint(BCLog::NET, "HEADER ERROR - SIZE (%s, %u bytes), peer=%d\n", SanitizeString(hdr.GetCommand()), hdr.nMessageSize, m_node_id); return -1; } @@ -755,7 +755,7 @@ std::optional V1TransportDeserializer::GetMessage(const std::chrono msg = std::nullopt; } else if (!hdr.IsCommandValid()) { LogPrint(BCLog::NET, "HEADER ERROR - COMMAND (%s, %u bytes), peer=%d\n", - hdr.GetCommand(), msg->m_message_size, m_node_id); + SanitizeString(hdr.GetCommand()), msg->m_message_size, m_node_id); out_err_raw_size = msg->m_raw_message_size; msg.reset(); } diff --git a/test/functional/p2p_invalid_messages.py b/test/functional/p2p_invalid_messages.py index c0b3c2cb12e..c81886a9826 100755 --- a/test/functional/p2p_invalid_messages.py +++ b/test/functional/p2p_invalid_messages.py @@ -37,7 +37,7 @@ VALID_DATA_LIMIT = MAX_PROTOCOL_MESSAGE_LENGTH - 5 # Account for the 5-byte len class msg_unrecognized: """Nonsensical message. Modeled after similar types in test_framework.messages.""" - msgtype = b'badmsg' + msgtype = b'badmsg\x01' def __init__(self, *, str_data): self.str_data = str_data.encode() if not isinstance(str_data, bytes) else str_data @@ -104,7 +104,7 @@ class InvalidMessagesTest(BitcoinTestFramework): 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']): + with self.nodes[0].assert_debug_log(['HEADER ERROR - MESSAGESTART received ffffffff']): msg = conn.build_message(msg_unrecognized(str_data="d")) # modify magic bytes msg = b'\xff' * 4 + msg[4:] From 09205b33aa74e385caa2803aa6febc18ad1efa32 Mon Sep 17 00:00:00 2001 From: "W. J. van der Laan" Date: Fri, 7 May 2021 07:45:55 +0200 Subject: [PATCH 2/2] net: Clarify message header validation errors Make the errors less shouty and more descriptive. --- src/net.cpp | 10 +++++----- test/functional/p2p_invalid_messages.py | 8 ++++---- 2 files changed, 9 insertions(+), 9 deletions(-) diff --git a/src/net.cpp b/src/net.cpp index 02e36724939..ce38c140cea 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -681,19 +681,19 @@ int V1TransportDeserializer::readHeader(Span msg_bytes) hdrbuf >> hdr; } catch (const std::exception&) { - LogPrint(BCLog::NET, "HEADER ERROR - UNABLE TO DESERIALIZE, peer=%d\n", m_node_id); + LogPrint(BCLog::NET, "Header error: Unable to deserialize, peer=%d\n", m_node_id); return -1; } // Check start string, network magic if (memcmp(hdr.pchMessageStart, m_chain_params.MessageStart(), CMessageHeader::MESSAGE_START_SIZE) != 0) { - LogPrint(BCLog::NET, "HEADER ERROR - MESSAGESTART received %s, peer=%d\n", HexStr(hdr.pchMessageStart), m_node_id); + LogPrint(BCLog::NET, "Header error: Wrong MessageStart %s received, peer=%d\n", HexStr(hdr.pchMessageStart), m_node_id); return -1; } // reject messages larger than MAX_SIZE or MAX_PROTOCOL_MESSAGE_LENGTH if (hdr.nMessageSize > MAX_SIZE || hdr.nMessageSize > MAX_PROTOCOL_MESSAGE_LENGTH) { - LogPrint(BCLog::NET, "HEADER ERROR - SIZE (%s, %u bytes), peer=%d\n", SanitizeString(hdr.GetCommand()), hdr.nMessageSize, m_node_id); + LogPrint(BCLog::NET, "Header error: Size too large (%s, %u bytes), peer=%d\n", SanitizeString(hdr.GetCommand()), hdr.nMessageSize, m_node_id); return -1; } @@ -746,7 +746,7 @@ std::optional V1TransportDeserializer::GetMessage(const std::chrono // Check checksum and header command string if (memcmp(hash.begin(), hdr.pchChecksum, CMessageHeader::CHECKSUM_SIZE) != 0) { - LogPrint(BCLog::NET, "CHECKSUM ERROR (%s, %u bytes), expected %s was %s, peer=%d\n", + LogPrint(BCLog::NET, "Header error: Wrong checksum (%s, %u bytes), expected %s was %s, peer=%d\n", SanitizeString(msg->m_command), msg->m_message_size, HexStr(Span(hash.begin(), hash.begin() + CMessageHeader::CHECKSUM_SIZE)), HexStr(hdr.pchChecksum), @@ -754,7 +754,7 @@ std::optional V1TransportDeserializer::GetMessage(const std::chrono out_err_raw_size = msg->m_raw_message_size; msg = std::nullopt; } else if (!hdr.IsCommandValid()) { - LogPrint(BCLog::NET, "HEADER ERROR - COMMAND (%s, %u bytes), peer=%d\n", + LogPrint(BCLog::NET, "Header error: Invalid message type (%s, %u bytes), peer=%d\n", SanitizeString(hdr.GetCommand()), msg->m_message_size, m_node_id); out_err_raw_size = msg->m_raw_message_size; msg.reset(); diff --git a/test/functional/p2p_invalid_messages.py b/test/functional/p2p_invalid_messages.py index c81886a9826..788a81d4af0 100755 --- a/test/functional/p2p_invalid_messages.py +++ b/test/functional/p2p_invalid_messages.py @@ -104,7 +104,7 @@ class InvalidMessagesTest(BitcoinTestFramework): 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 received ffffffff']): + with self.nodes[0].assert_debug_log(['Header error: Wrong MessageStart ffffffff received']): msg = conn.build_message(msg_unrecognized(str_data="d")) # modify magic bytes msg = b'\xff' * 4 + msg[4:] @@ -115,7 +115,7 @@ class InvalidMessagesTest(BitcoinTestFramework): 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']): + with self.nodes[0].assert_debug_log(['Header error: Wrong checksum (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 @@ -130,7 +130,7 @@ class InvalidMessagesTest(BitcoinTestFramework): 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, 4000001 bytes)']): + with self.nodes[0].assert_debug_log(['Header error: Size too large (badmsg, 4000001 bytes)']): msg = msg_unrecognized(str_data="d" * (VALID_DATA_LIMIT + 1)) msg = conn.build_message(msg) conn.send_raw_message(msg) @@ -140,7 +140,7 @@ class InvalidMessagesTest(BitcoinTestFramework): 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']): + with self.nodes[0].assert_debug_log(['Header error: Invalid message type']): msg = msg_unrecognized(str_data="d") msg = conn.build_message(msg) # Modify msgtype