p2p: Move all header verification into the network layer, extend logging #19107

723-    msg.m_valid_netmagic = (memcmp(hdr.pchMessageStart, message_start, CMessageHeader::MESSAGE_START_SIZE) == 0);
724-    uint256 hash = GetMessageHash();
725+    // Check the header
726+    if (!hdr.IsValid()){
727+        Reset();
728+        return boost::none;

581+ *                          ready to be processed
582+ * @return  True if the peer should stay connected,
583+ *          False if the peer should be disconnected from.
584+ */
585 bool CNode::ReceiveMsgBytes(const char *pch, unsigned int nBytes, bool& complete)
586 {

670+        return -1;
671+    }
672+
673+    // Check start string, network magic
674+    if (memcmp(hdr.pchMessageStart, chain_params.MessageStart(), CMessageHeader::MESSAGE_START_SIZE) != 0) {
675+        LogPrint(BCLog::NET, "HEADER ERROR - MESSAGESTART (%s, %u bytes), got %s\n", hdr.GetCommand(), hdr.nMessageSize + CMessageHeader::HEADER_SIZE, hdr.GetMessageStart());

676         return -1;
677     }
678 
679     // reject messages larger than MAX_SIZE or MAX_PROTOCOL_MESSAGE_LENGTH
680     if (hdr.nMessageSize > MAX_SIZE || hdr.nMessageSize > MAX_PROTOCOL_MESSAGE_LENGTH) {
681+        LogPrint(BCLog::NET, "HEADER ERROR - SIZE (%s, %u bytes)\n", hdr.GetCommand(), hdr.nMessageSize + CMessageHeader::HEADER_SIZE);

712@@ -692,29 +713,35 @@ const uint256& V1TransportDeserializer::GetMessageHash() const
713     return data_hash;
714 }
715 
716-CNetMessage V1TransportDeserializer::GetMessage(const CMessageHeader::MessageStartChars& message_start, int64_t time) {
717+Optional<CNetMessage> V1TransportDeserializer::GetMessage(int64_t time) {

721-    // store state about valid header, netmagic and checksum
722-    msg.m_valid_header = hdr.IsValid(message_start);
723-    msg.m_valid_netmagic = (memcmp(hdr.pchMessageStart, message_start, CMessageHeader::MESSAGE_START_SIZE) == 0);
724-    uint256 hash = GetMessageHash();
725+    // Check the header
726+    if (!hdr.IsValid()){

3541-    //  (4) message start
3542-    //  (12) command
3543-    //  (4) size
3544-    //  (4) checksum
3545-    //  (x) data
3546-    //

127         {
128             // Must be all zeros after the first zero
129             for (; p1 < pchCommand + COMMAND_SIZE; p1++)
130-                if (*p1 != 0)
131+                if (*p1 != 0){
132+                    LogPrint(BCLog::NET, "HEADER ERROR - COMMAND (%s, %u bytes)\n", GetCommand(), nMessageSize + HEADER_SIZE);

133                     return false;
134+                }
135         }
136-        else if (*p1 < ' ' || *p1 > 0x7E)
137+        else if (*p1 < ' ' || *p1 > 0x7E){
138+            LogPrint(BCLog::NET, "HEADER ERROR - COMMAND (%s, %u bytes)\n", GetCommand(), nMessageSize + HEADER_SIZE);

141+            # If we take 77 bytes, then there are 101 - 77 = 24 left
142+            # That's exactly the size of a header
143+            # So, bitcoind deserializes the header and rejects it for some other reason
144+            # But, if we take 78 bytes, then there are 101 - 78 = 23 left
145+            # That's not enough to fill a header, so, what happens?
146+

35@@ -36,15 +36,16 @@ class CMessageHeader
36     static constexpr size_t HEADER_SIZE = MESSAGE_START_SIZE + COMMAND_SIZE + MESSAGE_SIZE_SIZE + CHECKSUM_SIZE;
37     typedef unsigned char MessageStartChars[MESSAGE_START_SIZE];
38 
39-    explicit CMessageHeader(const MessageStartChars& pchMessageStartIn);
40+    explicit CMessageHeader();

674@@ -675,7 +675,7 @@ class V1TransportDeserializer final : public TransportDeserializer
675 
676 public:
677 
678-    V1TransportDeserializer(const CMessageHeader::MessageStartChars& pchMessageStartIn, int nTypeIn, int nVersionIn) : hdrbuf(nTypeIn, nVersionIn), hdr(pchMessageStartIn), vRecv(nTypeIn, nVersionIn) {
679+    V1TransportDeserializer(const CChainParams& chain_params_in, int nTypeIn, int nVersionIn) : chain_params(chain_params_in), hdrbuf(nTypeIn, nVersionIn), hdr(), vRecv(nTypeIn, nVersionIn) {

712 
713     // store state about valid header, netmagic and checksum
714-    msg.m_valid_header = hdr.IsValid(message_start);
715-    msg.m_valid_netmagic = (memcmp(hdr.pchMessageStart, message_start, CMessageHeader::MESSAGE_START_SIZE) == 0);
716-    uint256 hash = GetMessageHash();
717+    msg.m_valid_header = hdr.IsValid(Params().MessageStart());

647 };
648 
649 class V1TransportDeserializer final : public TransportDeserializer
650 {
651 private:
652+    const CChainParams& chain_params;

43@@ -44,7 +44,8 @@ class CMessageHeader
44     CMessageHeader(const MessageStartChars& pchMessageStartIn, const char* pszCommand, unsigned int nMessageSizeIn);
45 
46     std::string GetCommand() const;
47-    bool IsValid(const MessageStartChars& messageStart) const;
48+    std::string GetMessageStart() const;
49+    bool IsValid() const;

123@@ -124,7 +124,8 @@ def run_test(self):
124         #
125         # Send messages with an incorrect data size in the header.
126         #
127-        actual_size = 100
128+        # These all fail with a checksum error!  That's not what this test is supposed to test.

188@@ -189,10 +189,9 @@ void test_one_input(const std::vector<uint8_t>& buffer)
189         DeserializeFromFuzzingInput(buffer, s);
190         AssertEqualAfterSerializeDeserialize(s);
191 #elif MESSAGEHEADER_DESERIALIZE
192-        const CMessageHeader::MessageStartChars pchMessageStart = {0x00, 0x00, 0x00, 0x00};
193-        CMessageHeader mh(pchMessageStart);
194+        CMessageHeader mh;

598@@ -589,14 +599,22 @@ bool CNode::ReceiveMsgBytes(const char *pch, unsigned int nBytes, bool& complete
599     while (nBytes > 0) {
600         // absorb network data
601         int handled = m_deserializer->Read(pch, nBytes);
602-        if (handled < 0) return false;
603+        if (handled < 0){
604+            LogPrint(BCLog::NET, "HEADER ERROR peer=%d\n", id);

607 
608         pch += handled;
609         nBytes -= handled;
610 
611         if (m_deserializer->Complete()) {
612             // decompose a transport agnostic CNetMessage from the deserializer

640@@ -642,13 +641,14 @@ class TransportDeserializer {
641     // read and deserialize data
642     virtual int Read(const char *data, unsigned int bytes) = 0;
643     // decomposes a message from the context

598@@ -589,14 +599,22 @@ bool CNode::ReceiveMsgBytes(const char *pch, unsigned int nBytes, bool& complete
599     while (nBytes > 0) {
600         // absorb network data
601         int handled = m_deserializer->Read(pch, nBytes);
602-        if (handled < 0) return false;
603+        if (handled < 0){
604+            LogPrint(BCLog::NET, "HEADER ERROR peer=%d\n", id);
605+            return false;

117+std::string CMessageHeader::GetMessageStart() const
118 {
119-    // Check start string
120-    if (memcmp(pchMessageStart, pchMessageStartIn, MESSAGE_START_SIZE) != 0)
121-        return false;
122+    return std::string(pchMessageStart, pchMessageStart + strnlen(pchMessageStart, MESSAGE_START_SIZE));

752 
753-    msg.m_valid_checksum = (memcmp(hash.begin(), hdr.pchChecksum, CMessageHeader::CHECKSUM_SIZE) == 0);
754-    if (!msg.m_valid_checksum) {
755+    // Check checksum
756+    bool valid_checksum = (memcmp(hash.begin(), hdr.pchChecksum, CMessageHeader::CHECKSUM_SIZE) == 0);
757+    if (!valid_checksum) {

757+    if (!valid_checksum) {
758         LogPrint(BCLog::NET, "CHECKSUM ERROR (%s, %u bytes), expected %s was %s\n",
759                  SanitizeString(msg.m_command), msg.m_message_size,
760                  HexStr(hash.begin(), hash.begin()+CMessageHeader::CHECKSUM_SIZE),
761                  HexStr(hdr.pchChecksum, hdr.pchChecksum+CMessageHeader::CHECKSUM_SIZE));
762+        Reset();

611         if (m_deserializer->Complete()) {
612             // decompose a transport agnostic CNetMessage from the deserializer
613-            CNetMessage msg = m_deserializer->GetMessage(Params().MessageStart(), nTimeMicros);
614+            Optional<CNetMessage> result = m_deserializer->GetMessage(nTimeMicros);
615+            if(!result){
616+                LogPrint(BCLog::NET, "HEADER ERROR peer=%d\n", id);

 9@@ -10,12 +10,14 @@
10 #include <addrman.h>
11 #include <amount.h>
12 #include <bloom.h>
13+#include <chainparams.h>

130         if (*p1 == 0)
131         {
132             // Must be all zeros after the first zero
133             for (; p1 < pchCommand + COMMAND_SIZE; p1++)
134-                if (*p1 != 0)
135+                if (*p1 != 0){

136+                    LogPrint(BCLog::NET, "HEADER ERROR - COMMAND (%s, %u bytes)\n", GetCommand(), nMessageSize + HEADER_SIZE);
137                     return false;
138+                }
139         }
140-        else if (*p1 < ' ' || *p1 > 0x7E)
141+        else if (*p1 < ' ' || *p1 > 0x7E){

131         {
132             // Must be all zeros after the first zero
133             for (; p1 < pchCommand + COMMAND_SIZE; p1++)
134-                if (*p1 != 0)
135+                if (*p1 != 0){
136+                    LogPrint(BCLog::NET, "HEADER ERROR - COMMAND (%s, %u bytes)\n", GetCommand(), nMessageSize + HEADER_SIZE);

41-                assert(msg.m_valid_netmagic);
42-            }
43-            if (!msg.m_valid_netmagic) {
44-                assert(!msg.m_valid_header);
45+            auto result = deserializer.GetMessage(m_time);
46+            if (result){

609 
610         if (m_deserializer->Complete()) {
611             // decompose a transport agnostic CNetMessage from the deserializer
612-            CNetMessage msg = m_deserializer->GetMessage(Params().MessageStart(), nTimeMicros);
613+            Optional<CNetMessage> result = m_deserializer->GetMessage(nTimeMicros);
614+            if(!result){

597@@ -589,14 +598,22 @@ bool CNode::ReceiveMsgBytes(const char *pch, unsigned int nBytes, bool& complete
598     while (nBytes > 0) {
599         // absorb network data
600         int handled = m_deserializer->Read(pch, nBytes);
601-        if (handled < 0) return false;
602+        if (handled < 0){

674@@ -674,8 +675,16 @@ class V1TransportDeserializer final : public TransportDeserializer
675     }
676 
677 public:
678+<<<<<<< HEAD
679+    V1TransportDeserializer(const CChainParams& chain_params_in, int nTypeIn, int nVersionIn) : m_chain_params(chain_params_in), hdrbuf(nTypeIn, nVersionIn), vRecv(nTypeIn, nVersionIn)
680+    {
681+||||||| parent of f070a97fe5... Remove header checks out of net_processing

577@@ -579,6 +578,16 @@ void CNode::copyStats(CNodeStats &stats, const std::vector<bool> &m_asmap)
578 }
579 #undef X
580 
581+/**
582+ * Receive bytes from the buffer and deserialize them into messages.
583+ *
584+ * @param[in]   pch         Socket buffer
585+ * @param[in]   nBytes      Size of the socket buffer
586+ * @param[out]  complete    Set True if a message has been deserialized and is

608         nBytes -= handled;
609 
610         if (m_deserializer->Complete()) {
611             // decompose a transport agnostic CNetMessage from the deserializer
612-            CNetMessage msg = m_deserializer->GetMessage(Params().MessageStart(), nTimeMicros);
613+            Optional<CNetMessage> result = m_deserializer->GetMessage(nTimeMicros);

136-                if (*p1 != 0)
137+            for (; p1 < pchCommand + COMMAND_SIZE; ++p1) {
138+                if (*p1 != 0) {
139                     return false;
140-        }
141-        else if (*p1 < ' ' || *p1 > 0x7E)

72@@ -73,7 +73,7 @@ def test_checksum(self):
73 
74     def test_size(self):
75         conn = self.nodes[0].add_p2p_connection(P2PDataStore())
76-        with self.nodes[0].assert_debug_log(['']):
77+        with self.nodes[0].assert_debug_log(['HEADER ERROR - SIZE']):

50@@ -51,7 +51,7 @@ def run_test(self):
51 
52     def test_magic_bytes(self):
53         conn = self.nodes[0].add_p2p_connection(P2PDataStore())
54-        with self.nodes[0].assert_debug_log(['PROCESSMESSAGE: INVALID MESSAGESTART badmsg']):
55+        with self.nodes[0].assert_debug_log(['HEADER ERROR - MESSAGESTART']):

82@@ -83,9 +83,8 @@ def test_size(self):
83 
84     def test_msgtype(self):
85         conn = self.nodes[0].add_p2p_connection(P2PDataStore())
86-        with self.nodes[0].assert_debug_log(['PROCESSMESSAGE: ERRORS IN HEADER']):
87+        with self.nodes[0].assert_debug_log(['HEADER ERROR - COMMAND']):

613+            Optional<CNetMessage> result = m_deserializer->GetMessage(nTimeMicros);
614+            if (!result) {
615+                // Message deserialization failed.  Drop the message but don't disconnect the peer.
616+                continue;
617+            }
618+            CNetMessage msg = *result;

759+        LogPrint(BCLog::NET, "CHECKSUM ERROR (%s, %u bytes), expected %s was %s, peer=%d\n",
760+            SanitizeString(msg.m_command), msg.m_message_size,
761+            HexStr(hash.begin(), hash.begin() + CMessageHeader::CHECKSUM_SIZE),
762+            HexStr(hdr.pchChecksum, hdr.pchChecksum + CMessageHeader::CHECKSUM_SIZE),
763+            node_id);
764+        Reset();

681+        return -1;
682+    }
683+
684+    // Check start string, network magic
685+    if (memcmp(hdr.pchMessageStart, m_chain_params.MessageStart(), CMessageHeader::MESSAGE_START_SIZE) != 0) {
686+        LogPrint(BCLog::NET, "HEADER ERROR - MESSAGESTART (%s, %u bytes), got %s, peer=%d\n", hdr.GetCommand(), hdr.nMessageSize, HexStr(hdr.GetMessageStart()), node_id);

602-            CNetMessage msg = m_deserializer->GetMessage(Params().MessageStart(), nTimeMicros);
603+            Optional<CNetMessage> result = m_deserializer->GetMessage(Params().MessageStart(), nTimeMicros);
604+            if (!result) {
605+                continue;
606+            }
607+            CNetMessage msg = *result;

762+            node_id);
763+    } else if (!hdr.IsCommandValid()) {
764+        LogPrint(BCLog::NET, "HEADER ERROR - COMMAND (%s, %u bytes), peer=%d\n",
765+            hdr.GetCommand(), msg.m_message_size, node_id);
766+    } else {
767+        result = msg;

648 
649 class V1TransportDeserializer final : public TransportDeserializer
650 {
651 private:
652+    const CChainParams& m_chain_params;
653+    const NodeId node_id; // Only for logging

722@@ -699,37 +723,40 @@ const uint256& V1TransportDeserializer::GetMessageHash() const
723     return data_hash;
724 }
725 
726-CNetMessage V1TransportDeserializer::GetMessage(const CMessageHeader::MessageStartChars& message_start, int64_t time) {
727+Optional<CNetMessage> V1TransportDeserializer::GetMessage(int64_t time)
728+{
729     // decompose a single CNetMessage from the TransportDeserializer
730     CNetMessage msg(std::move(vRecv));
731+    Optional<CNetMessage> result{};

3659@@ -3660,17 +3660,8 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic<bool>& inter
3660     // Message size
3661     unsigned int nMessageSize = msg.m_message_size;
3662 
3663-    // Checksum
3664-    CDataStream& vRecv = msg.m_recv;
3665-    if (!msg.m_valid_checksum)
3666-    {
3667-        LogPrint(BCLog::NET, "%s(%s, %u bytes): CHECKSUM ERROR peer=%d\n", __func__,

41-            }
42-            if (!msg.m_valid_netmagic) {
43-                assert(!msg.m_valid_header);
44+            auto result = deserializer.GetMessage(Params().MessageStart(), m_time);
45+            if (result) {
46+                const CNetMessage msg = *result;

578@@ -579,6 +579,16 @@ void CNode::copyStats(CNodeStats &stats, const std::vector<bool> &m_asmap)
579 }
580 #undef X
581 
582+/**
583+ * Receive bytes from the buffer and deserialize them into messages.
584+ *
585+ * @param[in]   pch         Socket buffer

578@@ -579,6 +579,16 @@ void CNode::copyStats(CNodeStats &stats, const std::vector<bool> &m_asmap)
579 }
580 #undef X
581 
582+/**
583+ * Receive bytes from the buffer and deserialize them into messages.
584+ *
585+ * @param[in]   pch         Socket buffer
586+ * @param[in]   nBytes      Size of the socket buffer
587+ * @param[out]  complete    Set True if a message has been deserialized and is

673@@ -674,8 +674,8 @@ class V1TransportDeserializer final : public TransportDeserializer
674     }
675 
676 public:
677-
678-    V1TransportDeserializer(const CMessageHeader::MessageStartChars& pchMessageStartIn, int nTypeIn, int nVersionIn) : hdrbuf(nTypeIn, nVersionIn), hdr(pchMessageStartIn), vRecv(nTypeIn, nVersionIn) {
679+    V1TransportDeserializer(const CMessageHeader::MessageStartChars& pchMessageStartIn, int nTypeIn, int nVersionIn) : hdrbuf(nTypeIn, nVersionIn), vRecv(nTypeIn, nVersionIn)

 9@@ -10,7 +10,6 @@
10 #include <net.h>
11 
12 #include <banman.h>
13-#include <chainparams.h>

112@@ -113,6 +113,11 @@ std::string CMessageHeader::GetCommand() const
113     return std::string(pchCommand, pchCommand + strnlen(pchCommand, COMMAND_SIZE));
114 }
115 
116+std::string CMessageHeader::GetMessageStart() const
117+{
118+    return std::string(pchMessageStart, pchMessageStart + strnlen(pchMessageStart, MESSAGE_START_SIZE));

675@@ -674,11 +676,19 @@ int V1TransportDeserializer::readHeader(const char *pch, unsigned int nBytes)
676         hdrbuf >> hdr;
677     }
678     catch (const std::exception&) {
679+        LogPrint(BCLog::NET, "HEADER ERROR - UNABLE TO DESERIALIZE, peer=%d\n", m_node_id);

717@@ -718,10 +718,11 @@ CNetMessage V1TransportDeserializer::GetMessage(const CMessageHeader::MessageSta
718 
719     msg.m_valid_checksum = (memcmp(hash.begin(), hdr.pchChecksum, CMessageHeader::CHECKSUM_SIZE) == 0);
720     if (!msg.m_valid_checksum) {
721-        LogPrint(BCLog::NET, "CHECKSUM ERROR (%s, %u bytes), expected %s was %s\n",
722+        LogPrint(BCLog::NET, "CHECKSUM ERROR (%s, %u bytes), expected %s was %s, peer=%d\n",

2807@@ -2778,7 +2808,7 @@ CNode::CNode(NodeId idIn, ServiceFlags nLocalServicesIn, int nMyStartingHeightIn
2808         LogPrint(BCLog::NET, "Added connection peer=%d\n", id);
2809     }
2810 
2811-    m_deserializer = MakeUnique<V1TransportDeserializer>(V1TransportDeserializer(Params().MessageStart(), SER_NETWORK, INIT_PROTO_VERSION));
2812+    m_deserializer = MakeUnique<V1TransportDeserializer>(V1TransportDeserializer(Params(), GetId(), SER_NETWORK, INIT_PROTO_VERSION));

614+            uint32_t out_err{0};
615+            Optional<CNetMessage> result{m_deserializer->GetMessage(time, out_err)};
616+            if (!result) {
617+                // Message deserialization failed.  Drop the message but don't disconnect the peer.
618+                // store the size of the corrupt message
619+                mapRecvBytesPerMsgCmd.find(NET_MESSAGE_COMMAND_OTHER)->second += out_err;

607-            CNetMessage msg = m_deserializer->GetMessage(Params().MessageStart(), time);
608+            uint32_t out_err{0};
609+            Optional<CNetMessage> result{m_deserializer->GetMessage(Params().MessageStart(), time, out_err)};
610+            if (!result) {
611+                // store the size of the corrupt message
612+                mapRecvBytesPerMsgCmd.find(NET_MESSAGE_COMMAND_OTHER)->second += out_err;