Merge #9715: Disconnect peers which we do not receive VERACKs from within 60 sec

66f861a Add a test for P2P inactivity timeouts (Matt Corallo)
b436f92 qa: Expose on-connection to mininode listeners (Matt Corallo)
8aaba7a qa: mininode learns when a socket connects, not its first action (Matt Corallo)
2cbd119 Disconnect peers which we do not receive VERACKs from within 60 sec (Matt Corallo)

Author: laanwj

qa/pull-tester/rpc-tests.py

@@ -168,6 +168,7 @@
     # vv Tests less than 2m vv
     'bip68-sequence.py',
     'getblocktemplate_longpoll.py',
+    'p2p-timeouts.py',
     # vv Tests less than 60s vv
     'bip9-softforks.py',
     'p2p-feefilter.py',

qa/rpc-tests/p2p-timeouts.py

@@ -0,0 +1,103 @@
+#!/usr/bin/env python3
+# Copyright (c) 2016 The Bitcoin Core developers
+# Distributed under the MIT software license, see the accompanying
+# file COPYING or http://www.opensource.org/licenses/mit-license.php.
+""" TimeoutsTest -- test various net timeouts (only in extended tests)
+
+- Create three bitcoind nodes:
+
+    no_verack_node - we never send a verack in response to their version
+    no_version_node - we never send a version (only a ping)
+    no_send_node - we never send any P2P message.
+
+- Start all three nodes
+- Wait 1 second
+- Assert that we're connected
+- Send a ping to no_verack_node and no_version_node
+- Wait 30 seconds
+- Assert that we're still connected
+- Send a ping to no_verack_node and no_version_node
+- Wait 31 seconds
+- Assert that we're no longer connected (timeout to receive version/verack is 60 seconds)
+"""
+
+from time import sleep
+
+from test_framework.mininode import *
+from test_framework.test_framework import BitcoinTestFramework
+from test_framework.util import *
+
+class TestNode(SingleNodeConnCB):
+    def __init__(self):
+        SingleNodeConnCB.__init__(self)
+        self.connected = False
+        self.received_version = False
+
+    def on_open(self, conn):
+        self.connected = True
+
+    def on_close(self, conn):
+        self.connected = False
+
+    def on_version(self, conn, message):
+        # Don't send a verack in response
+        self.received_version = True
+
+class TimeoutsTest(BitcoinTestFramework):
+    def __init__(self):
+        super().__init__()
+        self.setup_clean_chain = True
+        self.num_nodes = 1
+
+    def setup_network(self):
+        self.nodes = []
+
+        # Start up node0 to be a version 1, pre-segwit node.
+        self.nodes = start_nodes(self.num_nodes, self.options.tmpdir, 
+                [["-debug", "-logtimemicros=1"]])
+
+    def run_test(self):
+        # Setup the p2p connections and start up the network thread.
+        self.no_verack_node = TestNode() # never send verack
+        self.no_version_node = TestNode() # never send version (just ping)
+        self.no_send_node = TestNode() # never send anything
+
+        connections = []
+        connections.append(NodeConn('127.0.0.1', p2p_port(0), self.nodes[0], self.no_verack_node))
+        connections.append(NodeConn('127.0.0.1', p2p_port(0), self.nodes[0], self.no_version_node, send_version=False))
+        connections.append(NodeConn('127.0.0.1', p2p_port(0), self.nodes[0], self.no_send_node, send_version=False))
+        self.no_verack_node.add_connection(connections[0])
+        self.no_version_node.add_connection(connections[1])
+        self.no_send_node.add_connection(connections[2])
+
+        NetworkThread().start()  # Start up network handling in another thread
+
+        sleep(1)
+
+        assert(self.no_verack_node.connected)
+        assert(self.no_version_node.connected)
+        assert(self.no_send_node.connected)
+
+        ping_msg = msg_ping()
+        connections[0].send_message(ping_msg)
+        connections[1].send_message(ping_msg)
+
+        sleep(30)
+
+        assert(self.no_verack_node.received_version)
+
+        assert(self.no_verack_node.connected)
+        assert(self.no_version_node.connected)
+        assert(self.no_send_node.connected)
+
+        connections[0].send_message(ping_msg)
+        connections[1].send_message(ping_msg)
+
+        sleep(31)
+
+        assert(not self.no_verack_node.connected)
+        assert(not self.no_version_node.connected)
+        assert(not self.no_send_node.connected)
+
+if __name__ == '__main__':
+    TimeoutsTest().main()

qa/rpc-tests/test_framework/mininode.py

@@ -1540,6 +1540,7 @@ def on_ping(self, conn, message):
         if conn.ver_send > BIP0031_VERSION:
             conn.send_message(msg_pong(message.nonce))
     def on_reject(self, conn, message): pass
+    def on_open(self, conn): pass
     def on_close(self, conn): pass
     def on_mempool(self, conn): pass
     def on_pong(self, conn, message): pass
@@ -1614,7 +1615,7 @@ class NodeConn(asyncore.dispatcher):
         "regtest": b"\xfa\xbf\xb5\xda",   # regtest
     }
 
-    def __init__(self, dstaddr, dstport, rpc, callback, net="regtest", services=NODE_NETWORK):
+    def __init__(self, dstaddr, dstport, rpc, callback, net="regtest", services=NODE_NETWORK, send_version=True):
         asyncore.dispatcher.__init__(self, map=mininode_socket_map)
         self.log = logging.getLogger("NodeConn(%s:%d)" % (dstaddr, dstport))
         self.dstaddr = dstaddr
@@ -1631,14 +1632,16 @@ def __init__(self, dstaddr, dstport, rpc, callback, net="regtest", services=NODE
         self.disconnect = False
         self.nServices = 0
 
-        # stuff version msg into sendbuf
-        vt = msg_version()
-        vt.nServices = services
-        vt.addrTo.ip = self.dstaddr
-        vt.addrTo.port = self.dstport
-        vt.addrFrom.ip = "0.0.0.0"
-        vt.addrFrom.port = 0
-        self.send_message(vt, True)
+        if send_version:
+            # stuff version msg into sendbuf
+            vt = msg_version()
+            vt.nServices = services
+            vt.addrTo.ip = self.dstaddr
+            vt.addrTo.port = self.dstport
+            vt.addrFrom.ip = "0.0.0.0"
+            vt.addrFrom.port = 0
+            self.send_message(vt, True)
+
         print('MiniNode: Connecting to Bitcoin Node IP # ' + dstaddr + ':' \
             + str(dstport))
 
@@ -1652,8 +1655,10 @@ def show_debug_msg(self, msg):
         self.log.debug(msg)
 
     def handle_connect(self):
-        self.show_debug_msg("MiniNode: Connected & Listening: \n")
-        self.state = "connected"
+        if self.state != "connected":
+            self.show_debug_msg("MiniNode: Connected & Listening: \n")
+            self.state = "connected"
+            self.cb.on_open(self)
 
     def handle_close(self):
         self.show_debug_msg("MiniNode: Closing Connection to %s:%d... "
@@ -1681,11 +1686,20 @@ def readable(self):
 
     def writable(self):
         with mininode_lock:
+            pre_connection = self.state == "connecting"
             length = len(self.sendbuf)
-        return (length > 0)
+        return (length > 0 or pre_connection)
 
     def handle_write(self):
         with mininode_lock:
+            # asyncore does not expose socket connection, only the first read/write
+            # event, thus we must check connection manually here to know when we
+            # actually connect
+            if self.state == "connecting":
+                self.handle_connect()
+            if not self.writable():
+                return
+
             try:
                 sent = self.send(self.sendbuf)
             except:

src/net.cpp

@@ -1388,6 +1388,11 @@ void CConnman::ThreadSocketHandler()
                     LogPrintf("ping timeout: %fs\n", 0.000001 * (GetTimeMicros() - pnode->nPingUsecStart));
                     pnode->fDisconnect = true;
                 }
+                else if (!pnode->fSuccessfullyConnected)
+                {
+                    LogPrintf("version handshake timeout from %d\n", pnode->id);
+                    pnode->fDisconnect = true;
+                }
             }
         }
         {