Merge #2639: [net] disallow sending messages before receiving verack …

…+ enable p2p_leak.py test

56f07da net_processing: 'SENDADDRV2' msg can be received before a verack. (furszy)
2f5339c test: update and enable p2p_leak.py (furszy)
475b1c6 net: require a verack before responding to anything else (Cory Fields)
8a6c72b net: correctly ban before the handshake is complete (furszy)

Pull request description:

  More updates, corrections and test coverage to the network layer for the LLMQ MNs connections work (deep rabbit hole..). Built on top of #2587.

  PR starts in cd00e31, focused on:

  1) Correctly ban before the handshake is complete (c45b9fb).
  2) Require a `verack` before responding to anything else (cbfc5a6).
  3) Update and enable `p2p_leak.py` functional test (check commit, the functional test framework was too ahead of it).
  4) Move `SENDADDRV2` msg processing so it can be processed before a verack.

ACKs for top commit:
  random-zebra:
    ACK 56f07da
  Fuzzbawls:
    ACK 56f07da

Tree-SHA512: b23a6003c6b815f797bd77a646023632d9087be530ad1651255005f9aa5764f9c91ce9de97eac9c9180384442fceeb4ff41ee9b81500246e01e324dcd20f52f6

src/net_processing.cpp

@@ -1288,6 +1288,19 @@ bool static ProcessMessage(CNode* pfrom, std::string strCommand, CDataStream& vR
                   (fLogIPs ? strprintf(", peeraddr=%s", pfrom->addr.ToString()) : ""));
     }
 
+    else if (strCommand == NetMsgType::SENDADDRV2) {
+        pfrom->m_wants_addrv2 = true;
+        return true;
+    }
+
+    else if (!pfrom->fSuccessfullyConnected)
+    {
+        // Must have a verack message before anything else
+        LOCK(cs_main);
+        Misbehaving(pfrom->GetId(), 1);
+        return false;
+    }
+
 
     else if (strCommand == NetMsgType::ADDR || strCommand == NetMsgType::ADDRV2) {
         int stream_version = vRecv.GetVersion();
@@ -1337,11 +1350,6 @@ bool static ProcessMessage(CNode* pfrom, std::string strCommand, CDataStream& vR
             pfrom->fDisconnect = true;
     }
 
-    else if (strCommand == NetMsgType::SENDADDRV2) {
-            pfrom->m_wants_addrv2 = true;
-            return true;
-    }
-
     else if (strCommand == NetMsgType::INV) {
         std::vector<CInv> vInv;
         vRecv >> vInv;
@@ -1954,6 +1962,29 @@ bool static ProcessMessage(CNode* pfrom, std::string strCommand, CDataStream& vR
     return true;
 }
 
+static bool DisconnectIfBanned(CNode* pnode, CConnman* connman)
+{
+    AssertLockHeld(cs_main);
+    CNodeState &state = *State(pnode->GetId());
+
+    if (state.fShouldBan) {
+        state.fShouldBan = false;
+        if (pnode->fWhitelisted) {
+            LogPrintf("Warning: not punishing whitelisted peer %s!\n", pnode->addr.ToString());
+        } else if (pnode->fAddnode) {
+            LogPrintf("Warning: not punishing addnoded peer %s!\n", pnode->addr.ToString());
+        } else {
+            pnode->fDisconnect = true;
+            if (pnode->addr.IsLocal()) {
+                LogPrintf("Warning: not banning local peer %s!\n", pnode->addr.ToString());
+            } else {
+                connman->Ban(pnode->addr, BanReasonNodeMisbehaving);
+            }
+        }
+        return true;
+    }
+    return false;
+}
 
 bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic<bool>& interruptMsgProc)
 {
@@ -2047,8 +2078,13 @@ bool PeerLogicValidation::ProcessMessages(CNode* pfrom, std::atomic<bool>& inter
         PrintExceptionContinue(NULL, "ProcessMessages()");
     }
 
-    if (!fRet)
-        LogPrint(BCLog::NET, "ProcessMessage(%s, %u bytes) FAILED peer=%d\n", SanitizeString(strCommand), nMessageSize, pfrom->GetId());
+    if (!fRet) {
+        LogPrint(BCLog::NET, "ProcessMessage(%s, %u bytes) FAILED peer=%d\n", SanitizeString(strCommand), nMessageSize,
+                 pfrom->GetId());
+    }
+
+    LOCK(cs_main);
+    DisconnectIfBanned(pfrom, connman);
 
     return fMoreWork;
 }
@@ -2107,25 +2143,12 @@ bool PeerLogicValidation::SendMessages(CNode* pto, std::atomic<bool>& interruptM
         if (!lockMain)
             return true;
 
-        CNodeState& state = *State(pto->GetId());
-
-        if (state.fShouldBan) {
-            state.fShouldBan = false;
-            if (pto->fWhitelisted)
-                LogPrintf("Warning: not punishing whitelisted peer %s!\n", pto->addr.ToString());
-            else if (pto->fAddnode)
-                LogPrintf("Warning: not punishing addnoded peer %s!\n", pto->addr.ToString());
-            else {
-                pto->fDisconnect = true;
-                if (pto->addr.IsLocal())
-                    LogPrintf("Warning: not banning local peer %s!\n", pto->addr.ToString());
-                else {
-                    connman->Ban(pto->addr, BanReasonNodeMisbehaving);
-                }
-                return true;
-            }
+        if (DisconnectIfBanned(pto, connman)) {
+            return true;
         }
 
+        CNodeState& state = *State(pto->GetId());
+
         // Address refresh broadcast
         int64_t nNow = GetTimeMicros();
         auto current_time = GetTime<std::chrono::microseconds>();

test/functional/p2p_leak.py

@@ -7,21 +7,19 @@
 A node should never send anything other than VERSION/VERACK until it's
 received a VERACK.
 
-This test connects to a node and sends it a few messages, trying to intice it
-into sending us something it shouldn't.
-
-Also test that nodes that send unsupported service bits to pivxd are disconnected
-and don't receive a VERACK. Unsupported service bits are currently 1 << 5 and
-1 << 7 (until August 1st 2018).
-"""
+This test connects to a node and sends it a few messages, trying to entice it
+into sending us something it shouldn't."""
 
 import time
 
-from test_framework.messages import NODE_NETWORK, msg_getaddr, msg_ping, msg_verack
-from test_framework.mininode import mininode_lock, P2PInterface
+from test_framework.messages import msg_getaddr, msg_ping, msg_verack
+from test_framework.mininode import mininode_lock, P2PInterface, msg_version
 from test_framework.test_framework import PivxTestFramework
-from test_framework.util import wait_until
-
+from test_framework.util import (
+    assert_equal,
+    assert_greater_than_or_equal,
+    wait_until,
+)
 
 banscore = 10
 
@@ -40,7 +38,6 @@ def on_open(self):
 
     def on_version(self, message): self.bad_message(message)
     def on_verack(self, message): self.bad_message(message)
-    def on_reject(self, message): self.bad_message(message)
     def on_inv(self, message): self.bad_message(message)
     def on_addr(self, message): self.bad_message(message)
     def on_getdata(self, message): self.bad_message(message)
@@ -60,22 +57,20 @@ def on_cmpctblock(self, message): self.bad_message(message)
     def on_getblocktxn(self, message): self.bad_message(message)
     def on_blocktxn(self, message): self.bad_message(message)
 
+
 # Node that never sends a version. We'll use this to send a bunch of messages
 # anyway, and eventually get disconnected.
-class CNodeNoVersionBan(CLazyNode):
-    # send a bunch of veracks without sending a message. This should get us disconnected.
-    # NOTE: implementation-specific check here. Remove if pivxd ban behavior changes
-    def on_open(self):
-        super().on_open()
-        for i in range(banscore):
-            self.send_message(msg_verack())
+class CNodeNoVersionMisbehavior(CLazyNode):
+    pass
+
 
 # Node that never sends a version. This one just sits idle and hopes to receive
 # any message (it shouldn't!)
 class CNodeNoVersionIdle(CLazyNode):
     def __init__(self):
         super().__init__()
 
+
 # Node that sends a version but not a verack.
 class CNodeNoVerackIdle(CLazyNode):
     def __init__(self):
@@ -91,59 +86,73 @@ def on_version(self, message):
         self.send_message(msg_ping())
         self.send_message(msg_getaddr())
 
+
+class P2PVersionStore(P2PInterface):
+    version_received = None
+
+    def on_version(self, msg):
+        super().on_version(msg)
+        self.version_received = msg
+
+
 class P2PLeakTest(PivxTestFramework):
     def set_test_params(self):
         self.num_nodes = 1
         self.extra_args = [['-banscore='+str(banscore)]]
 
     def run_test(self):
-        self.nodes[0].setmocktime(1501545600)  # August 1st 2017
+        no_version_disconnect_node = self.nodes[0].add_p2p_connection(
+            CNodeNoVersionMisbehavior(), send_version=False, wait_for_verack=False)
+        no_version_idlenode = self.nodes[0].add_p2p_connection(CNodeNoVersionIdle(), send_version=False, wait_for_verack=False)
+        no_verack_idlenode = self.nodes[0].add_p2p_connection(CNodeNoVerackIdle(), wait_for_verack=False)
 
-        no_version_bannode = self.nodes[0].add_p2p_connection(CNodeNoVersionBan(), send_version=False)
-        no_version_idlenode = self.nodes[0].add_p2p_connection(CNodeNoVersionIdle(), send_version=False)
-        no_verack_idlenode = self.nodes[0].add_p2p_connection(CNodeNoVerackIdle())
-        unsupported_service_bit5_node = self.nodes[0].add_p2p_connection(CLazyNode(), services=NODE_NETWORK)
-        unsupported_service_bit7_node = self.nodes[0].add_p2p_connection(CLazyNode(), services=NODE_NETWORK)
+        # Send enough veracks without a message to reach the peer discouragement
+        # threshold. This should get us disconnected.
+        for _ in range(banscore):
+            no_version_disconnect_node.send_message(msg_verack())
 
-        wait_until(lambda: no_version_bannode.ever_connected, timeout=10, lock=mininode_lock)
+        # Wait until we got the verack in response to the version. Though, don't wait for the other node to receive the
+        # verack, since we never sent one
+        no_verack_idlenode.wait_for_verack()
+
+        wait_until(lambda: no_version_disconnect_node.ever_connected, timeout=10, lock=mininode_lock)
         wait_until(lambda: no_version_idlenode.ever_connected, timeout=10, lock=mininode_lock)
         wait_until(lambda: no_verack_idlenode.version_received, timeout=10, lock=mininode_lock)
-        wait_until(lambda: unsupported_service_bit5_node.ever_connected, timeout=10, lock=mininode_lock)
-        wait_until(lambda: unsupported_service_bit7_node.ever_connected, timeout=10, lock=mininode_lock)
 
         # Mine a block and make sure that it's not sent to the connected nodes
         self.nodes[0].generate(1)
 
         #Give the node enough time to possibly leak out a message
         time.sleep(5)
 
-        #This node should have been banned
-        assert not no_version_bannode.is_connected
-
-        # These nodes should have been disconnected
-        assert not unsupported_service_bit5_node.is_connected
-        assert not unsupported_service_bit7_node.is_connected
+        # Expect this node to be disconnected for misbehavior
+        assert not no_version_disconnect_node.is_connected
 
         self.nodes[0].disconnect_p2ps()
 
-        # Wait until all connections are closed
-        wait_until(lambda: len(self.nodes[0].getpeerinfo()) == 0)
-
         # Make sure no unexpected messages came in
-        assert(no_version_bannode.unexpected_msg == False)
-        assert(no_version_idlenode.unexpected_msg == False)
-        assert(no_verack_idlenode.unexpected_msg == False)
-        assert not unsupported_service_bit5_node.unexpected_msg
-        assert not unsupported_service_bit7_node.unexpected_msg
-
-        self.log.info("Service bits 5 and 7 are allowed after August 1st 2018")
-        self.nodes[0].setmocktime(1533168000)  # August 2nd 2018
-
-        allowed_service_bit5_node = self.nodes[0].add_p2p_connection(P2PInterface(), services=NODE_NETWORK)
-        allowed_service_bit7_node = self.nodes[0].add_p2p_connection(P2PInterface(), services=NODE_NETWORK)
-
-        wait_until(lambda: allowed_service_bit5_node.message_count["verack"], lock=mininode_lock)
-        wait_until(lambda: allowed_service_bit7_node.message_count["verack"], lock=mininode_lock)
+        assert no_version_disconnect_node.unexpected_msg == False
+        assert no_version_idlenode.unexpected_msg == False
+        assert no_verack_idlenode.unexpected_msg == False
+
+        self.log.info('Check that the version message does not leak the local address of the node')
+        p2p_version_store = self.nodes[0].add_p2p_connection(P2PVersionStore())
+        ver = p2p_version_store.version_received
+        # Check that received time is within one hour of now
+        assert_greater_than_or_equal(ver.nTime, time.time() - 3600)
+        assert_greater_than_or_equal(time.time() + 3600, ver.nTime)
+        assert_equal(ver.addrFrom.port, 0)
+        assert_equal(ver.addrFrom.ip, '0.0.0.0')
+        assert_equal(ver.nStartingHeight, 201)
+        assert_equal(ver.nRelay, 1)
+
+        self.log.info('Check that old nodes are disconnected')
+        p2p_old_node = self.nodes[0].add_p2p_connection(P2PInterface(), send_version=False, wait_for_verack=False)
+        old_version_msg = msg_version()
+        old_version_msg.nVersion = 31799
+        with self.nodes[0].assert_debug_log(['peer=4 using obsolete version 31799; disconnecting']):
+            p2p_old_node.send_message(old_version_msg)
+            p2p_old_node.wait_for_disconnect()
 
 
 if __name__ == '__main__':

test/functional/test_runner.py

@@ -133,6 +133,7 @@
     'mining_v5_upgrade.py',                     # ~ 48 sec
     'p2p_mempool.py',                           # ~ 46 sec
     'rpc_named_arguments.py',                   # ~ 45 sec
+    'p2p_leak.py',
     'feature_filelock.py',
     'feature_help.py',                          # ~ 30 sec
 
@@ -144,7 +145,6 @@
     # 'mining_basic.py',
     # 'wallet_bumpfee.py',
     # 'wallet_listsinceblock.py',
-    # 'p2p_leak.py',
     # 'feature_cltv.py',
     # 'feature_minchainwork.py',
     # 'p2p_fingerprint.py',