This commit is contained in:
Larry Ruane 2024-04-29 04:32:57 +02:00 committed by GitHub
commit 86c2c3a47e
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
8 changed files with 113 additions and 11 deletions

View File

@ -0,0 +1,8 @@
JSON-RPC
--------
The `getpeerinfo` RPC now returns an additional result field,
`last_block_announcement`, which indicates the most recent time
this peer was the first to announce a new block to the local node.
This timestamp, previously internal only, is used by the stale-tip
eviction logic.

View File

@ -471,7 +471,7 @@ struct CNodeState {
ChainSyncTimeoutState m_chain_sync;
//! Time of last new block announcement
int64_t m_last_block_announcement{0};
NodeSeconds m_last_block_announcement{0s};
//! Whether this peer is an inbound connection
const bool m_is_inbound;
@ -525,8 +525,8 @@ public:
void ProcessMessage(CNode& pfrom, const std::string& msg_type, DataStream& vRecv,
const std::chrono::microseconds time_received, const std::atomic<bool>& interruptMsgProc) override
EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex, !m_recent_confirmed_transactions_mutex, !m_most_recent_block_mutex, !m_headers_presync_mutex, g_msgproc_mutex);
void UpdateLastBlockAnnounceTime(NodeId node, int64_t time_in_seconds) override;
ServiceFlags GetDesirableServiceFlags(ServiceFlags services) const override;
void UpdateLastBlockAnnounceTime(NodeId node, NodeSeconds time_in_seconds) override;
private:
/** Consider evicting an outbound peer based on the amount of time they've been behind our tip */
@ -1587,7 +1587,7 @@ void PeerManagerImpl::AddTxAnnouncement(const CNode& node, const GenTxid& gtxid,
m_txrequest.ReceivedInv(nodeid, gtxid, preferred, current_time + delay);
}
void PeerManagerImpl::UpdateLastBlockAnnounceTime(NodeId node, int64_t time_in_seconds)
void PeerManagerImpl::UpdateLastBlockAnnounceTime(NodeId node, NodeSeconds time_in_seconds)
{
LOCK(cs_main);
CNodeState *state = State(node);
@ -1757,6 +1757,7 @@ bool PeerManagerImpl::GetNodeStateStats(NodeId nodeid, CNodeStateStats& stats) c
if (queue.pindex)
stats.vHeightInFlight.push_back(queue.pindex->nHeight);
}
stats.m_last_block_announcement = state->m_last_block_announcement;
}
PeerRef peer = GetPeerRef(nodeid);
@ -2884,7 +2885,7 @@ void PeerManagerImpl::UpdatePeerStateForReceivedHeaders(CNode& pfrom, Peer& peer
// are still present, however, as belt-and-suspenders.
if (received_new_header && last_header.nChainWork > m_chainman.ActiveChain().Tip()->nChainWork) {
nodestate->m_last_block_announcement = GetTime();
nodestate->m_last_block_announcement = Now<NodeSeconds>();
}
// If we're in IBD, we want outbound peers that will serve us a useful
@ -4494,7 +4495,7 @@ void PeerManagerImpl::ProcessMessage(CNode& pfrom, const std::string& msg_type,
// If this was a new header with more work than our tip, update the
// peer's last block announcement time
if (received_new_header && pindex->nChainWork > m_chainman.ActiveChain().Tip()->nChainWork) {
nodestate->m_last_block_announcement = GetTime();
nodestate->m_last_block_announcement = Now<NodeSeconds>();
}
if (pindex->nStatus & BLOCK_HAVE_DATA) // Nothing to do here
@ -5264,7 +5265,7 @@ void PeerManagerImpl::EvictExtraOutboundPeers(std::chrono::seconds now)
// Protect peers from eviction if we don't have another connection
// to their network, counting both outbound-full-relay and manual peers.
NodeId worst_peer = -1;
int64_t oldest_block_announcement = std::numeric_limits<int64_t>::max();
std::optional<NodeSeconds> oldest_block_announcement;
m_connman.ForEachNode([&](CNode* pnode) EXCLUSIVE_LOCKS_REQUIRED(::cs_main, m_connman.GetNodesMutex()) {
AssertLockHeld(::cs_main);
@ -5279,7 +5280,10 @@ void PeerManagerImpl::EvictExtraOutboundPeers(std::chrono::seconds now)
// If this is the only connection on a particular network that is
// OUTBOUND_FULL_RELAY or MANUAL, protect it.
if (!m_connman.MultipleManualOrFullOutboundConns(pnode->addr.GetNetwork())) return;
if (state->m_last_block_announcement < oldest_block_announcement || (state->m_last_block_announcement == oldest_block_announcement && pnode->GetId() > worst_peer)) {
if (!oldest_block_announcement.has_value() ||
(state->m_last_block_announcement < *oldest_block_announcement) ||
((state->m_last_block_announcement == *oldest_block_announcement) && pnode->GetId() > worst_peer))
{
worst_peer = pnode->GetId();
oldest_block_announcement = state->m_last_block_announcement;
}
@ -5295,7 +5299,8 @@ void PeerManagerImpl::EvictExtraOutboundPeers(std::chrono::seconds now)
// block from.
CNodeState &state = *State(pnode->GetId());
if (now - pnode->m_connected > MINIMUM_CONNECT_TIME && state.vBlocksInFlight.empty()) {
LogPrint(BCLog::NET, "disconnecting extra outbound peer=%d (last block announcement received at time %d)\n", pnode->GetId(), oldest_block_announcement);
LogPrint(BCLog::NET, "disconnecting extra outbound peer=%d (last block announcement received at time %d)\n",
pnode->GetId(), TicksSinceEpoch<std::chrono::seconds>(*oldest_block_announcement));
pnode->fDisconnect = true;
return true;
} else {

View File

@ -41,6 +41,7 @@ struct CNodeStateStats {
bool m_addr_relay_enabled{false};
ServiceFlags their_services;
int64_t presync_height{-1};
NodeSeconds m_last_block_announcement;
};
class PeerManager : public CValidationInterface, public NetEventsInterface
@ -109,7 +110,7 @@ public:
const std::chrono::microseconds time_received, const std::atomic<bool>& interruptMsgProc) EXCLUSIVE_LOCKS_REQUIRED(g_msgproc_mutex) = 0;
/** This function is used for testing the stale tip eviction logic, see denialofservice_tests.cpp */
virtual void UpdateLastBlockAnnounceTime(NodeId node, int64_t time_in_seconds) = 0;
virtual void UpdateLastBlockAnnounceTime(NodeId node, NodeSeconds time_in_seconds) = 0;
/**
* Gets the set of service flags which are "desirable" for a given peer.

View File

@ -140,6 +140,7 @@ static RPCHelpMan getpeerinfo()
{RPCResult::Type::NUM_TIME, "lastrecv", "The " + UNIX_EPOCH_TIME + " of the last receive"},
{RPCResult::Type::NUM_TIME, "last_transaction", "The " + UNIX_EPOCH_TIME + " of the last valid transaction received from this peer"},
{RPCResult::Type::NUM_TIME, "last_block", "The " + UNIX_EPOCH_TIME + " of the last block received from this peer"},
{RPCResult::Type::NUM_TIME, "last_block_announcement", "The " + UNIX_EPOCH_TIME + " this peer was first to announce a block"},
{RPCResult::Type::NUM, "bytessent", "The total bytes sent"},
{RPCResult::Type::NUM, "bytesrecv", "The total bytes received"},
{RPCResult::Type::NUM_TIME, "conntime", "The " + UNIX_EPOCH_TIME + " of the connection"},
@ -236,6 +237,7 @@ static RPCHelpMan getpeerinfo()
obj.pushKV("lastrecv", count_seconds(stats.m_last_recv));
obj.pushKV("last_transaction", count_seconds(stats.m_last_tx_time));
obj.pushKV("last_block", count_seconds(stats.m_last_block_time));
obj.pushKV("last_block_announcement", TicksSinceEpoch<std::chrono::seconds>(statestats.m_last_block_announcement));
obj.pushKV("bytessent", stats.nSendBytes);
obj.pushKV("bytesrecv", stats.nRecvBytes);
obj.pushKV("conntime", count_seconds(stats.m_connected));

View File

@ -197,7 +197,7 @@ BOOST_AUTO_TEST_CASE(stale_tip_peer_management)
// Update the last announced block time for the last
// peer, and check that the next newest node gets evicted.
peerLogic->UpdateLastBlockAnnounceTime(vNodes.back()->GetId(), GetTime());
peerLogic->UpdateLastBlockAnnounceTime(vNodes.back()->GetId(), Now<NodeSeconds>());
peerLogic->CheckForStaleTipAndEvictPeers();
for (int i = 0; i < max_outbound_full_relay - 1; ++i) {

View File

@ -0,0 +1,83 @@
#!/usr/bin/env python3
# Copyright (c) 2023 The Bitcoin Core developers
# Distributed under the MIT software license, see the accompanying
# file COPYING or https://www.opensource.org/licenses/mit-license.php.
""" Test block announcement time tracking
The bitcoind client records, for each peer, the most recent time that
this peer announced a block that the client wasn't already aware of. This
timestamp, CNodeStateStats::m_last_block_announcement, is available in the
`last_block_announcement` field of each peer's `getpeerinfo` result. The
value zero means that this peer has never been the first to announce
a block to us. Blocks are announced using either the "headers" or
"cmpctblock" messages.
This timestamp is used when the "potential stale tip" condition occurs:
When a new block hasn't been seen for a longer-than-expected amount of
time (currently 30 minutes, see TipMayBeStale()), the client, suspecting
that there may be new blocks that its peers are not announcing, will
add an extra outbound peer and disconnect (evict) the peer that has
least recently been the first to announced a new block to us. (If there
is a tie, it will disconnect the most recently-added of those peers.)
This test verifies that this timestamp is being set correctly.
(This tests PR 26172.)
"""
import time
from test_framework.blocktools import (
create_block,
create_coinbase,
)
from test_framework.messages import (
CBlockHeader,
msg_headers,
)
from test_framework.p2p import P2PDataStore
from test_framework.test_framework import BitcoinTestFramework
class P2PBlockTimes(BitcoinTestFramework):
def set_test_params(self):
self.setup_clean_chain = True
self.num_nodes = 1
self.disable_autoconnect = False
def run_test(self):
node = self.nodes[0]
cur_time = int(time.time())
node.setmocktime(cur_time)
# Generate one block to exit IBD
self.generate(node, 1)
self.log.info("Create a full-outbound test framework peer")
node.add_outbound_p2p_connection(P2PDataStore(), p2p_idx=0)
self.log.info("Test framework peer generates a new block")
tip = int(node.getbestblockhash(), 16)
block = create_block(tip, create_coinbase(2))
block.solve()
self.log.info("Test framework peer sends node the new block")
node.p2ps[0].send_blocks_and_test([block], node, success=True)
self.log.info("Verify peerinfo block timestamps")
peerinfo = node.getpeerinfo()[0]
assert peerinfo['last_block'] == cur_time
assert peerinfo['last_block_announcement'] == cur_time
self.log.info("Sending a block announcement with no new blocks")
node.setmocktime(cur_time+1)
headers_message = msg_headers()
headers_message.headers = [CBlockHeader(block)]
node.p2ps[0].send_message(headers_message)
node.p2ps[0].sync_with_ping()
self.log.info("Verify that block announcement time isn't updated")
peerinfo = node.getpeerinfo()[0]
assert peerinfo['last_block_announcement'] == cur_time
if __name__ == '__main__':
P2PBlockTimes().main()

View File

@ -101,7 +101,8 @@ class NetTest(BitcoinTestFramework):
time_now = int(time.time())
peer_info = [x.getpeerinfo() for x in self.nodes]
# Verify last_block and last_transaction keys/values.
for node, peer, field in product(range(self.num_nodes), range(2), ['last_block', 'last_transaction']):
for node, peer, field in product(range(self.num_nodes), range(2),
['last_block', 'last_block_announcement', 'last_transaction']):
assert field in peer_info[node][peer].keys()
if peer_info[node][peer][field] != 0:
assert_approx(peer_info[node][peer][field], time_now, vspan=60)
@ -155,6 +156,7 @@ class NetTest(BitcoinTestFramework):
"inbound": True,
"inflight": [],
"last_block": 0,
"last_block_announcement": 0,
"last_transaction": 0,
"lastrecv": 0 if not self.options.v2transport else no_version_peer_conntime,
"lastsend": 0 if not self.options.v2transport else no_version_peer_conntime,

View File

@ -189,6 +189,7 @@ BASE_SCRIPTS = [
'mempool_reorg.py',
'p2p_block_sync.py --v1transport',
'p2p_block_sync.py --v2transport',
'p2p_block_times.py',
'wallet_createwallet.py --legacy-wallet',
'wallet_createwallet.py --usecli',
'wallet_createwallet.py --descriptors',