1 #!/usr/bin/env python3
2 # Copyright (c) 2022-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 initial headers download and timeout behavior
6 7 Test that we only try to initially sync headers from one peer (until our chain
8 is close to caught up), and that each block announcement results in only one
9 additional peer receiving a getheaders message.
10 11 Also test peer timeout during initial headers sync, including normal peer
12 disconnection vs noban peer behavior.
13 """
14 15 from test_framework.test_framework import BitcoinTestFramework
16 from test_framework.messages import (
17 CInv,
18 MSG_BLOCK,
19 msg_headers,
20 msg_inv,
21 )
22 from test_framework.p2p import (
23 p2p_lock,
24 P2PInterface,
25 )
26 from test_framework.util import (
27 assert_equal,
28 )
29 import math
30 import random
31 import time
32 33 # Constants from net_processing
34 HEADERS_DOWNLOAD_TIMEOUT_BASE_SEC = 15 * 60
35 HEADERS_DOWNLOAD_TIMEOUT_PER_HEADER_MS = 1
36 POW_TARGET_SPACING_SEC = 10 * 60
37 38 39 def calculate_headers_timeout(best_header_time, current_time):
40 seconds_since_best_header = current_time - best_header_time
41 # Using ceil ensures the calculated timeout is >= actual timeout and not lower
42 # because of precision loss from conversion to seconds
43 variable_timeout_sec = math.ceil(HEADERS_DOWNLOAD_TIMEOUT_PER_HEADER_MS / 1_000 *
44 seconds_since_best_header / POW_TARGET_SPACING_SEC)
45 return int(current_time + HEADERS_DOWNLOAD_TIMEOUT_BASE_SEC + variable_timeout_sec)
46 47 48 class HeadersSyncTest(BitcoinTestFramework):
49 def set_test_params(self):
50 self.setup_clean_chain = True
51 self.num_nodes = 1
52 53 def announce_random_block(self, peers):
54 new_block_announcement = msg_inv(inv=[CInv(MSG_BLOCK, random.randrange(1<<256))])
55 for p in peers:
56 p.send_and_ping(new_block_announcement)
57 58 def assert_single_getheaders_recipient(self, peers):
59 count = 0
60 receiving_peer = None
61 for p in peers:
62 with p2p_lock:
63 if "getheaders" in p.last_message:
64 count += 1
65 receiving_peer = p
66 assert_equal(count, 1)
67 return receiving_peer
68 69 def test_initial_headers_sync(self):
70 self.log.info("Test initial headers sync")
71 72 self.log.info("Adding a peer to node0")
73 peer1 = self.nodes[0].add_p2p_connection(P2PInterface())
74 best_block_hash = int(self.nodes[0].getbestblockhash(), 16)
75 76 # Wait for peer1 to receive a getheaders
77 peer1.wait_for_getheaders(block_hash=best_block_hash)
78 # An empty reply will clear the outstanding getheaders request,
79 # allowing additional getheaders requests to be sent to this peer in
80 # the future.
81 peer1.send_without_ping(msg_headers())
82 83 self.log.info("Connecting two more peers to node0")
84 # Connect 2 more peers; they should not receive a getheaders yet
85 peer2 = self.nodes[0].add_p2p_connection(P2PInterface())
86 peer3 = self.nodes[0].add_p2p_connection(P2PInterface())
87 88 all_peers = [peer1, peer2, peer3]
89 90 self.log.info("Verify that peer2 and peer3 don't receive a getheaders after connecting")
91 for p in all_peers:
92 p.sync_with_ping()
93 with p2p_lock:
94 assert "getheaders" not in peer2.last_message
95 assert "getheaders" not in peer3.last_message
96 97 self.log.info("Have all peers announce a new block")
98 self.announce_random_block(all_peers)
99 100 self.log.info("Check that peer1 receives a getheaders in response")
101 peer1.wait_for_getheaders(block_hash=best_block_hash)
102 peer1.send_without_ping(msg_headers()) # Send empty response, see above
103 104 self.log.info("Check that exactly 1 of {peer2, peer3} received a getheaders in response")
105 peer_receiving_getheaders = self.assert_single_getheaders_recipient([peer2, peer3])
106 peer_receiving_getheaders.send_without_ping(msg_headers()) # Send empty response, see above
107 108 self.log.info("Announce another new block, from all peers")
109 self.announce_random_block(all_peers)
110 111 self.log.info("Check that peer1 receives a getheaders in response")
112 peer1.wait_for_getheaders(block_hash=best_block_hash)
113 114 self.log.info("Check that the remaining peer received a getheaders as well")
115 expected_peer = peer2
116 if peer2 == peer_receiving_getheaders:
117 expected_peer = peer3
118 119 expected_peer.wait_for_getheaders(block_hash=best_block_hash)
120 121 def setup_timeout_test_peers(self):
122 self.log.info("Add peer1 and check it receives an initial getheaders request")
123 node = self.nodes[0]
124 with node.assert_debug_log(expected_msgs=["initial getheaders (0) to peer=0"]):
125 peer1 = node.add_p2p_connection(P2PInterface())
126 peer1.wait_for_getheaders(block_hash=int(node.getbestblockhash(), 16))
127 128 self.log.info("Add outbound peer2")
129 # This peer has to be outbound otherwise the stalling peer is
130 # protected from disconnection
131 peer2 = node.add_outbound_p2p_connection(P2PInterface(), p2p_idx=1, connection_type="outbound-full-relay")
132 133 assert_equal(node.num_test_p2p_connections(), 2)
134 return peer1, peer2
135 136 def trigger_headers_timeout(self):
137 self.log.info("Trigger the headers download timeout by advancing mock time")
138 # The node has not received any headers from peers yet
139 # So the best header time is the genesis block time
140 best_header_time = self.nodes[0].getblockchaininfo()["time"]
141 current_time = self.nodes[0].mocktime
142 timeout = calculate_headers_timeout(best_header_time, current_time)
143 # The calculated timeout above is always >= actual timeout, but we still need
144 # +1 to trigger the timeout when both values are equal
145 self.nodes[0].setmocktime(timeout + 1)
146 147 def test_normal_peer_timeout(self):
148 self.log.info("Test peer disconnection on header timeout")
149 self.restart_node(0)
150 self.nodes[0].setmocktime(int(time.time()))
151 peer1, peer2 = self.setup_timeout_test_peers()
152 153 with self.nodes[0].assert_debug_log(["Timeout downloading headers, disconnecting peer=0"]):
154 self.trigger_headers_timeout()
155 156 self.log.info("Check that stalling peer1 is disconnected")
157 peer1.wait_for_disconnect()
158 assert_equal(self.nodes[0].num_test_p2p_connections(), 1)
159 160 self.log.info("Check that peer2 receives a getheaders request")
161 peer2.wait_for_getheaders(block_hash=int(self.nodes[0].getbestblockhash(), 16))
162 163 def test_noban_peer_timeout(self):
164 self.log.info("Test noban peer on header timeout")
165 self.restart_node(0, extra_args=['-whitelist=noban@127.0.0.1'])
166 self.nodes[0].setmocktime(int(time.time()))
167 peer1, peer2 = self.setup_timeout_test_peers()
168 169 with self.nodes[0].assert_debug_log(["Timeout downloading headers from noban peer, not disconnecting peer=0"]):
170 self.trigger_headers_timeout()
171 172 self.log.info("Check that noban peer1 is not disconnected")
173 peer1.sync_with_ping()
174 assert_equal(self.nodes[0].num_test_p2p_connections(), 2)
175 176 self.log.info("Check that exactly 1 of {peer1, peer2} receives a getheaders")
177 self.assert_single_getheaders_recipient([peer1, peer2])
178 179 def run_test(self):
180 self.test_initial_headers_sync()
181 self.test_normal_peer_timeout()
182 self.test_noban_peer_timeout()
183 184 185 if __name__ == '__main__':
186 HeadersSyncTest(__file__).main()
187