From ab3598b1aac8f0a8aaba0f05d9ba218ddff45c58 Mon Sep 17 00:00:00 2001 From: pasta Date: Wed, 28 Aug 2024 11:06:24 -0500 Subject: [PATCH 1/5] feat: add transactions.mempool.lockedTransactions and chainlocks.blockHeight stats --- src/init.cpp | 5 +++-- src/llmq/chainlocks.cpp | 2 ++ 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/src/init.cpp b/src/init.cpp index 88e981898acca..4fc2c13548942 100644 --- a/src/init.cpp +++ b/src/init.cpp @@ -832,7 +832,7 @@ static void StartupNotify(const ArgsManager& args) } #endif -static void PeriodicStats(ArgsManager& args, ChainstateManager& chainman, const CTxMemPool& mempool) +static void PeriodicStats(ArgsManager& args, ChainstateManager& chainman, const CTxMemPool& mempool, const llmq::CInstantSendManager& isman) { assert(args.GetBoolArg("-statsenabled", DEFAULT_STATSD_ENABLE)); CCoinsStats stats{CoinStatsHashType::NONE}; @@ -882,6 +882,7 @@ static void PeriodicStats(ArgsManager& args, ChainstateManager& chainman, const statsClient.gauge("transactions.mempool.memoryUsageBytes", (int64_t) mempool.DynamicMemoryUsage(), 1.0f); statsClient.gauge("transactions.mempool.minFeePerKb", mempool.GetMinFee(args.GetArg("-maxmempool", DEFAULT_MAX_MEMPOOL_SIZE) * 1000000).GetFeePerK(), 1.0f); } + statsClient.gauge("transactions.mempool.lockedTransactions", isman.GetInstantSendLockCount(), 1.0f); } static bool AppInitServers(NodeContext& node) @@ -2241,7 +2242,7 @@ bool AppInitMain(NodeContext& node, interfaces::BlockAndHeaderTipInfo* tip_info) if (args.GetBoolArg("-statsenabled", DEFAULT_STATSD_ENABLE)) { int nStatsPeriod = std::min(std::max((int)args.GetArg("-statsperiod", DEFAULT_STATSD_PERIOD), MIN_STATSD_PERIOD), MAX_STATSD_PERIOD); - node.scheduler->scheduleEvery(std::bind(&PeriodicStats, std::ref(*node.args), std::ref(chainman), std::cref(*node.mempool)), std::chrono::seconds{nStatsPeriod}); + node.scheduler->scheduleEvery(std::bind(&PeriodicStats, std::ref(*node.args), std::ref(chainman), std::cref(*node.mempool), std::cref(*node.llmq_ctx->isman)), std::chrono::seconds{nStatsPeriod}); } // ********************************************************* Step 11: import blocks diff --git a/src/llmq/chainlocks.cpp b/src/llmq/chainlocks.cpp index 39130b5a07ecf..3090c93bedc68 100644 --- a/src/llmq/chainlocks.cpp +++ b/src/llmq/chainlocks.cpp @@ -16,6 +16,7 @@ #include #include #include +#include #include #include #include @@ -519,6 +520,7 @@ void CChainLocksHandler::EnforceBestChainLock() GetMainSignals().NotifyChainLock(currentBestChainLockBlockIndex, clsig); uiInterface.NotifyChainLock(clsig->getBlockHash().ToString(), clsig->getHeight()); + statsClient.gauge("chainlocks.blockHeight", clsig->getHeight(), 1.0f); } void CChainLocksHandler::HandleNewRecoveredSig(const llmq::CRecoveredSig& recoveredSig) From f2fbc7c41181a534e4966125edf2ed48825d0357 Mon Sep 17 00:00:00 2001 From: pasta Date: Wed, 28 Aug 2024 19:02:29 -0500 Subject: [PATCH 2/5] fix: add 1 to tip.Height so output matches RPCs such as getblockcount --- src/validation.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/validation.cpp b/src/validation.cpp index b4f7c2c422ba1..67fc85a4a0560 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -2284,7 +2284,7 @@ bool CChainState::ConnectBlock(const CBlock& block, BlockValidationState& state, statsClient.timing("ConnectBlock_ms", (nTime8 - nTimeStart) / 1000, 1.0f); statsClient.gauge("blocks.tip.SizeBytes", ::GetSerializeSize(block, PROTOCOL_VERSION), 1.0f); - statsClient.gauge("blocks.tip.Height", m_chain.Height(), 1.0f); + statsClient.gauge("blocks.tip.Height", m_chain.Height() + 1, 1.0f); // without the +1, the "tip.Height" doesn't match rpc calls like `getblockcount` statsClient.gauge("blocks.tip.Version", block.nVersion, 1.0f); statsClient.gauge("blocks.tip.NumTransactions", block.vtx.size(), 1.0f); statsClient.gauge("blocks.tip.SigOps", nSigOps, 1.0f); From 763e4fcc2e79942193a0c8494a2d8b6e18623696 Mon Sep 17 00:00:00 2001 From: pasta Date: Wed, 28 Aug 2024 19:03:08 -0500 Subject: [PATCH 3/5] feat: implement masternode counts in stats --- src/evo/deterministicmns.cpp | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/src/evo/deterministicmns.cpp b/src/evo/deterministicmns.cpp index b75c1403c2784..70dfedbab2b38 100644 --- a/src/evo/deterministicmns.cpp +++ b/src/evo/deterministicmns.cpp @@ -20,6 +20,7 @@ #include #include #include +#include #include #include @@ -641,6 +642,15 @@ bool CDeterministicMNManager::ProcessBlock(const CBlock& block, gsl::not_nullGetBlockHash()) { LogPrintf("CDeterministicMNManager::%s -- DIP3 enforcement block has wrong hash: hash=%s, expected=%s, nHeight=%d\n", __func__, From 63241c253262c573e0408c85023604a1e681e890 Mon Sep 17 00:00:00 2001 From: pasta Date: Wed, 28 Aug 2024 19:22:38 -0500 Subject: [PATCH 4/5] feat: add islock timing statistics --- src/llmq/instantsend.cpp | 21 +++++++++++++++++++++ src/llmq/instantsend.h | 3 +++ 2 files changed, 24 insertions(+) diff --git a/src/llmq/instantsend.cpp b/src/llmq/instantsend.cpp index 037dd2f1f661c..7821126a9c584 100644 --- a/src/llmq/instantsend.cpp +++ b/src/llmq/instantsend.cpp @@ -23,6 +23,7 @@ #include #include #include +#include #include @@ -790,6 +791,17 @@ 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; + }(); + statsClient.timing("islock_ms", time_diff); + LOCK(cs_pendingLocks); pendingInstantSendLocks.emplace(hash, std::make_pair(pfrom.GetId(), islock)); return {}; @@ -1179,6 +1191,15 @@ void CInstantSendManager::AddNonLockedTx(const CTransactionRef& tx, const CBlock ++it; } } + + { + 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()) { + timingsTxSeen[tx->GetHash()] = GetTimeMillis(); + } + } + LogPrint(BCLog::INSTANTSEND, "CInstantSendManager::%s -- txid=%s, pindexMined=%s\n", __func__, tx->GetHash().ToString(), pindexMined ? pindexMined->GetBlockHash().ToString() : ""); } diff --git a/src/llmq/instantsend.h b/src/llmq/instantsend.h index 733d2afd7a4f9..78a57e0e946c4 100644 --- a/src/llmq/instantsend.h +++ b/src/llmq/instantsend.h @@ -254,6 +254,9 @@ class CInstantSendManager : public CRecoveredSigsListener mutable Mutex cs_pendingRetry; std::unordered_set pendingRetryTxs GUARDED_BY(cs_pendingRetry); + mutable Mutex cs_timingsTxSeen; + std::unordered_map timingsTxSeen GUARDED_BY(cs_timingsTxSeen); + public: explicit CInstantSendManager(CChainLocksHandler& _clhandler, CChainState& chainstate, CConnman& _connman, CQuorumManager& _qman, CSigningManager& _sigman, CSigSharesManager& _shareman, From 2f26f788e140b80793b787dcc5e12f48222d0e95 Mon Sep 17 00:00:00 2001 From: UdjinM6 Date: Thu, 5 Sep 2024 23:48:40 +0300 Subject: [PATCH 5/5] fix: update `blocks.tip.*` stats in `ConnectTip`/`DisconnectTip` instead of `ConnectBlock` --- src/validation.cpp | 29 ++++++++++++++++++++++++----- 1 file changed, 24 insertions(+), 5 deletions(-) diff --git a/src/validation.cpp b/src/validation.cpp index 67fc85a4a0560..e84cea7366412 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -2283,11 +2283,6 @@ bool CChainState::ConnectBlock(const CBlock& block, BlockValidationState& state, LogPrint(BCLog::BENCHMARK, " - Callbacks: %.2fms [%.2fs (%.2fms/blk)]\n", MILLI * (nTime8 - nTime5), nTimeCallbacks * MICRO, nTimeCallbacks * MILLI / nBlocksTotal); statsClient.timing("ConnectBlock_ms", (nTime8 - nTimeStart) / 1000, 1.0f); - statsClient.gauge("blocks.tip.SizeBytes", ::GetSerializeSize(block, PROTOCOL_VERSION), 1.0f); - statsClient.gauge("blocks.tip.Height", m_chain.Height() + 1, 1.0f); // without the +1, the "tip.Height" doesn't match rpc calls like `getblockcount` - statsClient.gauge("blocks.tip.Version", block.nVersion, 1.0f); - statsClient.gauge("blocks.tip.NumTransactions", block.vtx.size(), 1.0f); - statsClient.gauge("blocks.tip.SigOps", nSigOps, 1.0f); return true; } @@ -2579,6 +2574,8 @@ bool CChainState::DisconnectTip(BlockValidationState& state, DisconnectedBlockTr AssertLockHeld(cs_main); if (m_mempool) AssertLockHeld(m_mempool->cs); + int64_t nTime1 = GetTimeMicros(); + CBlockIndex *pindexDelete = m_chain.Tip(); assert(pindexDelete); // Read block from disk. @@ -2625,6 +2622,19 @@ bool CChainState::DisconnectTip(BlockValidationState& state, DisconnectedBlockTr // Let wallets know transactions went from 1-confirmed to // 0-confirmed or conflicted: GetMainSignals().BlockDisconnected(pblock, pindexDelete); + + int64_t nTime2 = GetTimeMicros(); + + unsigned int nSigOps = 0; + for (const auto& tx : block.vtx) { + nSigOps += GetLegacySigOpCount(*tx); + } + statsClient.timing("DisconnectTip_ms", (nTime2 - nTime1) / 1000, 1.0f); + statsClient.gauge("blocks.tip.SizeBytes", ::GetSerializeSize(block, PROTOCOL_VERSION), 1.0f); + statsClient.gauge("blocks.tip.Height", m_chain.Height(), 1.0f); + statsClient.gauge("blocks.tip.Version", block.nVersion, 1.0f); + statsClient.gauge("blocks.tip.NumTransactions", block.vtx.size(), 1.0f); + statsClient.gauge("blocks.tip.SigOps", nSigOps, 1.0f); return true; } @@ -2743,7 +2753,16 @@ bool CChainState::ConnectTip(BlockValidationState& state, CBlockIndex* pindexNew LogPrint(BCLog::BENCHMARK, " - Connect postprocess: %.2fms [%.2fs (%.2fms/blk)]\n", (nTime6 - nTime5) * MILLI, nTimePostConnect * MICRO, nTimePostConnect * MILLI / nBlocksTotal); LogPrint(BCLog::BENCHMARK, "- Connect block: %.2fms [%.2fs (%.2fms/blk)]\n", (nTime6 - nTime1) * MILLI, nTimeTotal * MICRO, nTimeTotal * MILLI / nBlocksTotal); + unsigned int nSigOps = 0; + for (const auto& tx : blockConnecting.vtx) { + nSigOps += GetLegacySigOpCount(*tx); + } statsClient.timing("ConnectTip_ms", (nTime6 - nTime1) / 1000, 1.0f); + statsClient.gauge("blocks.tip.SizeBytes", ::GetSerializeSize(blockConnecting, PROTOCOL_VERSION), 1.0f); + statsClient.gauge("blocks.tip.Height", m_chain.Height(), 1.0f); + statsClient.gauge("blocks.tip.Version", blockConnecting.nVersion, 1.0f); + statsClient.gauge("blocks.tip.NumTransactions", blockConnecting.vtx.size(), 1.0f); + statsClient.gauge("blocks.tip.SigOps", nSigOps, 1.0f); connectTrace.BlockConnected(pindexNew, std::move(pthisBlock)); return true;