Manually measure "spike" metrics #4964

drebelsky · 2025-10-09T21:50:39Z

Resolves #4729. Implements a new class to use for timer replacement when timers are too expensive. For timers replaced in #4670, uses this new class. This class keeps track of the same sum and count metrics as introduced in #4670, but also keeps track of a max. Each max metric represents the max value since the previous /metrics call.

Other notes

I like SimpleTimer having the base unit as part of the type, but I can see a case for it to be switched such that we don't have the template. This is perhaps more relevant now that there is a SimpleTimer registry in BucketSnapshotManager (although the registry only produces SimpleTimer<std::chrono::microseconds> currently).
The /clear endpoint doesn't correctly reset the internal max tracker, but this just causes inaccuracies for the next syncMax() call

SimpleTimer registry

Initially,

The bucket metric uses static maps in its creation of the timer because all the timers need to share the same max. I chose to put the pseudo-registry as a static map because it felt like the least invasive change, especially if we might be removing Medida (#4945). I also couldn't think of a particularly better place to have a simple timer registry. With that said, one alternative would be to add a registry to Application, which would remove the need for much of the plumbing in this PR. Another would be to create a SimpleTimer.cpp and do the same sort of medida::MetricsRegistry -> simple timer registry map. One issue with the current approach and this last approach is that the pseudo-registry doesn't currently clean up old entries (e.g., in testing, each new Application will create a new entry in the pseudo-registry).

That caused errors because there wasn't a great way to clean up the registry on application destruction (putting it in e.g., ~BucketManager caused an error because ~ApplicationImpl was already called by then).

So, currently, it lives in BucketSnapshotManager. The only issue I have with that is that the SearchableBucketListSnapshotBase has a const ref to the manager, so there's a use of mutable on the map, which seems at least slightly misleading to me. (On the other hand, we do use mutable for a number of the metrics related variables in SearchableBucketListSnapshotBase.)

src/util/SimpleTimer.h

src/herder/TransactionQueue.h

src/overlay/OverlayManager.h

SirTyson

Thanks for this change! Our timers haven't been in a good place for sometime, and this will be very helpful in getting us back to a more feature rich and performant metrics system.

I've left a few comments. At a high level, I think this looks good, but we should probably do some refactoring. In general, this library seems a little complicated from the perspective of the user. There is a templated system that requires non-trivial constructor syntax with tuples and argument forwarding, and a pretty subtle requirement that the caller needs to expose a sync function when using this version of the timer, where our normal medida Timer is ready out of the box. Sometimes features are inherently complex, but I think we can probably avoid this code complexity for this particular case.

Additionally, this is a pretty sensitive perf change, as the reason we removed timers in the first place was due high overhead. While I think this looks good, I'd like to see some analysis with tracy to verify that this change doesn't add additional performance overhead.

One other procedural note, the commit history is very long and difficult to follow. For a reviewer, it's often helpful to step through commit by commit to follow along with the process and better understand the feature. The commits are so granular that it's challenging for me to follow your process. We'll of course rebase and squash when we actually merge, but I like to have each of my commits reflect a single logical change, feature, or refactor, as apposed to a line by line change log for the sake of PR review.

SirTyson · 2025-11-11T22:39:17Z

src/bucket/BucketSnapshotManager.h

    // Lock must be held when accessing any member variables holding snapshots
    mutable SharedMutex mSnapshotMutex;

+    mutable Mutex mSimpleTimerRegistryMutex;


I don't think it makes much sense for BucketSnapshotManager to manage the metrics registry. While this initial PR mostly deals with BucketList related loads, there are other time based metrics that also require simple timer, see "herder.pending[-soroban]-txs.sum". I think what makes the most sense to me is to create a lightweight wrapper that combines our SimpleTimer metric registry with medida::MetricsRegistry. Maybe we could call this something like stellar::MetricRegistry and have this be the entry point for both registries. This type would then be returned by Application::getMetrics.

That seems reasonable enough, I hadn't been sure if that was too intrusive of a change. Maybe worth noting that right now the registry is only for the snapshot metrics—the other SimpleTimers are owned by their respective classes.

Ya I think given the sync requirement and in order to maintain a unified interface with our other metrics, it would be helpful.

SirTyson · 2025-11-11T22:46:13Z

src/herder/TransactionQueue.h

-                     medida::Counter& transactionsDelayCounter,
-                     medida::Counter& transactionsSelfDelayAccumulator,
-                     medida::Counter& transactionsSelfDelayCounter,
+                     std::tuple<medida::MetricsRegistry&, std::string&&,


This seems overly complicated for an operation we do often (create a metric in a constructor). I think we can simplify this to a shared interface with app.getMetrics().getSimpleTimer() if we follow the wrapper suggestion from the comment in BucketSnapshotManager.h.

SirTyson · 2025-11-11T22:53:07Z

src/util/SimpleTimer.h

+// while keeping track of the maximums. Names are based on the constructor with
+// a suffix of `sum`, `count`, or `max`. Timers can be expensive, so this class
+// replaces them with a subset of the functionality using Counters internally.
+template <typename Duration> class SimpleTimer


Why do we have a templated duration here? In medida::Timer, it looks like all Timers have a duration of std::chrono::nanoseconds. We can always reduce resolution from ns and convert larger values, it seems like the duration is adding uncecessary caller complexity and also making our constructor/registration process more complicated.

Conceptually, the duration felt like a reasonable part of the type—I'll update, though.

src/util/SimpleTimer.h

SirTyson · 2025-11-11T22:58:00Z

src/util/SimpleTimer.h

+    // Specify `windowSize` to auto-call `syncMax` on every `Update` that takes
+    // place at least `windowSize` since the last `syncMax`.


I'm not sure what this comment means, given that there is no windowSize parameter.

Oops, that's left over from before the previous review.

SirTyson · 2025-11-11T22:59:35Z

src/util/SimpleTimer.h

+void
+SimpleTimer<Duration>::syncMax()
+{
+


Nit: extra whitespace

SirTyson · 2025-11-11T23:00:03Z

src/util/SimpleTimer.h

+    std::chrono::nanoseconds Stop();
+};
+
+template <typename Duration>


Nit: it would be nice to separate into a .cpp file to keep in line with our general code style.

Yep, will do now that I'm removing the template.

SirTyson · 2025-11-11T23:01:16Z

src/util/SimpleTimer.h

+        isDuration<Duration>,
+        "SimpleTimer must be instantiated with a std::chrono::duration");
+    medida::Counter& mSum;
+    medida::Counter& mCount;


I think the term "counter" is overloaded a bit here between mMaxCounter and mCount. Maybe change the names to be a little more clear, mSampleCount and mMaxSampleValue or something like that.

SirTyson · 2025-11-12T00:03:52Z

src/bucket/BucketManager.h


+    // Ensure any metrics that are "current state" gauge-like counters reflect
+    // the current reality as best as possible.
+    void syncMetrics();


I think the current design, where callers of the metric have to wire in a sync functionality, is flawed. While we do have some syncMetrics functions already, these are special cases, where the metric has something weird going on that the caller want to maintain. This is a bit different. Here we have a timer that just won't work properly unless synced and always requires the caller to manage sync. It looks like syncMetrics is thread safe. Could we not just call this from Application on all SimpleTimers registered? This would be much simpler, and shouldn't be too hard if we refactor the metrics registration to Application (or something similar).

drebelsky · 2025-11-12T21:29:50Z

Changed to do an application-wide registry that wraps medida::MetricsRegistry. This might be a little excessive for this PR (and I'm happy to separate so that we have, e.g., a getMetrics() and getSimpleTimerMetrics()), but it does also lead more nicely into potentially replacing medida later on.

SirTyson

Thank you for your changes! It looks like there was a bit of a painful find-replace on the refactor, but I appreciate it, the new unified interface is a lot cleaner and more streamlined. Overall I think this looks good and almost done, I just have a few nitpics, and one question about the duration parameter.

SirTyson · 2025-11-12T22:56:51Z

src/main/Application.h

 {
 }
-namespace medida
+namespace stellar


This can be removed and just use the stellar namespace bellow

SirTyson · 2025-11-12T22:57:05Z

src/main/Application.h

    // Get the registry of metrics owned by this application. Metrics are
    // reported through the administrative HTTP interface, see CommandHandler.
-    virtual medida::MetricsRegistry& getMetrics() = 0;
+    virtual stellar::MetricsRegistry& getMetrics() = 0;


I don't think stellar:: is necessary here

SirTyson · 2025-11-12T22:57:30Z

src/main/ApplicationImpl.cpp

    , mSelfCheckTimer(*this)
    , mMetrics(
-          std::make_unique<medida::MetricsRegistry>(cfg.HISTOGRAM_WINDOW_SIZE))
+          std::make_unique<stellar::MetricsRegistry>(cfg.HISTOGRAM_WINDOW_SIZE))


I don't think the stellar:: namespace is necessary in this file.

SirTyson · 2025-11-12T22:58:42Z

src/main/ApplicationImpl.cpp

        .set_count(fs::getOpenHandleCount());
+
+    // Update simple timer metrics
+    mMetrics->syncMaxes();


I think this would be a good place for a bit of a longer comment explaining why we need to periodically sync the SimpleTimer.

SirTyson · 2025-11-12T22:59:19Z

src/main/ApplicationImpl.h

    virtual bool isStopping() const override;
    virtual VirtualClock& getClock() override;
-    virtual medida::MetricsRegistry& getMetrics() override;
+    virtual stellar::MetricsRegistry& getMetrics() override;


For this and the rest of the file, I think we can drop the stellar when dealing with our new MetricsRegistry

SirTyson · 2025-11-12T23:01:59Z

src/util/MetricsRegistry.h

+
+    // Call syncMax() on each simple timer--i.e., set max metric to the tracked
+    // max, and reset max tracking.
+    void syncMaxes();


Can we make this a little more descriptive? Maybe syncSimpleTimerStats or syncSimpleTimerMaxes.

SirTyson · 2025-11-12T23:04:27Z

src/util/MetricsRegistry.h

+class MetricsRegistry : public medida::MetricsRegistry
+{
+    Mutex mLock;
+    // Note that we can use SimpleTimer instead of shared_ptr as medida does


Nit: I don't think I really understand this comment. I get that there's an implementation difference between this and the medida registry, but it seems like a very detailed explanation for something pretty straight forward, i.e., we just need to keep track of non-polymorphic timers so a map is fine.

There's a map in medida too—I was initially confused why medida used shared_ptrs for the value type (polymorphism + returning the map). Off the top of my head, I also didn't know that map iterators were stable, but I'm happy to remove the comment.

SirTyson · 2025-11-12T23:09:37Z

src/util/SimpleTimer.cpp

+
+SimpleTimer::SimpleTimer(MetricsRegistry& registry,
+                         medida::MetricName const& name,
+                         std::chrono::nanoseconds durationUnit)


Is this durationUnit parameter necessary? It looks like every other medidia::timer we use just uses the default duration unit. If this is correct, I'd rather just drop the param (or at least give it a default value) so SimpleTimer and medida::Timer maintain the same interface. If this isn't correct, we definitely need to look into it (outside the scope of this PR, but we'd need to file a follow up issue and at least investigate).

SirTyson · 2025-11-12T23:13:16Z

src/bucket/BucketListSnapshotBase.cpp

-            {BucketT::METRIC_STRING, label, "count"});
-        mPointCounters.emplace(static_cast<LedgerEntryType>(t), counter);
+        auto& metric = app.getMetrics().NewSimpleTimer(
+            {BucketT::METRIC_STRING, label, "sum"},


I think this label is incorrect, as it will have the name sum-sum

SirTyson · 2025-11-12T23:16:17Z

src/herder/TransactionQueue.cpp

-        app.getMetrics().NewCounter(
-            {"herder", "pending-soroban-txs", "self-count"}),
+        app.getMetrics().NewSimpleTimer(
+            {"herder", "pending-soroban-txs", "sum"},


Same issue here, this will get called sum-sum. Is there a better way to pass in label information? The current param is a little confusing, since it looks the same a NewTimer but is subtly different. Not a huge deal and I can't think of a better way off the top of my head, but just an observation since we have the same param bug repeated in a few places, and passing "" as the name seems counterintuitive.

drebelsky changed the title ~~DRAFT: Unify timer replacement implementation and add max tracking~~ DRAFT: Manually measure "spike" metrics Oct 9, 2025

drebelsky force-pushed the measure-spikes branch from 4030d71 to dbb6479 Compare October 21, 2025 16:47

drebelsky changed the title ~~DRAFT: Manually measure "spike" metrics~~ Manually measure "spike" metrics Oct 21, 2025

drebelsky force-pushed the measure-spikes branch 2 times, most recently from 1c22cf6 to 7f8ebc5 Compare October 22, 2025 21:22

bboston7 reviewed Oct 24, 2025

View reviewed changes

drebelsky force-pushed the measure-spikes branch from 6a79f8f to d76bba0 Compare November 3, 2025 18:32

drebelsky marked this pull request as ready for review November 6, 2025 18:07

drebelsky requested a review from bboston7 November 6, 2025 19:01

bboston7 previously approved these changes Nov 7, 2025

View reviewed changes

drebelsky requested a review from SirTyson November 7, 2025 06:45

SirTyson requested changes Nov 12, 2025

View reviewed changes

drebelsky dismissed bboston7’s stale review via 8eeec45 November 12, 2025 21:29

drebelsky force-pushed the measure-spikes branch from e9cb7e6 to 8eeec45 Compare November 12, 2025 21:29

drebelsky requested a review from SirTyson November 12, 2025 21:31

drebelsky force-pushed the measure-spikes branch from 8eeec45 to 25933b6 Compare November 12, 2025 22:46

Add SimpleTimer class and registry for measuring point loads

59f0670

drebelsky force-pushed the measure-spikes branch from 25933b6 to 59f0670 Compare November 12, 2025 22:47

SirTyson requested changes Nov 12, 2025

View reviewed changes

		// Specify `windowSize` to auto-call `syncMax` on every `Update` that takes
		// place at least `windowSize` since the last `syncMax`.

Manually measure "spike" metrics #4964

Are you sure you want to change the base?

Manually measure "spike" metrics #4964

Uh oh!

Conversation

drebelsky commented Oct 9, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

SirTyson left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

SirTyson Nov 11, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

drebelsky commented Nov 12, 2025

Uh oh!

SirTyson left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

SirTyson Nov 12, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

drebelsky commented Oct 9, 2025 •

edited

Loading

SirTyson left a comment •

edited

Loading

SirTyson Nov 11, 2025 •

edited

Loading

SirTyson Nov 12, 2025 •

edited

Loading