[pull] master from bitcoin:master

src/sync.cpp

@@ -4,6 +4,7 @@
 
 #include <sync.h>
 
+#include <logging/timer.h>
 #include <tinyformat.h>
 #include <util/log.h>
 #include <util/strencodings.h>
@@ -19,6 +20,19 @@
 #include <utility>
 #include <vector>
 
+#ifdef DEBUG_LOCKCONTENTION
+
+template <typename LockType>
+void ContendedLock(std::string_view name, std::string_view file, int nLine, LockType& lock)
+{
+    LOG_TIME_MICROS_WITH_CATEGORY(strprintf("lock contention %s, %s:%d", name, file, nLine), BCLog::LOCK);
+    lock.lock();
+}
+template void ContendedLock(std::string_view name, std::string_view file, int nLine, std::unique_lock<std::mutex>& lock);
+template void ContendedLock(std::string_view name, std::string_view file, int nLine, std::unique_lock<std::recursive_mutex>& lock);
+
+#endif
+
 #ifdef DEBUG_LOCKORDER
 //
 // Early deadlock detection.

src/sync.h

@@ -6,10 +6,6 @@
 #ifndef BITCOIN_SYNC_H
 #define BITCOIN_SYNC_H
 
-#ifdef DEBUG_LOCKCONTENTION
-#include <logging/timer.h>
-#endif
-
 #include <threadsafety.h> // IWYU pragma: export
 #include <util/macros.h>
 
@@ -77,6 +73,16 @@ inline void DeleteLock(void* cs) {}
 inline bool LockStackEmpty() { return true; }
 #endif
 
+/*
+ * Called when a mutex fails to lock immediately because it is held by another
+ * thread, or spuriously. Responsible for locking the lock before returning.
+ */
+#ifdef DEBUG_LOCKCONTENTION
+
+template <typename LockType>
+void ContendedLock(std::string_view name, std::string_view file, int nLine, LockType& lock);
+#endif
+
 /**
  * Template mixin that adds -Wthread-safety locking annotations and lock order
  * checking to a subset of the mutex API.
@@ -151,10 +157,12 @@ class SCOPED_LOCKABLE UniqueLock : public MutexType::unique_lock
     {
         EnterCritical(pszName, pszFile, nLine, Base::mutex());
 #ifdef DEBUG_LOCKCONTENTION
-        if (Base::try_lock()) return;
-        LOG_TIME_MICROS_WITH_CATEGORY(strprintf("lock contention %s, %s:%d", pszName, pszFile, nLine), BCLog::LOCK);
-#endif
+        if (!Base::try_lock()) {
+            ContendedLock(pszName, pszFile, nLine, static_cast<Base&>(*this));
+        }
+#else
         Base::lock();
+#endif
     }
 
     bool TryEnter(const char* pszName, const char* pszFile, int nLine)

src/validation.cpp

@@ -2982,7 +2982,7 @@ bool Chainstate::DisconnectTip(BlockValidationState& state, DisconnectedBlockTra
     // Let wallets know transactions went from 1-confirmed to
     // 0-confirmed or conflicted:
     if (m_chainman.m_options.signals) {
-        m_chainman.m_options.signals->BlockDisconnected(pblock, pindexDelete);
+        m_chainman.m_options.signals->BlockDisconnected(std::move(pblock), pindexDelete);
     }
     return true;
 }
@@ -3391,9 +3391,9 @@ bool Chainstate::ActivateBestChain(BlockValidationState& state, std::shared_ptr<
                 }
                 pindexNewTip = m_chain.Tip();
 
-                for (const auto& [index, block] : connected_blocks) {
+                for (auto& [index, block] : std::move(connected_blocks)) {
                     if (m_chainman.m_options.signals) {
-                        m_chainman.m_options.signals->BlockConnected(chainstate_role, Assert(block), Assert(index));
+                        m_chainman.m_options.signals->BlockConnected(chainstate_role, std::move(Assert(block)), Assert(index));
                     }
                 }
 

src/validationinterface.cpp

@@ -156,33 +156,39 @@ void ValidationSignals::SyncWithValidationInterfaceQueue()
 
 // 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_task_runner->insert([=] { \
-            LOG_EVENT(fmt, local_name, __VA_ARGS__);           \
-            event();                                           \
-        });                                                    \
+#define ENQUEUE_AND_LOG_EVENT(event, log_msg)                                                                    \
+    do {                                                                                                         \
+        static_assert(std::is_rvalue_reference_v<decltype((event))>,                                             \
+                      "event must be passed as an rvalue");                                                      \
+        static_assert(std::is_rvalue_reference_v<decltype((log_msg))>,                                           \
+                      "log_msg must be passed as an rvalue");                                                    \
+        auto enqueue_log_msg = (log_msg);                                                                        \
+        LOG_EVENT("Enqueuing %s", enqueue_log_msg);                                                              \
+        m_internals->m_task_runner->insert([local_log_msg = std::move(enqueue_log_msg), local_event = (event)] { \
+            LOG_EVENT("%s", local_log_msg);                                                                      \
+            local_event();                                                                                       \
+        });                                                                                                      \
     } while (0)
 
+#define LOG_MSG(fmt, ...) \
+    (ShouldLog(BCLog::VALIDATION, BCLog::Level::Debug) ? tfm::format((fmt), __VA_ARGS__) : std::string{})
+
 #define LOG_EVENT(fmt, ...) \
-    LogDebug(BCLog::VALIDATION, fmt "\n", __VA_ARGS__)
+    LogDebug(BCLog::VALIDATION, fmt, __VA_ARGS__)
 
 void ValidationSignals::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
 
-    auto event = [pindexNew, pindexFork, fInitialDownload, this] {
-        m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.UpdatedBlockTip(pindexNew, pindexFork, fInitialDownload); });
-    };
-    ENQUEUE_AND_LOG_EVENT(event, "%s: new block hash=%s fork block hash=%s (in IBD=%s)", __func__,
+    auto log_msg = LOG_MSG("%s: new block hash=%s fork block hash=%s (in IBD=%s)", __func__,
                           pindexNew->GetBlockHash().ToString(),
                           pindexFork ? pindexFork->GetBlockHash().ToString() : "null",
                           fInitialDownload);
+    auto event = [pindexNew, pindexFork, fInitialDownload, this] {
+        m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.UpdatedBlockTip(pindexNew, pindexFork, fInitialDownload); });
+    };
+    ENQUEUE_AND_LOG_EVENT(std::move(event), std::move(log_msg));
 }
 
 void ValidationSignals::ActiveTipChange(const CBlockIndex& new_tip, bool is_ibd)
@@ -193,61 +199,67 @@ void ValidationSignals::ActiveTipChange(const CBlockIndex& new_tip, bool is_ibd)
 
 void ValidationSignals::TransactionAddedToMempool(const NewMempoolTransactionInfo& tx, uint64_t mempool_sequence)
 {
+    auto log_msg = LOG_MSG("%s: txid=%s wtxid=%s", __func__,
+                          tx.info.m_tx->GetHash().ToString(),
+                          tx.info.m_tx->GetWitnessHash().ToString());
     auto event = [tx, mempool_sequence, this] {
         m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.TransactionAddedToMempool(tx, mempool_sequence); });
     };
-    ENQUEUE_AND_LOG_EVENT(event, "%s: txid=%s wtxid=%s", __func__,
-                          tx.info.m_tx->GetHash().ToString(),
-                          tx.info.m_tx->GetWitnessHash().ToString());
+    ENQUEUE_AND_LOG_EVENT(std::move(event), std::move(log_msg));
 }
 
 void ValidationSignals::TransactionRemovedFromMempool(const CTransactionRef& tx, MemPoolRemovalReason reason, uint64_t mempool_sequence) {
-    auto event = [tx, reason, mempool_sequence, this] {
-        m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.TransactionRemovedFromMempool(tx, reason, mempool_sequence); });
-    };
-    ENQUEUE_AND_LOG_EVENT(event, "%s: txid=%s wtxid=%s reason=%s", __func__,
+    auto log_msg = LOG_MSG("%s: txid=%s wtxid=%s reason=%s", __func__,
                           tx->GetHash().ToString(),
                           tx->GetWitnessHash().ToString(),
                           RemovalReasonToString(reason));
+    auto event = [tx, reason, mempool_sequence, this] {
+        m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.TransactionRemovedFromMempool(tx, reason, mempool_sequence); });
+    };
+    ENQUEUE_AND_LOG_EVENT(std::move(event), std::move(log_msg));
 }
 
-void ValidationSignals::BlockConnected(const ChainstateRole& role, const std::shared_ptr<const CBlock>& pblock, const CBlockIndex* pindex)
+void ValidationSignals::BlockConnected(const ChainstateRole& role, std::shared_ptr<const CBlock> pblock, const CBlockIndex* pindex)
 {
-    auto event = [role, pblock, pindex, this] {
-        m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.BlockConnected(role, pblock, pindex); });
-    };
-    ENQUEUE_AND_LOG_EVENT(event, "%s: block hash=%s block height=%d", __func__,
+    auto log_msg = LOG_MSG("%s: block hash=%s block height=%d", __func__,
                           pblock->GetHash().ToString(),
                           pindex->nHeight);
+    auto event = [role, pblock = std::move(pblock), pindex, this] {
+        m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.BlockConnected(role, pblock, pindex); });
+    };
+    ENQUEUE_AND_LOG_EVENT(std::move(event), std::move(log_msg));
 }
 
 void ValidationSignals::MempoolTransactionsRemovedForBlock(const std::vector<RemovedMempoolTransactionInfo>& txs_removed_for_block, unsigned int nBlockHeight)
 {
+    auto log_msg = LOG_MSG("%s: block height=%s txs removed=%s", __func__,
+                          nBlockHeight,
+                          txs_removed_for_block.size());
     auto event = [txs_removed_for_block, nBlockHeight, this] {
         m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.MempoolTransactionsRemovedForBlock(txs_removed_for_block, nBlockHeight); });
     };
-    ENQUEUE_AND_LOG_EVENT(event, "%s: block height=%s txs removed=%s", __func__,
-                          nBlockHeight,
-                          txs_removed_for_block.size());
+    ENQUEUE_AND_LOG_EVENT(std::move(event), std::move(log_msg));
 }
 
-void ValidationSignals::BlockDisconnected(const std::shared_ptr<const CBlock>& pblock, const CBlockIndex* pindex)
+void ValidationSignals::BlockDisconnected(std::shared_ptr<const CBlock> pblock, const CBlockIndex* pindex)
 {
-    auto event = [pblock, pindex, this] {
-        m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.BlockDisconnected(pblock, pindex); });
-    };
-    ENQUEUE_AND_LOG_EVENT(event, "%s: block hash=%s block height=%d", __func__,
+    auto log_msg = LOG_MSG("%s: block hash=%s block height=%d", __func__,
                           pblock->GetHash().ToString(),
                           pindex->nHeight);
+    auto event = [pblock = std::move(pblock), pindex, this] {
+        m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.BlockDisconnected(pblock, pindex); });
+    };
+    ENQUEUE_AND_LOG_EVENT(std::move(event), std::move(log_msg));
 }
 
 void ValidationSignals::ChainStateFlushed(const ChainstateRole& role, const CBlockLocator& locator)
 {
+    auto log_msg = LOG_MSG("%s: block hash=%s", __func__,
+                          locator.IsNull() ? "null" : locator.vHave.front().ToString());
     auto event = [role, locator, this] {
         m_internals->Iterate([&](CValidationInterface& callbacks) { callbacks.ChainStateFlushed(role, locator); });
     };
-    ENQUEUE_AND_LOG_EVENT(event, "%s: block hash=%s", __func__,
-                          locator.IsNull() ? "null" : locator.vHave.front().ToString());
+    ENQUEUE_AND_LOG_EVENT(std::move(event), std::move(log_msg));
 }
 
 void ValidationSignals::BlockChecked(const std::shared_ptr<const CBlock>& block, const BlockValidationState& state)

src/validationinterface.h

@@ -223,8 +223,8 @@ class ValidationSignals {
     void TransactionAddedToMempool(const NewMempoolTransactionInfo&, uint64_t mempool_sequence);
     void TransactionRemovedFromMempool(const CTransactionRef&, MemPoolRemovalReason, uint64_t mempool_sequence);
     void MempoolTransactionsRemovedForBlock(const std::vector<RemovedMempoolTransactionInfo>&, unsigned int nBlockHeight);
-    void BlockConnected(const kernel::ChainstateRole&, const std::shared_ptr<const CBlock>&, const CBlockIndex* pindex);
-    void BlockDisconnected(const std::shared_ptr<const CBlock> &, const CBlockIndex* pindex);
+    void BlockConnected(const kernel::ChainstateRole&, std::shared_ptr<const CBlock>, const CBlockIndex* pindex);
+    void BlockDisconnected(std::shared_ptr<const CBlock>, const CBlockIndex* pindex);
     void ChainStateFlushed(const kernel::ChainstateRole&, const CBlockLocator&);
     void BlockChecked(const std::shared_ptr<const CBlock>&, const BlockValidationState&);
     void NewPoWValidBlock(const CBlockIndex *, const std::shared_ptr<const CBlock>&);