From 355547334f7d08640ee1fa291227356d61145d1a Mon Sep 17 00:00:00 2001 From: Pieter Wuille Date: Fri, 12 Aug 2022 17:29:52 -0400 Subject: Track headers presync progress and log it --- src/headerssync.h | 6 ++++ src/net_processing.cpp | 96 ++++++++++++++++++++++++++++++++++++++++++++++---- src/validation.cpp | 23 ++++++++++++ src/validation.h | 9 +++++ 4 files changed, 127 insertions(+), 7 deletions(-) diff --git a/src/headerssync.h b/src/headerssync.h index 01d55eb44e..16da964246 100644 --- a/src/headerssync.h +++ b/src/headerssync.h @@ -121,6 +121,12 @@ public: /** Return the height reached during the PRESYNC phase */ int64_t GetPresyncHeight() const { return m_current_height; } + /** Return the block timestamp of the last header received during the PRESYNC phase. */ + uint32_t GetPresyncTime() const { return m_last_header_received.nTime; } + + /** Return the amount of work in the chain received during the PRESYNC phase. */ + arith_uint256 GetPresyncWork() const { return m_current_chain_work; } + /** Construct a HeadersSyncState object representing a headers sync via this * download-twice mechanism). * diff --git a/src/net_processing.cpp b/src/net_processing.cpp index f471e96b50..03b876eee2 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -513,9 +513,9 @@ public: /** Implement NetEventsInterface */ void InitializeNode(CNode& node, ServiceFlags our_services) override EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex); - void FinalizeNode(const CNode& node) override EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex); + void FinalizeNode(const CNode& node) override EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex, !m_headers_presync_mutex); bool ProcessMessages(CNode* pfrom, std::atomic& interrupt) override - EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex, !m_recent_confirmed_transactions_mutex, !m_most_recent_block_mutex); + EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex, !m_recent_confirmed_transactions_mutex, !m_most_recent_block_mutex, !m_headers_presync_mutex); bool SendMessages(CNode* pto) override EXCLUSIVE_LOCKS_REQUIRED(pto->cs_sendProcessing) EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex, !m_recent_confirmed_transactions_mutex, !m_most_recent_block_mutex); @@ -532,7 +532,7 @@ public: void UnitTestMisbehaving(NodeId peer_id, int howmuch) override EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex) { Misbehaving(*Assert(GetPeerRef(peer_id)), howmuch, ""); }; void ProcessMessage(CNode& pfrom, const std::string& msg_type, CDataStream& vRecv, const std::chrono::microseconds time_received, const std::atomic& interruptMsgProc) override - EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex, !m_recent_confirmed_transactions_mutex, !m_most_recent_block_mutex); + EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex, !m_recent_confirmed_transactions_mutex, !m_most_recent_block_mutex, !m_headers_presync_mutex); void UpdateLastBlockAnnounceTime(NodeId node, int64_t time_in_seconds) override; private: @@ -601,7 +601,7 @@ private: void ProcessHeadersMessage(CNode& pfrom, Peer& peer, std::vector&& headers, bool via_compact_block) - EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex); + EXCLUSIVE_LOCKS_REQUIRED(!m_peer_mutex, !m_headers_presync_mutex); /** Various helpers for headers processing, invoked by ProcessHeadersMessage() */ /** Return true if headers are continuous and have valid proof-of-work (DoS points assigned on failure) */ bool CheckHeadersPoW(const std::vector& headers, const Consensus::Params& consensusParams, Peer& peer); @@ -633,7 +633,7 @@ private: */ bool IsContinuationOfLowWorkHeadersSync(Peer& peer, CNode& pfrom, std::vector& headers) - EXCLUSIVE_LOCKS_REQUIRED(peer.m_headers_sync_mutex); + EXCLUSIVE_LOCKS_REQUIRED(peer.m_headers_sync_mutex, !m_headers_presync_mutex); /** Check work on a headers chain to be processed, and if insufficient, * initiate our anti-DoS headers sync mechanism. * @@ -649,7 +649,7 @@ private: bool TryLowWorkHeadersSync(Peer& peer, CNode& pfrom, const CBlockIndex* chain_start_header, std::vector& headers) - EXCLUSIVE_LOCKS_REQUIRED(!peer.m_headers_sync_mutex, !m_peer_mutex); + EXCLUSIVE_LOCKS_REQUIRED(!peer.m_headers_sync_mutex, !m_peer_mutex, !m_headers_presync_mutex); /** Return true if the given header is an ancestor of * m_chainman.m_best_header or our current tip */ @@ -844,6 +844,24 @@ private: std::shared_ptr m_most_recent_compact_block GUARDED_BY(m_most_recent_block_mutex); uint256 m_most_recent_block_hash GUARDED_BY(m_most_recent_block_mutex); + // Data about the low-work headers synchronization, aggregated from all peers' HeadersSyncStates. + /** Mutex guarding the other m_headers_presync_* variables. */ + Mutex m_headers_presync_mutex; + /** A type to represent statistics about a peer's low-work headers sync. + * + * - The first field is the total verified amount of work in that synchronization. + * - The second is: + * - nullopt: the sync is in REDOWNLOAD phase (phase 2). + * - {height, timestamp}: the sync has the specified tip height and block timestamp (phase 1). + */ + using HeadersPresyncStats = std::pair>>; + /** Statistics for all peers in low-work headers sync. */ + std::map m_headers_presync_stats GUARDED_BY(m_headers_presync_mutex) {}; + /** The peer with the most-work entry in m_headers_presync_stats. */ + NodeId m_headers_presync_bestpeer GUARDED_BY(m_headers_presync_mutex) {-1}; + /** The m_headers_presync_stats improved, and needs signalling. */ + std::atomic_bool m_headers_presync_should_signal{false}; + /** Height of the highest block announced using BIP 152 high-bandwidth mode. */ int m_highest_fast_announce{0}; @@ -1502,6 +1520,10 @@ void PeerManagerImpl::FinalizeNode(const CNode& node) // fSuccessfullyConnected set. m_addrman.Connected(node.addr); } + { + LOCK(m_headers_presync_mutex); + m_headers_presync_stats.erase(nodeid); + } LogPrint(BCLog::NET, "Cleared nodestate for peer=%d\n", nodeid); } @@ -2448,6 +2470,48 @@ bool PeerManagerImpl::IsContinuationOfLowWorkHeadersSync(Peer& peer, CNode& pfro if (peer.m_headers_sync->GetState() == HeadersSyncState::State::FINAL) { peer.m_headers_sync.reset(nullptr); + + // Delete this peer's entry in m_headers_presync_stats. + // If this is m_headers_presync_bestpeer, it will be replaced later + // by the next peer that triggers the else{} branch below. + LOCK(m_headers_presync_mutex); + m_headers_presync_stats.erase(pfrom.GetId()); + } else { + // Build statistics for this peer's sync. + HeadersPresyncStats stats; + stats.first = peer.m_headers_sync->GetPresyncWork(); + if (peer.m_headers_sync->GetState() == HeadersSyncState::State::PRESYNC) { + stats.second = {peer.m_headers_sync->GetPresyncHeight(), + peer.m_headers_sync->GetPresyncTime()}; + } + + // Update statistics in stats. + LOCK(m_headers_presync_mutex); + m_headers_presync_stats[pfrom.GetId()] = stats; + auto best_it = m_headers_presync_stats.find(m_headers_presync_bestpeer); + bool best_updated = false; + if (best_it == m_headers_presync_stats.end()) { + // If the cached best peer is outdated, iterate over all remaining ones (including + // newly updated one) to find the best one. + NodeId peer_best{-1}; + const HeadersPresyncStats* stat_best{nullptr}; + for (const auto& [peer, stat] : m_headers_presync_stats) { + if (!stat_best || stat > *stat_best) { + peer_best = peer; + stat_best = &stat; + } + } + m_headers_presync_bestpeer = peer_best; + best_updated = (peer_best == pfrom.GetId()); + } else if (best_it->first == pfrom.GetId() || stats > best_it->second) { + // pfrom was and remains the best peer, or pfrom just became best. + m_headers_presync_bestpeer = pfrom.GetId(); + best_updated = true; + } + if (best_updated && stats.second.has_value()) { + // If the best peer updated, and it is in its first phase, signal. + m_headers_presync_should_signal = true; + } } if (result.success) { @@ -2676,6 +2740,8 @@ void PeerManagerImpl::ProcessHeadersMessage(CNode& pfrom, Peer& peer, LOCK(peer.m_headers_sync_mutex); if (peer.m_headers_sync) { peer.m_headers_sync.reset(nullptr); + LOCK(m_headers_presync_mutex); + m_headers_presync_stats.erase(pfrom.GetId()); } return; } @@ -4318,7 +4384,23 @@ void PeerManagerImpl::ProcessMessage(CNode& pfrom, const std::string& msg_type, ReadCompactSize(vRecv); // ignore tx count; assume it is 0. } - return ProcessHeadersMessage(pfrom, *peer, std::move(headers), /*via_compact_block=*/false); + ProcessHeadersMessage(pfrom, *peer, std::move(headers), /*via_compact_block=*/false); + + // Check if the headers presync progress needs to be reported to validation. + // This needs to be done without holding the m_headers_presync_mutex lock. + if (m_headers_presync_should_signal.exchange(false)) { + HeadersPresyncStats stats; + { + LOCK(m_headers_presync_mutex); + auto it = m_headers_presync_stats.find(m_headers_presync_bestpeer); + if (it != m_headers_presync_stats.end()) stats = it->second; + } + if (stats.second) { + m_chainman.ReportHeadersPresync(stats.first, stats.second->first, stats.second->second); + } + } + + return; } if (msg_type == NetMsgType::BLOCK) diff --git a/src/validation.cpp b/src/validation.cpp index dda575fede..5eaafa3f02 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -3711,6 +3711,29 @@ bool ChainstateManager::ProcessNewBlockHeaders(const std::vector& return true; } +void ChainstateManager::ReportHeadersPresync(const arith_uint256& work, int64_t height, int64_t timestamp) +{ + AssertLockNotHeld(cs_main); + const auto& chainstate = ActiveChainstate(); + { + LOCK(cs_main); + // Don't report headers presync progress if we already have a post-minchainwork header chain. + // This means we lose reporting for potentially legimate, but unlikely, deep reorgs, but + // prevent attackers that spam low-work headers from filling our logs. + if (m_best_header->nChainWork >= UintToArith256(GetConsensus().nMinimumChainWork)) return; + // Rate limit headers presync updates to 4 per second, as these are not subject to DoS + // protection. + auto now = std::chrono::steady_clock::now(); + if (now < m_last_presync_update + std::chrono::milliseconds{250}) return; + m_last_presync_update = now; + } + if (chainstate.IsInitialBlockDownload()) { + const int64_t blocks_left{(GetTime() - timestamp) / GetConsensus().nPowTargetSpacing}; + const double progress{100.0 * height / (height + blocks_left)}; + LogPrintf("Pre-synchronizing blockheaders, height: %d (~%.2f%%)\n", height, progress); + } +} + /** Store block on disk. If dbp is non-nullptr, the file is known to already reside on disk */ bool CChainState::AcceptBlock(const std::shared_ptr& pblock, BlockValidationState& state, CBlockIndex** ppindex, bool fRequested, const FlatFilePos* dbp, bool* fNewBlock, bool min_pow_checked) { diff --git a/src/validation.h b/src/validation.h index e5af65cde8..d3f293132f 100644 --- a/src/validation.h +++ b/src/validation.h @@ -868,6 +868,9 @@ private: bool min_pow_checked) EXCLUSIVE_LOCKS_REQUIRED(cs_main); friend CChainState; + /** Most recent headers presync progress update, for rate-limiting. */ + std::chrono::time_point m_last_presync_update GUARDED_BY(::cs_main) {}; + public: using Options = kernel::ChainstateManagerOpts; @@ -1046,6 +1049,12 @@ public: /** Produce the necessary coinbase commitment for a block (modifies the hash, don't call for mined blocks). */ std::vector GenerateCoinbaseCommitment(CBlock& block, const CBlockIndex* pindexPrev) const; + /** This is used by net_processing to report pre-synchronization progress of headers, as + * headers are not yet fed to validation during that time, but validation is (for now) + * responsible for logging and signalling through NotifyHeaderTip, so it needs this + * information. */ + void ReportHeadersPresync(const arith_uint256& work, int64_t height, int64_t timestamp); + ~ChainstateManager(); }; -- cgit v1.2.3