diff --git a/src/logging.h b/src/logging.h --- a/src/logging.h +++ b/src/logging.h @@ -54,6 +54,7 @@ COINDB = (1 << 18), QT = (1 << 19), LEVELDB = (1 << 20), + VALIDATION = (1 << 21), ALL = ~uint32_t(0), }; diff --git a/src/logging.cpp b/src/logging.cpp --- a/src/logging.cpp +++ b/src/logging.cpp @@ -122,6 +122,7 @@ {BCLog::COINDB, "coindb"}, {BCLog::QT, "qt"}, {BCLog::LEVELDB, "leveldb"}, + {BCLog::VALIDATION, "validation"}, {BCLog::ALL, "1"}, {BCLog::ALL, "all"}, }; diff --git a/src/validationinterface.cpp b/src/validationinterface.cpp --- a/src/validationinterface.cpp +++ b/src/validationinterface.cpp @@ -5,8 +5,13 @@ #include +#include +#include +#include #include +#include #include +#include #include #include @@ -159,6 +164,22 @@ promise.get_future().wait(); } +// Use a macro instead of a function for conditional logging to prevent +// evaluating arguments when logging is not enabled. +// +// NOTE: The lambda captures all local variables by value. +#define ENQUEUE_AND_LOG_EVENT(event, fmt, name, ...) \ + do { \ + auto local_name = (name); \ + LOG_EVENT("Enqueuing " fmt, local_name, __VA_ARGS__); \ + m_internals->m_schedulerClient.AddToProcessQueue([=] { \ + LOG_EVENT(fmt, local_name, __VA_ARGS__); \ + event(); \ + }); \ + } while (0) + +#define LOG_EVENT(fmt, ...) LogPrint(BCLog::VALIDATION, fmt "\n", __VA_ARGS__) + void CMainSignals::UpdatedBlockTip(const CBlockIndex *pindexNew, const CBlockIndex *pindexFork, bool fInitialDownload) { @@ -167,48 +188,65 @@ // for the caller to invoke this signal in the same critical section where // the chain is updated - m_internals->m_schedulerClient.AddToProcessQueue([pindexNew, pindexFork, - fInitialDownload, this] { + auto event = [pindexNew, pindexFork, fInitialDownload, this] { m_internals->UpdatedBlockTip(pindexNew, pindexFork, fInitialDownload); - }); + }; + ENQUEUE_AND_LOG_EVENT( + event, "%s: new block hash=%s fork block hash=%s (in IBD=%s)", __func__, + pindexNew->GetBlockHash().ToString(), + pindexFork ? pindexFork->GetBlockHash().ToString() : "null", + fInitialDownload); } void CMainSignals::TransactionAddedToMempool(const CTransactionRef &ptx) { - m_internals->m_schedulerClient.AddToProcessQueue( - [ptx, this] { m_internals->TransactionAddedToMempool(ptx); }); + auto event = [ptx, this] { m_internals->TransactionAddedToMempool(ptx); }; + ENQUEUE_AND_LOG_EVENT(event, "%s: txid=%s", __func__, + ptx->GetHash().ToString()); } void CMainSignals::TransactionRemovedFromMempool(const CTransactionRef &ptx) { - m_internals->m_schedulerClient.AddToProcessQueue( - [ptx, this] { m_internals->TransactionRemovedFromMempool(ptx); }); + auto event = [ptx, this] { + m_internals->TransactionRemovedFromMempool(ptx); + }; + ENQUEUE_AND_LOG_EVENT(event, "%s: txid=%s", __func__, + ptx->GetHash().ToString()); } void CMainSignals::BlockConnected( const std::shared_ptr &pblock, const CBlockIndex *pindex, const std::shared_ptr> &pvtxConflicted) { - m_internals->m_schedulerClient.AddToProcessQueue( - [pblock, pindex, pvtxConflicted, this] { - m_internals->BlockConnected(pblock, pindex, *pvtxConflicted); - }); + auto event = [pblock, pindex, pvtxConflicted, this] { + m_internals->BlockConnected(pblock, pindex, *pvtxConflicted); + }; + ENQUEUE_AND_LOG_EVENT(event, "%s: block hash=%s block height=%d", __func__, + pblock->GetHash().ToString(), pindex->nHeight); } void CMainSignals::BlockDisconnected( const std::shared_ptr &pblock) { - m_internals->m_schedulerClient.AddToProcessQueue( - [pblock, this] { m_internals->BlockDisconnected(pblock); }); + // TODO: This function was refactored as part of an out-of-order backport + // of https://github.com/bitcoin/bitcoin/pull/16688 + auto event = [pblock, this] { m_internals->BlockDisconnected(pblock); }; + ENQUEUE_AND_LOG_EVENT(event, "%s: block hash=%s", __func__, + pblock->GetHash().ToString()); } void CMainSignals::ChainStateFlushed(const CBlockLocator &locator) { - m_internals->m_schedulerClient.AddToProcessQueue( - [locator, this] { m_internals->ChainStateFlushed(locator); }); + auto event = [locator, this] { m_internals->ChainStateFlushed(locator); }; + ENQUEUE_AND_LOG_EVENT(event, "%s: block hash=%s", __func__, + locator.IsNull() ? "null" + : locator.vHave.front().ToString()); } void CMainSignals::BlockChecked(const CBlock &block, const CValidationState &state) { + LOG_EVENT("%s: block hash=%s state=%s", __func__, + block.GetHash().ToString(), FormatStateMessage(state)); m_internals->BlockChecked(block, state); } void CMainSignals::NewPoWValidBlock( const CBlockIndex *pindex, const std::shared_ptr &block) { + LOG_EVENT("%s: block hash=%s", __func__, block->GetHash().ToString()); m_internals->NewPoWValidBlock(pindex, block); } diff --git a/test/lint/lint-format-strings.py b/test/lint/lint-format-strings.py --- a/test/lint/lint-format-strings.py +++ b/test/lint/lint-format-strings.py @@ -19,6 +19,8 @@ ("src/netbase.cpp", "LogConnectFailure(bool manual_connection, const char *fmt, const Args &... args)"), ("src/util/system.cpp", "strprintf(_(COPYRIGHT_HOLDERS).translated, COPYRIGHT_HOLDERS_SUBSTITUTION)"), + ("src/validationinterface.cpp", + "LogPrint(BCLog::VALIDATION, fmt \"\\n\", __VA_ARGS__)"), ("src/tinyformat.h", "printf(const char *fmt, const Args &... args)"), ("src/tinyformat.h", "printf(const char *fmt, TINYFORMAT_VARARGS(n))"), ("src/wallet/wallet.h",