From a8d9a0edc7cef2c31a557ef53eb45520976b0d65 Mon Sep 17 00:00:00 2001 From: Sergi Delgado Segura Date: Wed, 20 Dec 2023 10:53:49 -0500 Subject: [PATCH] test: adds outbound eviction functional tests, updates comment in ConsiderEviction --- src/net_processing.cpp | 11 +- test/functional/p2p_outbound_eviction.py | 224 +++++++++++++++++++++++ test/functional/test_runner.py | 1 + 3 files changed, 232 insertions(+), 4 deletions(-) create mode 100755 test/functional/p2p_outbound_eviction.py diff --git a/src/net_processing.cpp b/src/net_processing.cpp index 39ffff97d2b..f936f1b666c 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -5165,16 +5165,19 @@ void PeerManagerImpl::ConsiderEviction(CNode& pto, Peer& peer, std::chrono::seco // unless it's invalid, in which case we should find that out and // disconnect from them elsewhere). if (state.pindexBestKnownBlock != nullptr && state.pindexBestKnownBlock->nChainWork >= m_chainman.ActiveChain().Tip()->nChainWork) { + // The outbound peer has sent us a block with at least as much work as our current tip, so reset the timeout if it was set if (state.m_chain_sync.m_timeout != 0s) { state.m_chain_sync.m_timeout = 0s; state.m_chain_sync.m_work_header = nullptr; state.m_chain_sync.m_sent_getheaders = false; } } else if (state.m_chain_sync.m_timeout == 0s || (state.m_chain_sync.m_work_header != nullptr && state.pindexBestKnownBlock != nullptr && state.pindexBestKnownBlock->nChainWork >= state.m_chain_sync.m_work_header->nChainWork)) { - // Our best block known by this peer is behind our tip, and we're either noticing - // that for the first time, OR this peer was able to catch up to some earlier point - // where we checked against our tip. - // Either way, set a new timeout based on current tip. + // At this point we know that the outbound peer has either never sent us a block/header or they have, but its tip is behind ours + // AND + // we are noticing this for the first time (m_timeout is 0) + // OR we noticed this at some point within the last CHAIN_SYNC_TIMEOUT + HEADERS_RESPONSE_TIME seconds and set a timeout + // for them, they caught up to our tip at the time of setting the timer but not to our current one (we've also advanced). + // Either way, set a new timeout based on our current tip. state.m_chain_sync.m_timeout = time_in_seconds + CHAIN_SYNC_TIMEOUT; state.m_chain_sync.m_work_header = m_chainman.ActiveChain().Tip(); state.m_chain_sync.m_sent_getheaders = false; diff --git a/test/functional/p2p_outbound_eviction.py b/test/functional/p2p_outbound_eviction.py new file mode 100755 index 00000000000..43dec4df83a --- /dev/null +++ b/test/functional/p2p_outbound_eviction.py @@ -0,0 +1,224 @@ +#!/usr/bin/env python3 +# Copyright (c) 2019-2021 The Bitcoin Core developers +# Distributed under the MIT software license, see the accompanying +# file COPYING or http://www.opensource.org/licenses/mit-license.php. + +""" Test node outbound peer eviction logic + +A subset of our outbound peers are subject to eviction logic if they cannot keep up +with our vision of the best chain. This criteria applies only to non-protected peers, +and can be triggered by either not learning about any blocks from an outbound peer after +a certain deadline, or by them not being able to catch up fast enough (under the same deadline). + +This tests the different eviction paths based on the peer's behavior and on whether they are protected +or not. +""" +import time + +from test_framework.messages import ( + from_hex, + msg_headers, + CBlockHeader, +) +from test_framework.p2p import P2PInterface +from test_framework.test_framework import BitcoinTestFramework + +# Timeouts (in seconds) +CHAIN_SYNC_TIMEOUT = 20 * 60 +HEADERS_RESPONSE_TIME = 2 * 60 + + +class P2POutEvict(BitcoinTestFramework): + def set_test_params(self): + self.num_nodes = 1 + + def test_outbound_eviction_unprotected(self): + # This tests the eviction logic for **unprotected** outbound peers (that is, PeerManagerImpl::ConsiderEviction) + node = self.nodes[0] + cur_mock_time = node.mocktime + + # Get our tip header and its parent + tip_header = from_hex(CBlockHeader(), node.getblockheader(node.getbestblockhash(), False)) + prev_header = from_hex(CBlockHeader(), node.getblockheader(f"{tip_header.hashPrevBlock:064x}", False)) + + self.log.info("Create an outbound connection and don't send any headers") + # Test disconnect due to no block being announced in 22+ minutes (headers are not even exchanged) + peer = node.add_outbound_p2p_connection(P2PInterface(), p2p_idx=0, connection_type="outbound-full-relay") + # Wait for over 20 min to trigger the first eviction timeout. This sets the last call past 2 min in the future. + cur_mock_time += (CHAIN_SYNC_TIMEOUT + 1) + node.setmocktime(cur_mock_time) + peer.sync_with_ping() + # Wait for over 2 more min to trigger the disconnection + peer.wait_for_getheaders(block_hash=tip_header.hashPrevBlock) + cur_mock_time += (HEADERS_RESPONSE_TIME + 1) + node.setmocktime(cur_mock_time) + self.log.info("Test that the peer gets evicted") + peer.wait_for_disconnect() + + self.log.info("Create an outbound connection and send header but never catch up") + # Mimic a node that just falls behind for long enough + # This should also apply for a node doing IBD that does not catch up in time + # Connect a peer and make it send us headers ending in our tip's parent + peer = node.add_outbound_p2p_connection(P2PInterface(), p2p_idx=0, connection_type="outbound-full-relay") + peer.send_and_ping(msg_headers([prev_header])) + + # Trigger the timeouts + cur_mock_time += (CHAIN_SYNC_TIMEOUT + 1) + node.setmocktime(cur_mock_time) + peer.sync_with_ping() + peer.wait_for_getheaders(block_hash=tip_header.hashPrevBlock) + cur_mock_time += (HEADERS_RESPONSE_TIME + 1) + node.setmocktime(cur_mock_time) + self.log.info("Test that the peer gets evicted") + peer.wait_for_disconnect() + + self.log.info("Create an outbound connection and keep lagging behind, but not too much") + # Test that if the peer never catches up with our current tip, but it does with the + # expected work that we set when setting the timer (that is, our tip at the time) + # we do not disconnect the peer + peer = node.add_outbound_p2p_connection(P2PInterface(), p2p_idx=0, connection_type="outbound-full-relay") + + self.log.info("Mine a block so our peer starts lagging") + prev_prev_hash = tip_header.hashPrevBlock + best_block_hash = self.generateblock(node, output="raw(42)", transactions=[])["hash"] + peer.sync_with_ping() + + self.log.info("Keep catching up with the old tip and check that we are not evicted") + for i in range(10): + # Generate an additional block so the peers is 2 blocks behind + prev_header = from_hex(CBlockHeader(), node.getblockheader(best_block_hash, False)) + best_block_hash = self.generateblock(node, output="raw(42)", transactions=[])["hash"] + peer.sync_with_ping() + + # Advance time but not enough to evict the peer + cur_mock_time += (CHAIN_SYNC_TIMEOUT + 1) + node.setmocktime(cur_mock_time) + peer.sync_with_ping() + + # Wait until we get out last call (by receiving a getheaders) + peer.wait_for_getheaders(block_hash=prev_prev_hash) + + # Send a header with the previous tip (so we go back to 1 block behind) + peer.send_and_ping(msg_headers([prev_header])) + prev_prev_hash = tip_header.hash + + self.log.info("Create an outbound connection and take some time to catch up, but do it in time") + # Check that if the peer manages to catch up within time, the timeouts are removed (and the peer is not disconnected) + # We are reusing the peer from the previous case which already sent us a valid (but old) block and whose timer is ticking + + # Send an updated headers message matching our tip + peer.send_and_ping(msg_headers([from_hex(CBlockHeader(), node.getblockheader(best_block_hash, False))])) + + # Wait for long enough for the timeouts to have triggered and check that we are still connected + cur_mock_time += (CHAIN_SYNC_TIMEOUT + 1) + node.setmocktime(cur_mock_time) + peer.sync_with_ping() + cur_mock_time += (HEADERS_RESPONSE_TIME + 1) + node.setmocktime(cur_mock_time) + self.log.info("Test that the peer does not get evicted") + peer.sync_with_ping() + + node.disconnect_p2ps() + + def test_outbound_eviction_protected(self): + # This tests the eviction logic for **protected** outbound peers (that is, PeerManagerImpl::ConsiderEviction) + # Outbound connections are flagged as protected as long as they have sent us a connecting block with at least as + # much work as our current tip and we have enough empty protected_peers slots. + node = self.nodes[0] + cur_mock_time = node.mocktime + tip_header = from_hex(CBlockHeader(), node.getblockheader(node.getbestblockhash(), False)) + + self.log.info("Create an outbound connection to a peer that shares our tip so it gets granted protection") + peer = node.add_outbound_p2p_connection(P2PInterface(), p2p_idx=0, connection_type="outbound-full-relay") + peer.send_and_ping(msg_headers([tip_header])) + + self.log.info("Mine a new block and sync with our peer") + self.generateblock(node, output="raw(42)", transactions=[]) + peer.sync_with_ping() + + self.log.info("Let enough time pass for the timeouts to go off") + # Trigger the timeouts and check how we are still connected + cur_mock_time += (CHAIN_SYNC_TIMEOUT + 1) + node.setmocktime(cur_mock_time) + peer.sync_with_ping() + peer.wait_for_getheaders(block_hash=tip_header.hashPrevBlock) + cur_mock_time += (HEADERS_RESPONSE_TIME + 1) + node.setmocktime(cur_mock_time) + self.log.info("Test that the node does not get evicted") + peer.sync_with_ping() + + node.disconnect_p2ps() + + def test_outbound_eviction_mixed(self): + # This tests the outbound eviction logic for a mix of protected and unprotected peers. + node = self.nodes[0] + cur_mock_time = node.mocktime + + self.log.info("Create a mix of protected and unprotected outbound connections to check against eviction") + + # Let's try this logic having multiple peers, some protected and some unprotected + # We protect up to 4 peers as long as they have provided a block with the same amount of work as our tip + self.log.info("The first 4 peers are protected by sending us a valid block with enough work") + tip_header = from_hex(CBlockHeader(), node.getblockheader(node.getbestblockhash(), False)) + headers_message = msg_headers([tip_header]) + protected_peers = [] + for i in range(4): + peer = node.add_outbound_p2p_connection(P2PInterface(), p2p_idx=i, connection_type="outbound-full-relay") + peer.send_and_ping(headers_message) + protected_peers.append(peer) + + # We can create 4 additional outbound connections to peers that are unprotected. 2 of them will be well behaved, + # whereas the other 2 will misbehave (1 sending no headers, 1 sending old ones) + self.log.info("The remaining 4 peers will be mixed between honest (2) and misbehaving peers (2)") + prev_header = from_hex(CBlockHeader(), node.getblockheader(f"{tip_header.hashPrevBlock:064x}", False)) + headers_message = msg_headers([prev_header]) + honest_unprotected_peers = [] + for i in range(2): + peer = node.add_outbound_p2p_connection(P2PInterface(), p2p_idx=4+i, connection_type="outbound-full-relay") + peer.send_and_ping(headers_message) + honest_unprotected_peers.append(peer) + + misbehaving_unprotected_peers = [] + for i in range(2): + peer = node.add_outbound_p2p_connection(P2PInterface(), p2p_idx=6+i, connection_type="outbound-full-relay") + if i%2==0: + peer.send_and_ping(headers_message) + misbehaving_unprotected_peers.append(peer) + + self.log.info("Mine a new block and keep the unprotected honest peer on sync, all the rest off-sync") + # Mine a block so all peers become outdated + target_hash = prev_header.rehash() + tip_hash = self.generateblock(node, output="raw(42)", transactions=[])["hash"] + tip_header = from_hex(CBlockHeader(), node.getblockheader(tip_hash, False)) + tip_headers_message = msg_headers([tip_header]) + + # Let the timeouts hit and check back + cur_mock_time += (CHAIN_SYNC_TIMEOUT + 1) + node.setmocktime(cur_mock_time) + for peer in protected_peers + misbehaving_unprotected_peers: + peer.sync_with_ping() + peer.wait_for_getheaders(block_hash=target_hash) + for peer in honest_unprotected_peers: + peer.send_and_ping(tip_headers_message) + peer.wait_for_getheaders(block_hash=target_hash) + + cur_mock_time += (HEADERS_RESPONSE_TIME + 1) + node.setmocktime(cur_mock_time) + self.log.info("Check how none of the honest nor protected peers was evicted but all the misbehaving unprotected were") + for peer in protected_peers + honest_unprotected_peers: + peer.sync_with_ping() + for peer in misbehaving_unprotected_peers: + peer.wait_for_disconnect() + + node.disconnect_p2ps() + + + def run_test(self): + self.nodes[0].setmocktime(int(time.time())) + self.test_outbound_eviction_unprotected() + self.test_outbound_eviction_protected() + self.test_outbound_eviction_mixed() + + +if __name__ == '__main__': + P2POutEvict().main() diff --git a/test/functional/test_runner.py b/test/functional/test_runner.py index 32b55813a8c..ec9096f9291 100755 --- a/test/functional/test_runner.py +++ b/test/functional/test_runner.py @@ -292,6 +292,7 @@ BASE_SCRIPTS = [ 'p2p_leak_tx.py --v1transport', 'p2p_leak_tx.py --v2transport', 'p2p_eviction.py', + 'p2p_outbound_eviction.py', 'p2p_ibd_stalling.py --v1transport', 'p2p_ibd_stalling.py --v2transport', 'p2p_net_deadlock.py --v1transport',