p2p_ping.py raw

   1  #!/usr/bin/env python3
   2  # Copyright (c) 2020-present The Bitcoin Core developers
   3  # Distributed under the MIT software license, see the accompanying
   4  # file COPYING or http://www.opensource.org/licenses/mit-license.php.
   5  """Test ping message
   6  """
   7  
   8  import time
   9  
  10  from test_framework.messages import (
  11      msg_pong,
  12      msg_generic,
  13  )
  14  from test_framework.p2p import P2PInterface
  15  from test_framework.test_framework import BitcoinTestFramework
  16  from test_framework.util import (
  17      assert_equal,
  18      assert_not_equal,
  19  )
  20  
  21  
  22  PING_INTERVAL = 2 * 60
  23  TIMEOUT_INTERVAL = 20 * 60
  24  
  25  
  26  class NodeNoPong(P2PInterface):
  27      def on_ping(self, message):
  28          pass
  29  
  30  
  31  class PingPongTest(BitcoinTestFramework):
  32      def set_test_params(self):
  33          self.setup_clean_chain = True
  34          self.num_nodes = 1
  35          # Set the peer connection timeout low. It does not matter for this
  36          # test, as long as it is less than TIMEOUT_INTERVAL.
  37          self.extra_args = [['-peertimeout=1']]
  38  
  39      def check_peer_info(self, *, pingtime, minping, pingwait):
  40          stats = self.nodes[0].getpeerinfo()[0]
  41          assert_equal(stats.pop('pingtime', None), pingtime)
  42          assert_equal(stats.pop('minping', None), minping)
  43          assert_equal(stats.pop('pingwait', None), pingwait)
  44  
  45      def mock_forward(self, delta):
  46          self.mock_time += delta
  47          self.nodes[0].setmocktime(self.mock_time)
  48  
  49      def run_test(self):
  50          self.mock_time = int(time.time())
  51          self.mock_forward(0)
  52  
  53          self.log.info('Check that ping is sent after connection is established')
  54          no_pong_node = self.nodes[0].add_p2p_connection(NodeNoPong())
  55          self.mock_forward(3)
  56          assert_not_equal(no_pong_node.last_message.pop('ping').nonce, 0)
  57          self.check_peer_info(pingtime=None, minping=None, pingwait=3)
  58  
  59          self.log.info('Reply without nonce cancels ping')
  60          with self.nodes[0].assert_debug_log(['pong peer=0: Short payload']):
  61              no_pong_node.send_and_ping(msg_generic(b"pong", b""))
  62          self.check_peer_info(pingtime=None, minping=None, pingwait=None)
  63  
  64          self.log.info('Reply without ping')
  65          with self.nodes[0].assert_debug_log([
  66                  'pong peer=0: Unsolicited pong without ping, 0 expected, 0 received, 8 bytes',
  67          ]):
  68              no_pong_node.send_and_ping(msg_pong())
  69          self.check_peer_info(pingtime=None, minping=None, pingwait=None)
  70  
  71          self.log.info('Reply with wrong nonce does not cancel ping')
  72          assert 'ping' not in no_pong_node.last_message
  73          with self.nodes[0].assert_debug_log(['pong peer=0: Nonce mismatch']):
  74              # mock time PING_INTERVAL ahead to trigger node into sending a ping
  75              self.mock_forward(PING_INTERVAL + 1)
  76              no_pong_node.wait_until(lambda: 'ping' in no_pong_node.last_message)
  77              self.mock_forward(9)
  78              # Send the wrong pong
  79              no_pong_node.send_and_ping(msg_pong(no_pong_node.last_message.pop('ping').nonce - 1))
  80          self.check_peer_info(pingtime=None, minping=None, pingwait=9)
  81  
  82          self.log.info('Reply with zero nonce does cancel ping')
  83          with self.nodes[0].assert_debug_log(['pong peer=0: Nonce zero']):
  84              no_pong_node.send_and_ping(msg_pong(0))
  85          self.check_peer_info(pingtime=None, minping=None, pingwait=None)
  86  
  87          self.log.info('Check that ping is properly reported on RPC')
  88          assert 'ping' not in no_pong_node.last_message
  89          # mock time PING_INTERVAL ahead to trigger node into sending a ping
  90          self.mock_forward(PING_INTERVAL + 1)
  91          no_pong_node.wait_until(lambda: 'ping' in no_pong_node.last_message)
  92          ping_delay = 29
  93          self.mock_forward(ping_delay)
  94          no_pong_node.wait_until(lambda: 'ping' in no_pong_node.last_message)
  95          no_pong_node.send_and_ping(msg_pong(no_pong_node.last_message.pop('ping').nonce))
  96          self.check_peer_info(pingtime=ping_delay, minping=ping_delay, pingwait=None)
  97  
  98          self.log.info('Check that minping is decreased after a fast roundtrip')
  99          # mock time PING_INTERVAL ahead to trigger node into sending a ping
 100          self.mock_forward(PING_INTERVAL + 1)
 101          no_pong_node.wait_until(lambda: 'ping' in no_pong_node.last_message)
 102          ping_delay = 9
 103          self.mock_forward(ping_delay)
 104          no_pong_node.wait_until(lambda: 'ping' in no_pong_node.last_message)
 105          no_pong_node.send_and_ping(msg_pong(no_pong_node.last_message.pop('ping').nonce))
 106          self.check_peer_info(pingtime=ping_delay, minping=ping_delay, pingwait=None)
 107  
 108          self.log.info('Check that peer is disconnected after ping timeout')
 109          assert 'ping' not in no_pong_node.last_message
 110          self.nodes[0].ping()
 111          no_pong_node.wait_until(lambda: 'ping' in no_pong_node.last_message)
 112          with self.nodes[0].assert_debug_log(['ping timeout: 1201.000000s']):
 113              self.mock_forward(TIMEOUT_INTERVAL // 2)
 114              # Check that sending a ping does not prevent the disconnect
 115              no_pong_node.sync_with_ping()
 116              self.mock_forward(TIMEOUT_INTERVAL // 2 + 1)
 117              no_pong_node.wait_for_disconnect()
 118  
 119  
 120  if __name__ == '__main__':
 121      PingPongTest(__file__).main()
 122