From 9d3e39c29c31775fd82af319d1d4dfbbd3e21bfa Mon Sep 17 00:00:00 2001 From: Sjors Provoost Date: Fri, 21 Feb 2025 15:35:43 +0100 Subject: [PATCH] Log block header in net_processing Previously ChainstateManager::AcceptBlockHeader would log when it saw a new header. This commit moves logging to the call site(s) in net_processing. The next commits will then log which peer sent it and whether it was part of a compact block. This commit changes behavior: - when multiple headers are received in a single message, only the last one is logged - if any of the headers are invalid, the valid ones are not logged This happens because net_processing calls ProcessNewBlockHeaders with multiple headers, which then calls AcceptBlockHeader one header at a time. Additionally: - when the header is received via a compact block, there's no more duplicate log (a later commit also unifies logging code paths) --- src/net_processing.cpp | 34 +++++++++++++++++++++++++++++++++- src/validation.cpp | 17 ----------------- src/validation.h | 1 + 3 files changed, 34 insertions(+), 18 deletions(-) diff --git a/src/net_processing.cpp b/src/net_processing.cpp index 0b25396dd21..d7061fdec87 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -1071,6 +1071,8 @@ private: void AddAddressKnown(Peer& peer, const CAddress& addr) EXCLUSIVE_LOCKS_REQUIRED(g_msgproc_mutex); void PushAddress(Peer& peer, const CAddress& addr) EXCLUSIVE_LOCKS_REQUIRED(g_msgproc_mutex); + + void LogBlockHeader(const CBlockIndex& index); }; const CNodeState* PeerManagerImpl::State(NodeId pnode) const @@ -2970,7 +2972,10 @@ void PeerManagerImpl::ProcessHeadersMessage(CNode& pfrom, Peer& peer, // Now process all the headers. BlockValidationState state; - if (!m_chainman.ProcessNewBlockHeaders(headers, /*min_pow_checked=*/true, state, &pindexLast)) { + const bool processed{m_chainman.ProcessNewBlockHeaders(headers, + /*min_pow_checked=*/true, + state, &pindexLast)}; + if (!processed) { if (state.IsInvalid()) { MaybePunishNodeForBlock(pfrom.GetId(), state, via_compact_block, "invalid header received"); return; @@ -2978,6 +2983,10 @@ void PeerManagerImpl::ProcessHeadersMessage(CNode& pfrom, Peer& peer, } assert(pindexLast); + if (processed && received_new_header) { + LogBlockHeader(*pindexLast); + } + // Consider fetching more headers if we are not using our headers-sync mechanism. if (nCount == m_opts.max_headers_result && !have_headers_sync) { // Headers message had its maximum size; the peer may have more headers. @@ -3405,6 +3414,29 @@ void PeerManagerImpl::ProcessCompactBlockTxns(CNode& pfrom, Peer& peer, const Bl return; } +void PeerManagerImpl::LogBlockHeader(const CBlockIndex& index) { + // To prevent log spam, this function should only be called after it was determined that a + // header is both new and valid. + // + // These messages are valuable for detecting potential selfish mining behavior; + // if multiple displacing headers are seen near simultaneously across many + // nodes in the network, this might be an indication of selfish mining. + // In addition it can be used to identify peers which send us a header, but + // don't followup with a complete and valid (compact) block. + // Having this log by default when not in IBD ensures broad availability of + // this data in case investigation is merited. + const auto msg = strprintf( + "Saw new header hash=%s height=%d", + index.GetBlockHash().ToString(), + index.nHeight + ); + if (m_chainman.IsInitialBlockDownload()) { + LogDebug(BCLog::VALIDATION, "%s", msg); + } else { + LogInfo("%s", msg); + } +} + void PeerManagerImpl::ProcessMessage(CNode& pfrom, const std::string& msg_type, DataStream& vRecv, const std::chrono::microseconds time_received, const std::atomic& interruptMsgProc) diff --git a/src/validation.cpp b/src/validation.cpp index aa1effb736f..01650ba1f57 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -4403,23 +4403,6 @@ bool ChainstateManager::AcceptBlockHeader(const CBlockHeader& block, BlockValida if (ppindex) *ppindex = pindex; - // Since this is the earliest point at which we have determined that a - // header is both new and valid, log here. - // - // These messages are valuable for detecting potential selfish mining behavior; - // if multiple displacing headers are seen near simultaneously across many - // nodes in the network, this might be an indication of selfish mining. Having - // this log by default when not in IBD ensures broad availability of this data - // in case investigation is merited. - const auto msg = strprintf( - "Saw new header hash=%s height=%d", hash.ToString(), pindex->nHeight); - - if (IsInitialBlockDownload()) { - LogPrintLevel(BCLog::VALIDATION, BCLog::Level::Debug, "%s\n", msg); - } else { - LogPrintf("%s\n", msg); - } - return true; } diff --git a/src/validation.h b/src/validation.h index e361c7af101..cdea2a98936 100644 --- a/src/validation.h +++ b/src/validation.h @@ -1218,6 +1218,7 @@ public: * @param[in] min_pow_checked True if proof-of-work anti-DoS checks have been done by caller for headers chain * @param[out] state This may be set to an Error state if any error occurred processing them * @param[out] ppindex If set, the pointer will be set to point to the last new block index object for the given headers + * @returns false if AcceptBlockHeader fails on any of the headers, true otherwise (including if headers were already known) */ bool ProcessNewBlockHeaders(std::span headers, bool min_pow_checked, BlockValidationState& state, const CBlockIndex** ppindex = nullptr) LOCKS_EXCLUDED(cs_main);