[Util] Add validation interface logging

CMakeLists.txt

@@ -432,6 +432,7 @@ set(UTIL_SOURCES
         ./src/util/threadnames.cpp
         ./src/util/blockstatecatcher.h
         ./src/util/system.cpp
+        ./src/util/validation.cpp
         ./src/utilstrencodings.cpp
         ./src/utilmoneystr.cpp
         ./src/utiltime.cpp

src/Makefile.am

@@ -297,6 +297,7 @@ BITCOIN_CORE_H = \
   util/macros.h \
   util/string.h \
   util/threadnames.h \
+  util/validation.h \
   utilstrencodings.h \
   utilmoneystr.h \
   utiltime.h \
@@ -569,6 +570,7 @@ libbitcoin_util_a_SOURCES = \
   util/threadnames.cpp \
   utilstrencodings.cpp \
   util/string.cpp \
+  util/validation.cpp \
   utiltime.cpp \
   $(BITCOIN_CORE_H) \
   $(LIBSAPLING_H)

src/blockassembler.cpp

@@ -21,7 +21,7 @@
 #include "spork.h"
 #include "timedata.h"
 #include "util/system.h"
-#include "validation.h"
+#include "util/validation.h"
 #include "validationinterface.h"
 
 #ifdef ENABLE_WALLET

src/budget/budgetmanager.cpp

@@ -11,6 +11,7 @@
 #include "masternodeman.h"
 #include "net_processing.h"
 #include "netmessagemaker.h"
+#include "util/validation.h"
 #include "validation.h"   // GetTransaction, cs_main
 
 

src/budget/budgetvote.h

@@ -7,6 +7,7 @@
 #define BUDGET_VOTE_H
 
 #include "messagesigner.h"
+#include "primitives/transaction.h"
 
 #include <univalue.h>
 

src/budget/finalizedbudgetvote.h

@@ -7,6 +7,7 @@
 #define FINALIZED_BUDGET_VOTE_H
 
 #include "messagesigner.h"
+#include "primitives/transaction.h"
 
 #include <univalue.h>
 

src/evo/deterministicmns.cpp

@@ -16,7 +16,6 @@
 #include "script/standard.h"
 #include "spork.h"
 #include "sync.h"
-#include "validation.h"
 #include "validationinterface.h"
 
 #include <univalue.h>

src/logging.cpp

@@ -126,6 +126,7 @@ const CLogCategoryDesc LogCategories[] = {
         {BCLog::MNPING,         "mnping"},
         {BCLog::SAPLING,        "sapling"},
         {BCLog::SPORKS,         "sporks"},
+        {BCLog::VALIDATION,     "validation"},
         {BCLog::ALL,            "1"},
         {BCLog::ALL,            "all"},
 };

src/logging.h

@@ -65,6 +65,7 @@ namespace BCLog {
         LEGACYZC    = (1 << 25),
         SAPLING     = (1 << 26),
         SPORKS      = (1 << 27),
+        VALIDATION  = (1 << 28),
         ALL         = ~(uint32_t)0,
     };
 

src/masternode.h

@@ -10,6 +10,7 @@
 #include "key.h"
 #include "messagesigner.h"
 #include "net.h"
+#include "primitives/transaction.h"
 #include "serialize.h"
 #include "sync.h"
 #include "timedata.h"

src/messagesigner.cpp

@@ -8,9 +8,9 @@
 #include "messagesigner.h"
 #include "tinyformat.h"
 #include "util/system.h"
+#include "util/validation.h"
 #include "utilstrencodings.h"
 
-const std::string strMessageMagic = "DarkNet Signed Message:\n";
 
 bool CMessageSigner::GetKeysFromSecret(const std::string& strSecret, CKey& keyRet, CPubKey& pubkeyRet)
 {

src/messagesigner.h

@@ -7,9 +7,6 @@
 #define MESSAGESIGNER_H
 
 #include "key.h"
-#include "primitives/transaction.h" // for CTxIn
-
-extern const std::string strMessageMagic;
 
 enum MessageVersion {
         MESS_VER_STRMESS    = 0, // old format

src/net_processing.cpp

@@ -19,6 +19,7 @@
 #include "primitives/transaction.h"
 #include "sporkdb.h"
 #include "streams.h"
+#include "util/validation.h"
 
 int64_t nTimeBestReceived = 0;  // Used only to inform the wallet of when we last received a block
 

src/primitives/block.h

@@ -174,7 +174,7 @@ struct CBlockLocator
         vHave.clear();
     }
 
-    bool IsNull()
+    bool IsNull() const
     {
         return vHave.empty();
     }

src/qt/pivx/settings/settingssignmessagewidgets.cpp

@@ -3,16 +3,17 @@
 // file COPYING or http://www.opensource.org/licenses/mit-license.php.
 
 #include "qt/pivx/settings/settingssignmessagewidgets.h"
-#include "qt/pivx/settings/forms/ui_settingssignmessagewidgets.h"
-#include "qt/pivx/qtutils.h"
-#include "guiutil.h"
-#include "walletmodel.h"
 
-#include "key_io.h"
 #include "init.h"
+#include "key_io.h"
+#include "qt/askpassphrasedialog.h"
+#include "qt/addressbookpage.h"
+#include "qt/guiutil.h"
+#include "qt/pivx/settings/forms/ui_settingssignmessagewidgets.h"
+#include "qt/pivx/qtutils.h"
+#include "qt/walletmodel.h"
+#include "util/validation.h"
 #include "wallet/wallet.h"
-#include "askpassphrasedialog.h"
-#include "addressbookpage.h"
 
 #include <string>
 #include <vector>

src/rpc/budget.cpp

@@ -16,6 +16,7 @@
 #include "masternodeman.h"
 #include "messagesigner.h"
 #include "rpc/server.h"
+#include "util/validation.h"
 #include "utilmoneystr.h"
 #ifdef ENABLE_WALLET
 #include "wallet/rpcwallet.h"

src/rpc/misc.cpp

@@ -17,6 +17,7 @@
 #include "spork.h"
 #include "timedata.h"
 #include "util/system.h"
+#include "util/validation.h"
 #ifdef ENABLE_WALLET
 #include "wallet/rpcwallet.h"
 #include "wallet/wallet.h"

src/rpc/rpcevo.cpp

@@ -17,8 +17,8 @@
 #include "pubkey.h" // COMPACT_SIGNATURE_SIZE
 #include "rpc/server.h"
 #include "script/sign.h"
+#include "util/validation.h"
 #include "utilmoneystr.h"
-#include "validation.h"
 
 #ifdef ENABLE_WALLET
 #include "coincontrol.h"

src/util/blockstatecatcher.h

@@ -5,7 +5,7 @@
 #ifndef PIVX_BLOCKSTATECATCHER_H
 #define PIVX_BLOCKSTATECATCHER_H
 
-#include "validation.h"
+#include "consensus/validation.h"
 #include "validationinterface.h"
 
 /**

src/util/validation.cpp

@@ -0,0 +1,27 @@
+// Copyright (c) 2009-2010 Satoshi Nakamoto
+// Copyright (c) 2009-2019 The Bitcoin Core developers
+// Copyright (c) 2021 The PIVX developers
+// Distributed under the MIT software license, see the accompanying
+// file COPYING or http://www.opensource.org/licenses/mit-license.php.
+
+#include "util/validation.h"
+
+#include "consensus/validation.h"
+#include "tinyformat.h"
+
+/** Convert CValidationState to a human-readable message for logging */
+std::string FormatStateMessage(const CValidationState& state)
+{
+    if (state.IsValid()) {
+        return "Valid";
+    }
+
+    const std::string& debug_message = state.GetDebugMessage();
+    if (!debug_message.empty()) {
+        return strprintf("%s, %s", state.GetRejectReason(), debug_message);
+    }
+
+    return state.GetRejectReason();
+}
+
+const std::string strMessageMagic = "DarkNet Signed Message:\n";

src/util/validation.h

@@ -0,0 +1,19 @@
+// Copyright (c) 2009-2010 Satoshi Nakamoto
+// Copyright (c) 2009-2019 The Bitcoin Core developers
+// Copyright (c) 2021 The PIVX developers
+// Distributed under the MIT software license, see the accompanying
+// file COPYING or http://www.opensource.org/licenses/mit-license.php.
+
+#ifndef PIVX_UTIL_VALIDATION_H
+#define PIVX_UTIL_VALIDATION_H
+
+#include <string>
+
+class CValidationState;
+
+/** Convert CValidationState to a human-readable message for logging */
+std::string FormatStateMessage(const CValidationState& state);
+
+extern const std::string strMessageMagic;
+
+#endif // PIVX_UTIL_VALIDATION_H

src/validation.cpp

@@ -43,6 +43,7 @@
 #include "txdb.h"
 #include "undo.h"
 #include "util/system.h"
+#include "util/validation.h"
 #include "utilmoneystr.h"
 #include "validationinterface.h"
 #include "warnings.h"
@@ -312,15 +313,6 @@ CAmount GetShieldedTxMinFee(const CTransaction& tx)
     return nMinFee;
 }
 
-/** Convert CValidationState to a human-readable message for logging */
-std::string FormatStateMessage(const CValidationState &state)
-{
-    return strprintf("%s%s (code %i)",
-        state.GetRejectReason(),
-        (state.GetDebugMessage().empty() ? "" : ", " + state.GetDebugMessage()),
-        state.GetRejectCode());
-}
-
 /* Make mempool consistent after a reorg, by re-adding or recursively erasing
  * disconnected block transactions from the mempool, and also removing any
  * other transactions from the mempool that are no longer valid given the new

src/validation.h

@@ -223,9 +223,6 @@ bool AcceptToMemoryPoolWithTime(CTxMemPool& pool, CValidationState &state, const
                                 bool* pfMissingInputs, int64_t nAcceptTime, bool fOverrideMempoolLimit = false,
                                 bool fRejectInsaneFee = false, bool ignoreFees = false);
 
-/** Convert CValidationState to a human-readable message for logging */
-std::string FormatStateMessage(const CValidationState &state);
-
 CAmount GetMinRelayFee(const CTransaction& tx, const CTxMemPool& pool, unsigned int nBytes);
 CAmount GetMinRelayFee(unsigned int nBytes);
 /**

src/validationinterface.cpp

@@ -5,8 +5,14 @@
 // file COPYING or http://www.opensource.org/licenses/mit-license.php.
 
 #include "validationinterface.h"
+
+#include "chain.h"
+#include "consensus/validation.h"
+#include "evo/deterministicmns.h"
+#include "logging.h"
 #include "scheduler.h"
-#include "validation.h"
+#include "util/validation.h"
+#include "validation.h" // cs_main
 
 #include <future>
 #include <list>
@@ -132,44 +138,73 @@ void SyncWithValidationInterfaceQueue() {
     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) {
     // Dependencies exist that require UpdatedBlockTip events to be delivered in the order in which
     // the chain actually updates. One way to ensure this is 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] {
+    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, MemPoolRemovalReason reason) {
-    m_internals->m_schedulerClient.AddToProcessQueue([ptx, reason, this] {
+    auto event = [ptx, reason, this] {
         m_internals->TransactionRemovedFromMempool(ptx, reason);
-    });
+    };
+    ENQUEUE_AND_LOG_EVENT(event, "%s: txid=%s", __func__, ptx->GetHash().ToString());
 }
 
 void CMainSignals::BlockConnected(const std::shared_ptr<const CBlock> &pblock, const CBlockIndex *pindex) {
-    m_internals->m_schedulerClient.AddToProcessQueue([pblock, pindex, this] {
+    auto event = [pblock, pindex, this] {
         m_internals->BlockConnected(pblock, pindex);
-    });
+    };
+    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<const CBlock> &pblock, const uint256& blockHash, int nBlockHeight, int64_t blockTime) {
-    m_internals->m_schedulerClient.AddToProcessQueue([pblock, blockHash, nBlockHeight, blockTime, this] {
+    auto event = [pblock, blockHash, nBlockHeight, blockTime, this] {
         m_internals->BlockDisconnected(pblock, blockHash, nBlockHeight, blockTime);
-    });
+    };
+    ENQUEUE_AND_LOG_EVENT(event, "%s: block hash=%s, block height=%d, block time=%d", __func__,
+                          blockHash.ToString(), nBlockHeight, blockTime);
 }
 
-void CMainSignals::SetBestChain(const CBlockLocator &locator) {
-    m_internals->m_schedulerClient.AddToProcessQueue([locator, this] {
+void CMainSignals::SetBestChain(const CBlockLocator& locator) {
+    auto event = [locator, this] {
         m_internals->SetBestChain(locator);
-    });
+    };
+    ENQUEUE_AND_LOG_EVENT(event, "%s: block hash=%s", __func__,
+                          locator.IsNull() ? "null" : locator.vHave.front().ToString());
 }
 
 void CMainSignals::Broadcast(CConnman* connman) {
@@ -178,8 +213,16 @@ void CMainSignals::Broadcast(CConnman* connman) {
 
 void CMainSignals::BlockChecked(const CBlock& block, const CValidationState& state) {
     m_internals->BlockChecked(block, state);
+    LOG_EVENT("%s: block hash=%s (state=%s)", __func__,
+              block.GetHash().ToString(), FormatStateMessage(state));
 }
 
 void CMainSignals::NotifyMasternodeListChanged(bool undo, const CDeterministicMNList& oldMNList, const CDeterministicMNListDiff& diff) {
     m_internals->NotifyMasternodeListChanged(undo, oldMNList, diff);
+    LOG_EVENT("%s: (undo=%d) old list for=%s, added=%d, updated=%d, removed=%d", __func__,
+              undo,
+              oldMNList.GetBlockHash().ToString(),
+              diff.addedMNs.size(),
+              diff.updatedMNs.size(),
+              diff.removedMns.size());
 }

src/wallet/rpcwallet.cpp

@@ -23,6 +23,7 @@
 #include "spork.h"
 #include "timedata.h"
 #include "utilmoneystr.h"
+#include "util/validation.h"
 #include "wallet/wallet.h"
 #include "wallet/walletdb.h"
 #include "wallet/walletutil.h"