feat: also log the islock time, and erase the received at time; conditional on either stats or logger being active

Author: PastaPastaPasta

src/llmq/instantsend.cpp

@@ -742,6 +742,10 @@ PeerMsgRet CInstantSendManager::ProcessMessage(const CNode& pfrom, PeerManager&
     return {};
 }
 
+bool ShouldReportISLockTiming() {
+    return g_stats_client->active() || LogAcceptDebug(BCLog::INSTANTSEND);
+}
+
 PeerMsgRet CInstantSendManager::ProcessMessageInstantSendLock(const CNode& pfrom, PeerManager& peerman,
                                                               const llmq::CInstantSendLockPtr& islock)
 {
@@ -775,16 +779,22 @@ PeerMsgRet CInstantSendManager::ProcessMessageInstantSendLock(const CNode& pfrom
     LogPrint(BCLog::INSTANTSEND, "CInstantSendManager::%s -- txid=%s, islock=%s: received islock, peer=%d\n", __func__,
             islock->txid.ToString(), hash.ToString(), pfrom.GetId());
 
-    auto time_diff =  [&] () -> int64_t {
-        LOCK(cs_timingsTxSeen);
-        if (auto it = timingsTxSeen.find(islock->txid); it != timingsTxSeen.end()) {
-            // This is the normal case where we received the TX before the islock
-            return GetTimeMillis() - it->second;
-        }
-        // But if we received the islock and don't know when we got the tx, then say 0, to indicate we received the islock first.
-        return 0;
-    }();
-    ::g_stats_client->timing("islock_ms", time_diff);
+    if (ShouldReportISLockTiming()) {
+        auto time_diff =  [&] () -> int64_t {
+            LOCK(cs_timingsTxSeen);
+            if (auto it = timingsTxSeen.find(islock->txid); it != timingsTxSeen.end()) {
+                // This is the normal case where we received the TX before the islock
+                auto diff = GetTimeMillis() - it->second;
+                timingsTxSeen.erase(it);
+                return diff;
+            }
+            // But if we received the islock and don't know when we got the tx, then say 0, to indicate we received the islock first.
+            return 0;
+        }();
+        ::g_stats_client->timing("islock_ms", time_diff);
+        LogPrint(BCLog::INSTANTSEND, "CInstantSendManager::%s -- txid=%s, islock took %dms\n", __func__,
+            islock->txid.ToString(), time_diff);
+    }
 
     LOCK(cs_pendingLocks);
     pendingInstantSendLocks.emplace(hash, std::make_pair(pfrom.GetId(), islock));
@@ -1180,7 +1190,7 @@ void CInstantSendManager::AddNonLockedTx(const CTransactionRef& tx, const CBlock
         }
     }
 
-    {
+    if (ShouldReportISLockTiming()) {
         LOCK(cs_timingsTxSeen);
         // Only insert the time the first time we see the tx, as we sometimes try to resign
         if (auto it = timingsTxSeen.find(tx->GetHash()); it == timingsTxSeen.end()) {