Add SimpleTimer class and registry for measuring point loads

Author: drebelsky

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,10 @@ 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, "sum"},
+            std::chrono::microseconds{1});
+        mPointTimers.emplace(static_cast<LedgerEntryType>(t), metric);
     }
 }
 
@@ -241,4 +230,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>