Manually measure "spike" metrics

docs/metrics.md

@@ -49,6 +49,7 @@ bucketlistDB-live.bulk.eviction           | timer     | time to load for evictio
 bucketlistDB-live.bulk.query              | timer     | time to load for query server
 bucketlistDB-<X>.<Y>.sum                  | counter   | sum of time (microseconds) to load single entry of type <Y> on BucketList <X> (live/hotArchive)
 bucketlistDB-<X>.<Y>.count                | counter   | number of times single entry of type <Y> on BucketList <X> (live/hotArchive) is loaded
+bucketlistDB-<X>.<Y>.max                  | counter   | max (since last metrics call) of time (microseconds) to load single entry of type <Y> on BucketList <X> (live/hotArchive)
 bucketlistDB-cache.hit                    | meter     | number of cache hits on Live BucketList Disk random eviction cache
 bucketlistDB-cache.miss                   | meter     | number of cache misses on Live BucketList Disk random eviction cache
 bucketlistDB.cache.entries                | counter   | number of entries currently in Live BucketList index cache
@@ -65,8 +66,10 @@ herder.pending[-soroban]-txs.age3         | counter   | number of gen3 pending t
 herder.pending[-soroban]-txs.banned       | counter   | number of transactions that got banned
 herder.pending[-soroban]-txs.sum          | counter   | sum of time (milliseconds) for transactions to be included in a ledger
 herder.pending[-soroban]-txs.count        | counter   | number of transactions to be included in a ledger
+herder.pending[-soroban]-txs.max          | counter   | largest time (milliseconds) for a transaction to be included in a ledger since last metrics call
 herder.pending[-soroban]-txs.self-sum     | counter   | sum of time (milliseconds) for transactions submitted from this node to be included in a ledger
 herder.pending[-soroban]-txs.self-count   | counter   | number of transactions submitted from this node to be included in a ledger
+herder.pending[-soroban]-txs.self-max     | counter   | largest time (milliseconds) for a transaction submitted from this node to be included in a ledger since last metrics call
 herder.pending[-soroban]-txs.evicted-due-to-low-fee-count   | counter   | Count of transactions evicted by higher fee txs when queue is near its capacity.
 herder.pending[-soroban]-txs.evicted-due-to-age-count   | counter   | Count of transactions that had low fee for too long and have not been included into several ledgers in a row.
 herder.pending[-soroban]-txs.not-included-due-to-low-fee-count   | counter   | Count of transactions that were not included into queue because it is at capacity and the fee is too low to replace other txs.
@@ -163,6 +166,7 @@ overlay.outbound.establish                | meter     | outbound connection esta
 overlay.recv.<X>                          | timer     | received message <X> (except transaction)
 overlay.recv-transaction.sum              | counter   | sum of time (microseconds) to receive transaction message
 overlay.recv-transaction.count            | counter   | number of transaction messages received
+overlay.recv-transaction.max              | counter   | maximum time (microseconds) to receive transaction message since last metrics call
 overlay.send.<X>                          | meter     | sent message <X>
 overlay.timeout.idle                      | meter     | idle peer timeout
 overlay.timeout.straggler                 | meter     | straggler peer timeout
@@ -273,4 +277,4 @@ soroban.module-cache.rebuild-bytes           | counter   | bytes of WASM bytecod
 soroban.in-memory-state.contract-code-size   | counter   | size in bytes of non-evicted ContractCode entries according to memory cost model
 soroban.in-memory-state.contract-data-size   | counter   | size in bytes of ContractData entries in memory
 soroban.in-memory-state.contract-code-entries   | counter   | number of ContractCode entries in memory
-soroban.in-memory-state.contract-data-entries   | counter   | number of ContractData entries in memory
+soroban.in-memory-state.contract-data-entries   | counter   | number of ContractData entries in memory

src/bucket/BucketListSnapshotBase.cpp

@@ -10,7 +10,7 @@
 #include "main/AppConnector.h"
 
 #include "util/GlobalChecks.h"
-#include <medida/metrics_registry.h>
+#include "util/MetricsRegistry.h"
 #include <optional>
 #include <vector>
 
@@ -89,7 +89,9 @@ SearchableBucketListSnapshotBase<BucketT>::load(LedgerKey const& k) const
     ZoneScoped;
 
     std::shared_ptr<typename BucketT::LoadT const> result{};
-    auto startTime = mAppConnector.now();
+    auto timerIter = mPointTimers.find(k.type());
+    releaseAssert(timerIter != mPointTimers.end());
+    auto timer = timerIter->second.TimeScope();
 
     // Search function called on each Bucket in BucketList until we find the key
     auto loadKeyBucketLoop = [&](auto const& b) {
@@ -98,7 +100,7 @@ SearchableBucketListSnapshotBase<BucketT>::load(LedgerKey const& k) const
         {
             // Reset timer on bloom miss to avoid outlier metrics, since we
             // really only want to measure disk performance
-            startTime = mAppConnector.now();
+            timer.Reset();
         }
 
         if (be)
@@ -113,17 +115,6 @@ SearchableBucketListSnapshotBase<BucketT>::load(LedgerKey const& k) const
     };
 
     loopAllBuckets(loadKeyBucketLoop, *mSnapshot);
-    auto endTime = mAppConnector.now();
-    auto duration = std::chrono::duration_cast<std::chrono::microseconds>(
-        endTime - startTime);
-
-    auto accumulatorIter = mPointAccumulators.find(k.type());
-    releaseAssert(accumulatorIter != mPointAccumulators.end());
-    accumulatorIter->second.inc(duration.count());
-
-    auto counterIter = mPointCounters.find(k.type());
-    releaseAssert(counterIter != mPointCounters.end());
-    counterIter->second.inc();
 
     return result;
 }
@@ -200,12 +191,9 @@ SearchableBucketListSnapshotBase<BucketT>::SearchableBucketListSnapshotBase(
     {
         auto const& label = xdr::xdr_traits<LedgerEntryType>::enum_name(
             static_cast<LedgerEntryType>(t));
-        auto& metric =
-            app.getMetrics().NewCounter({BucketT::METRIC_STRING, label, "sum"});
-        mPointAccumulators.emplace(static_cast<LedgerEntryType>(t), metric);
-        auto& counter = app.getMetrics().NewCounter(
-            {BucketT::METRIC_STRING, label, "count"});
-        mPointCounters.emplace(static_cast<LedgerEntryType>(t), counter);
+        auto& metric = app.getMetrics().NewSimpleTimer(
+            {BucketT::METRIC_STRING, label}, std::chrono::microseconds{1});
+        mPointTimers.emplace(static_cast<LedgerEntryType>(t), metric);
     }
 }
 
@@ -241,4 +229,4 @@ template class BucketListSnapshot<LiveBucket>;
 template class BucketListSnapshot<HotArchiveBucket>;
 template class SearchableBucketListSnapshotBase<LiveBucket>;
 template class SearchableBucketListSnapshotBase<HotArchiveBucket>;
-}
+}

src/bucket/BucketListSnapshotBase.h

@@ -11,6 +11,7 @@
 #include "bucket/BucketUtils.h"
 #include "bucket/HotArchiveBucket.h"
 #include "bucket/LiveBucket.h"
+#include "util/SimpleTimer.h"
 
 namespace medida
 {
@@ -91,9 +92,8 @@ class SearchableBucketListSnapshotBase : public NonMovableOrCopyable
 
     // Tracks the sum of point load times for each LedgerEntryType, in
     // microseconds. For point loads, Timers are too expensive to maintain, so
-    // we use a Counter to keep track of the total trend instead.
-    UnorderedMap<LedgerEntryType, medida::Counter&> mPointAccumulators{};
-    UnorderedMap<LedgerEntryType, medida::Counter&> mPointCounters{};
+    // we use SimpleTimer.
+    UnorderedMap<LedgerEntryType, SimpleTimer&> mPointTimers{};
 
     // Bulk load timers take significantly longer, so the timer overhead is
     // comparatively negligible.
@@ -150,4 +150,4 @@ class SearchableBucketListSnapshotBase : public NonMovableOrCopyable
     std::shared_ptr<typename BucketT::LoadT const>
     load(LedgerKey const& k) const;
 };
-}
+}

src/bucket/BucketManager.cpp

@@ -27,6 +27,7 @@
 #include "util/GlobalChecks.h"
 #include "util/LogSlowExecution.h"
 #include "util/Logging.h"
+#include "util/MetricsRegistry.h"
 #include "util/ProtocolVersion.h"
 #include "util/TmpDir.h"
 #include "util/UnorderedMap.h"
@@ -44,7 +45,6 @@
 #include "history/FileTransferInfo.h"
 #include "medida/counter.h"
 #include "medida/meter.h"
-#include "medida/metrics_registry.h"
 #include "medida/timer.h"
 #include "work/WorkScheduler.h"
 #include "xdrpp/printer.h"

src/bucket/BucketUtils.cpp

@@ -8,11 +8,11 @@
 #include "ledger/LedgerTypeUtils.h"
 #include "main/AppConnector.h"
 #include "main/Application.h"
+#include "util/MetricsRegistry.h"
 #include "util/types.h"
 #include "xdr/Stellar-ledger-entries.h"
 #include <fmt/format.h>
 #include <medida/counter.h>
-#include <medida/metrics_registry.h>
 
 namespace stellar
 {

src/bucket/FutureBucket.cpp

@@ -20,13 +20,12 @@
 #include "util/GlobalChecks.h"
 #include "util/LogSlowExecution.h"
 #include "util/Logging.h"
+#include "util/MetricsRegistry.h"
 #include "util/ProtocolVersion.h"
 #include "util/Thread.h"
 #include <Tracy.hpp>
 #include <fmt/format.h>
 
-#include "medida/metrics_registry.h"
-
 #include <chrono>
 #include <memory>
 #include <type_traits>

src/catchup/LedgerApplyManagerImpl.cpp

@@ -13,9 +13,9 @@
 #include "ledger/LedgerManager.h"
 #include "main/Application.h"
 #include "medida/meter.h"
-#include "medida/metrics_registry.h"
 #include "util/GlobalChecks.h"
 #include "util/Logging.h"
+#include "util/MetricsRegistry.h"
 #include "util/StatusManager.h"
 #include "work/WorkScheduler.h"
 #include <Tracy.hpp>

src/database/Database.cpp

@@ -13,6 +13,7 @@
 #include "util/Fs.h"
 #include "util/GlobalChecks.h"
 #include "util/Logging.h"
+#include "util/MetricsRegistry.h"
 #include "util/Timer.h"
 #include "util/types.h"
 #include <error.h>
@@ -31,7 +32,6 @@
 #include "transactions/TransactionSQL.h"
 
 #include "medida/counter.h"
-#include "medida/metrics_registry.h"
 #include "medida/timer.h"
 #include "xdr/Stellar-ledger-entries.h"
 

src/herder/HerderImpl.cpp

@@ -28,7 +28,6 @@
 #include "main/PersistentState.h"
 #include "medida/counter.h"
 #include "medida/meter.h"
-#include "medida/metrics_registry.h"
 #include "overlay/OverlayManager.h"
 #include "process/ProcessManager.h"
 #include "scp/LocalNode.h"
@@ -40,6 +39,7 @@
 #include "util/LogSlowExecution.h"
 #include "util/Logging.h"
 #include "util/Math.h"
+#include "util/MetricsRegistry.h"
 #include "util/StatusManager.h"
 #include "util/Timer.h"
 #include "util/XDRStream.h"

src/herder/HerderSCPDriver.cpp

@@ -19,6 +19,7 @@
 #include "scp/Slot.h"
 #include "util/Logging.h"
 #include "util/Math.h"
+#include "util/MetricsRegistry.h"
 #include "util/ProtocolVersion.h"
 #include "xdr/Stellar-SCP.h"
 #include "xdr/Stellar-ledger-entries.h"
@@ -27,7 +28,6 @@
 #include <algorithm>
 #include <cmath>
 #include <fmt/format.h>
-#include <medida/metrics_registry.h>
 #include <numeric>
 #include <optional>
 #include <stdexcept>

src/herder/PendingEnvelopes.cpp

@@ -12,6 +12,7 @@
 #include "scp/Slot.h"
 #include "util/GlobalChecks.h"
 #include "util/Logging.h"
+#include "util/MetricsRegistry.h"
 #include "util/UnorderedSet.h"
 #include <Tracy.hpp>
 #include <xdrpp/marshal.h>

src/herder/QuorumIntersectionChecker.h

@@ -12,17 +12,13 @@
 #include <memory>
 #include <optional>
 
-namespace medida
-{
-class MetricsRegistry;
-}
-
 namespace stellar
 {
 
 class Config;
 class Application;
 class TmpDir;
+class MetricsRegistry;
 
 struct QuorumMapIntersectionState
 {
@@ -39,7 +35,7 @@ struct QuorumMapIntersectionState
     std::unique_ptr<TmpDir> mTmpDir;
 
     QuorumCheckerStatus mStatus{QuorumCheckerStatus::UNKNOWN};
-    medida::MetricsRegistry& mMetrics;
+    MetricsRegistry& mMetrics;
     std::pair<std::vector<PublicKey>, std::vector<PublicKey>> mPotentialSplit{};
     std::set<std::set<PublicKey>> mIntersectionCriticalNodes{};
 

src/herder/RustQuorumCheckerAdaptor.cpp

@@ -8,7 +8,6 @@
 #include "herder/HerderUtils.h"
 #include "herder/QuorumIntersectionChecker.h"
 #include "medida/meter.h"
-#include "medida/metrics_registry.h"
 #include "process/ProcessManager.h"
 #include "rust/RustBridge.h"
 #include "scp/LocalNode.h"
@@ -330,7 +329,7 @@ QuorumCheckerMetrics::toJson()
 }
 
 void
-QuorumCheckerMetrics::flush(medida::MetricsRegistry& metrics)
+QuorumCheckerMetrics::flush(MetricsRegistry& metrics)
 {
     metrics.NewCounter({"scp", "qic", "successful-run"}).inc(mSuccessfulRun);
     metrics.NewCounter({"scp", "qic", "failed-run"}).inc(mFailedRun);
@@ -623,4 +622,4 @@ runQuorumIntersectionCheckAsync(
 }
 
 } // namespace quorum_checker
-} // namespace stellar
+} // namespace stellar

src/herder/RustQuorumCheckerAdaptor.h

@@ -8,6 +8,7 @@
 #include "main/Config.h"
 #include "process/ProcessManager.h"
 #include "rust/RustBridge.h"
+#include "util/MetricsRegistry.h"
 #include <optional>
 
 namespace Json
@@ -39,7 +40,7 @@ struct QuorumCheckerMetrics
     QuorumCheckerMetrics();
     QuorumCheckerMetrics(Json::Value const& value);
     Json::Value toJson();
-    void flush(medida::MetricsRegistry& metrics);
+    void flush(MetricsRegistry& metrics);
 };
 
 // In-process quorum intersection checker that directly calls the Rust

src/herder/TransactionQueue.cpp

@@ -22,6 +22,7 @@
 #include "util/GlobalChecks.h"
 #include "util/HashOfHash.h"
 #include "util/Math.h"
+#include "util/MetricsRegistry.h"
 #include "util/ProtocolVersion.h"
 #include "util/TarjanSCCCalculator.h"
 #include "util/XDROperators.h"
@@ -33,7 +34,6 @@
 #include <functional>
 #include <limits>
 #include <medida/meter.h>
-#include <medida/metrics_registry.h>
 #include <medida/timer.h>
 #include <numeric>
 #include <optional>
@@ -131,10 +131,8 @@ ClassicTransactionQueue::ClassicTransactionQueue(Application& app,
     mQueueMetrics = std::make_unique<QueueMetrics>(
         sizeByAge,
         app.getMetrics().NewCounter({"herder", "pending-txs", "banned"}),
-        app.getMetrics().NewCounter({"herder", "pending-txs", "sum"}),
-        app.getMetrics().NewCounter({"herder", "pending-txs", "count"}),
-        app.getMetrics().NewCounter({"herder", "pending-txs", "self-sum"}),
-        app.getMetrics().NewCounter({"herder", "pending-txs", "self-count"}),
+        app.getMetrics().NewSimpleTimer({"herder", "pending-txs"}),
+        app.getMetrics().NewSimpleTimer({"herder", "pending-txs", "self-"}),
         app.getMetrics().NewCounter(
             {"herder", "pending-txs", "evicted-due-to-low-fee-count"}),
         app.getMetrics().NewCounter(
@@ -781,17 +779,12 @@ TransactionQueue::removeApplied(Transactions const& appliedTxs)
                     if (transaction->mTx->getFullHash() ==
                         appliedTx->getFullHash())
                     {
-                        auto elapsed = std::chrono::duration_cast<
-                            std::chrono::milliseconds>(
-                            now - transaction->mInsertionTime);
-                        mQueueMetrics->mTransactionsDelayAccumulator.inc(
-                            elapsed.count());
-                        mQueueMetrics->mTransactionsDelayCounter.inc();
+                        auto elapsed = now - transaction->mInsertionTime;
+                        mQueueMetrics->mTransactionsDelay.Update(elapsed);
                         if (transaction->mSubmittedFromSelf)
                         {
-                            mQueueMetrics->mTransactionsSelfDelayAccumulator
-                                .inc(elapsed.count());
-                            mQueueMetrics->mTransactionsSelfDelayCounter.inc();
+                            mQueueMetrics->mTransactionsSelfDelay.Update(
+                                elapsed);
                         }
                     }
 
@@ -1087,12 +1080,9 @@ SorobanTransactionQueue::SorobanTransactionQueue(
         sizeByAge,
         app.getMetrics().NewCounter(
             {"herder", "pending-soroban-txs", "banned"}),
-        app.getMetrics().NewCounter({"herder", "pending-soroban-txs", "sum"}),
-        app.getMetrics().NewCounter({"herder", "pending-soroban-txs", "count"}),
-        app.getMetrics().NewCounter(
-            {"herder", "pending-soroban-txs", "self-sum"}),
-        app.getMetrics().NewCounter(
-            {"herder", "pending-soroban-txs", "self-count"}),
+        app.getMetrics().NewSimpleTimer({"herder", "pending-soroban-txs"}),
+        app.getMetrics().NewSimpleTimer(
+            {"herder", "pending-soroban-txs", "self-"}),
         app.getMetrics().NewCounter(
             {"herder", "pending-soroban-txs", "evicted-due-to-low-fee-count"}),
         app.getMetrics().NewCounter(