From 61b101e1472e1f217182889fa1edbebe656d915e Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Tue, 28 Jul 2026 18:24:07 +0100 Subject: [PATCH 1/2] fix(nodestore): sample writer depth over one population Depth was observed at insert entry but its sample was only counted at insert exit, so an insert still in flight contributed nothing to the mean while completed inserts -- disproportionately the fast, shallow ones -- all did. The reported mean understated queueing exactly when queueing was worst: with every writer inside its first insert the gauge was omitted entirely, while writers-in-flight correctly showed them all. Depth and its sample count are now both folded in at entry, so the mean is taken over one population. Mean depth is the L in Little's Law, so a biased L understated the derived queueing share of each insert. Co-Authored-By: Claude Opus 5 (1M context) --- include/xrpl/nodestore/WriteStats.h | 13 ++++++++-- src/libxrpl/nodestore/backend/NuDBFactory.cpp | 24 +++++++++++++++++-- src/xrpld/telemetry/MetricsRegistry.cpp | 9 ++++++- 3 files changed, 41 insertions(+), 5 deletions(-) diff --git a/include/xrpl/nodestore/WriteStats.h b/include/xrpl/nodestore/WriteStats.h index 08d4529960..11aafff0c9 100644 --- a/include/xrpl/nodestore/WriteStats.h +++ b/include/xrpl/nodestore/WriteStats.h @@ -25,7 +25,7 @@ namespace xrpl::node_store { * | * concurrentWriters = queue length here * insertTotalUs / insertCount = time in the whole system (W) - * depthSum / insertCount = mean depth (L) + * depthSum / depthSamples = mean depth (L) * * @note All fields except @ref concurrentWriters are cumulative for the * life of the backend, so a reader must difference successive @@ -38,7 +38,7 @@ namespace xrpl::node_store { * if (auto const s = backend->getWriteStats(); s && s->insertCount) * { * double const meanUs = double(s->insertTotalUs) / s->insertCount; - * double const meanDepth = double(s->depthSum) / s->insertCount; + * double const meanDepth = double(s->depthSum) / s->depthSamples; * double const serviceUs = meanUs / meanDepth; // Little's Law * } * @endcode @@ -76,6 +76,15 @@ struct WriteStats * @ref insertCount this gives mean depth. */ std::uint64_t depthSum = 0; + + /** + * Number of depth samples summed into @ref depthSum. + * + * Divide @ref depthSum by this, not by @ref insertCount: a sample is + * taken when an insert starts, while insertCount only rises when one + * finishes, so the two populations differ while inserts are in flight. + */ + std::uint64_t depthSamples = 0; }; } // namespace xrpl::node_store diff --git a/src/libxrpl/nodestore/backend/NuDBFactory.cpp b/src/libxrpl/nodestore/backend/NuDBFactory.cpp index 4f19283c8e..26b1af1037 100644 --- a/src/libxrpl/nodestore/backend/NuDBFactory.cpp +++ b/src/libxrpl/nodestore/backend/NuDBFactory.cpp @@ -87,10 +87,21 @@ public: std::atomic insertMaxUs{0}; /** - * Summed depth observed at each insert. + * Summed depth observed at each insert, accumulated at insert entry. */ std::atomic depthSum{0}; + /** + * How many depth samples make up @ref depthSum. + * + * Its own counter rather than reusing the completed-insert count, because + * the two are taken at different moments: a depth sample exists as soon + * as an insert starts, while the insert count only rises when one + * finishes. Dividing by the wrong one biases the mean downward under + * load, which is when the mean matters. + */ + std::atomic depthSamples{0}; + NuDBBackend( size_t keyBytes, Section const& keyValues, @@ -270,7 +281,16 @@ public: // NuDB takes one global mutex for the whole insert, so the wait is // invisible from here. Record the depth we joined at and the wall // time we spent; the split follows from Little's Law. + // + // Depth and its sample count are both folded in HERE, at entry, so + // the mean is over the same population. Counting the sample at exit + // instead would drop every insert still in flight, and those are the + // slow, deep ones -- biasing the mean down exactly when queueing is + // worst. With all writers inside their first insert the exit-counted + // version reports no depth at all. auto const depth = concurrentWriters.fetch_add(1, std::memory_order_relaxed) + 1; + depthSum.fetch_add(depth, std::memory_order_relaxed); + depthSamples.fetch_add(1, std::memory_order_relaxed); auto const begin = std::chrono::steady_clock::now(); // A scope guard rather than straight-line code, because the insert @@ -369,6 +389,7 @@ public: stats.insertTotalUs = insertTotalUs.load(std::memory_order_relaxed); stats.insertMaxUs = insertMaxUs.load(std::memory_order_relaxed); stats.depthSum = depthSum.load(std::memory_order_relaxed); + stats.depthSamples = depthSamples.load(std::memory_order_relaxed); return stats; } @@ -424,7 +445,6 @@ private: concurrentWriters.fetch_sub(1, std::memory_order_relaxed); insertCount.fetch_add(1, std::memory_order_relaxed); insertTotalUs.fetch_add(elapsedUs, std::memory_order_relaxed); - depthSum.fetch_add(depth, std::memory_order_relaxed); // std::atomic has no fetch_max, so raise the maximum with a CAS // loop. Mirrors the clamp loop in OTelCollector.cpp. diff --git a/src/xrpld/telemetry/MetricsRegistry.cpp b/src/xrpld/telemetry/MetricsRegistry.cpp index cb979ff9ef..5424e7a8b7 100644 --- a/src/xrpld/telemetry/MetricsRegistry.cpp +++ b/src/xrpld/telemetry/MetricsRegistry.cpp @@ -849,7 +849,7 @@ MetricsRegistry::observeWritePathDetail(node_store::Database const& db, ObserveF // above 1.0 even under load. An integral gauge would truncate that to 1 // and lose the whole signal, hence the fixed-point scale -- which the // name states, so nobody reads 140 as 140 writers. - if (auto const mean = scaledMean(ws->depthSum, ws->insertCount, 100)) + if (auto const mean = scaledMean(ws->depthSum, ws->depthSamples, 100)) observe("nudb_writer_depth_x100", *mean); } @@ -862,6 +862,13 @@ MetricsRegistry::observeAcquireStats(AcquireStats const& stats, ObserveFn const& // give-up path cannot fire, so an acquisition never ends. observe("acquire_deferrals", static_cast(stats.getDeferrals())); observe("acquire_timeouts", static_cast(stats.getTimeouts())); + + // The same two events, narrowed to ledger acquisition. The pair above + // sums every TimeoutCounter subclass, so a busy replay lane can imitate + // a stalled ledger acquisition; compare these two instead when asking + // whether ledger acquisition's give-up path is advancing. + observe("acquire_ledger_deferrals", static_cast(stats.getLedgerDeferrals())); + observe("acquire_ledger_timeouts", static_cast(stats.getLedgerTimeouts())); observe("acquire_give_ups", static_cast(stats.getGiveUps())); observe("acquire_aborts", static_cast(stats.getAborts())); observe("acquire_aborts_partial", static_cast(stats.getAbortsWithPartialWork())); From 56325f56c2533cbe5fa8bd21954dbae4b852a349 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Tue, 28 Jul 2026 18:25:22 +0100 Subject: [PATCH 2/2] feat(ledger): attribute deferrals and timeouts to ledger acquisition Both counters are recorded in TimeoutCounter, a base shared by five subclasses with different job limits, so they pooled every lane together. The documented fingerprint for a stalled acquisition is deferrals rising while timeouts stay flat -- but a saturated replay lane reproduces that shape while ledger acquisition is healthy, and the two counters being compared were not drawn from the same population. Adds ledger-acquisition-scoped counts alongside the totals, discriminated by the job name already held at both call sites, so no new state and no signature change. The all-lane counters stay for callers that want them. Their exporters went in with the preceding commit, which shared a file. Co-Authored-By: Claude Opus 5 (1M context) --- src/xrpld/app/ledger/AcquireStats.h | 44 ++++++++++++++++++- .../app/ledger/detail/TimeoutCounter.cpp | 4 +- src/xrpld/app/ledger/detail/TimeoutCounter.h | 17 +++++++ 3 files changed, 61 insertions(+), 4 deletions(-) diff --git a/src/xrpld/app/ledger/AcquireStats.h b/src/xrpld/app/ledger/AcquireStats.h index 027a6b346b..7ed93e85c7 100644 --- a/src/xrpld/app/ledger/AcquireStats.h +++ b/src/xrpld/app/ledger/AcquireStats.h @@ -93,9 +93,11 @@ public: * advance the retry count toward give-up. */ void - recordDeferral() + recordDeferral(bool ledgerAcquisition = false) { deferrals_.fetch_add(1, std::memory_order_relaxed); + if (ledgerAcquisition) + ledgerDeferrals_.fetch_add(1, std::memory_order_relaxed); } /** @@ -105,9 +107,11 @@ public: * separate from deferrals. */ void - recordTimeout() + recordTimeout(bool ledgerAcquisition = false) { timeouts_.fetch_add(1, std::memory_order_relaxed); + if (ledgerAcquisition) + ledgerTimeouts_.fetch_add(1, std::memory_order_relaxed); } /** @@ -171,6 +175,32 @@ public: return timeouts_.load(std::memory_order_relaxed); } + /** + * Deferrals that belong to ledger acquisition only. + * + * @ref getDeferrals covers every TimeoutCounter subclass, so a busy + * replay or transaction-set lane inflates it. Compare this against + * @ref getLedgerTimeouts to judge ledger acquisition on its own. + */ + [[nodiscard]] std::uint64_t + getLedgerDeferrals() const + { + return ledgerDeferrals_.load(std::memory_order_relaxed); + } + + /** + * Timeouts that belong to ledger acquisition only. + * + * The partner of @ref getLedgerDeferrals: rising deferrals with flat + * timeouts here means ledger acquisition's give-up path is disarmed, + * which the all-lane counters cannot show. + */ + [[nodiscard]] std::uint64_t + getLedgerTimeouts() const + { + return ledgerTimeouts_.load(std::memory_order_relaxed); + } + /** * Return the number of acquisitions that exhausted their retry budget. */ @@ -224,6 +254,16 @@ private: */ std::atomic deferrals_{0}; + /** + * Deferrals attributable to ledger acquisition alone. + */ + std::atomic ledgerDeferrals_{0}; + + /** + * Timeouts attributable to ledger acquisition alone. + */ + std::atomic ledgerTimeouts_{0}; + /** * Timer bodies that ran and advanced the retry count. */ diff --git a/src/xrpld/app/ledger/detail/TimeoutCounter.cpp b/src/xrpld/app/ledger/detail/TimeoutCounter.cpp index c5a54b8cc9..3e9961bfb1 100644 --- a/src/xrpld/app/ledger/detail/TimeoutCounter.cpp +++ b/src/xrpld/app/ledger/detail/TimeoutCounter.cpp @@ -67,7 +67,7 @@ TimeoutCounter::queueJob(ScopedLockType& sl) // Counted separately from timeouts: this path re-arms the timer // without running invokeOnTimer, so timeouts_ does not advance and the // give-up test that reads it cannot fire while the lane stays full. - app_.getAcquireStats().recordDeferral(); + app_.getAcquireStats().recordDeferral(isLedgerAcquisition()); JLOG(journal_.debug()) << "Deferring " << queueJobParameter_.jobName << " timer due to load"; setTimer(sl); @@ -92,7 +92,7 @@ TimeoutCounter::invokeOnTimer() if (!progress_) { ++timeouts_; - app_.getAcquireStats().recordTimeout(); + app_.getAcquireStats().recordTimeout(isLedgerAcquisition()); JLOG(journal_.debug()) << "Timeout(" << timeouts_ << ") " << " acquiring " << hash_; onTimer(false, sl); diff --git a/src/xrpld/app/ledger/detail/TimeoutCounter.h b/src/xrpld/app/ledger/detail/TimeoutCounter.h index 682abf1537..bba22139be 100644 --- a/src/xrpld/app/ledger/detail/TimeoutCounter.h +++ b/src/xrpld/app/ledger/detail/TimeoutCounter.h @@ -139,6 +139,23 @@ protected: QueueJobParameter queueJobParameter_; + /** + * Whether this counter belongs to ledger acquisition. + * + * Deferrals and timeouts are recorded in this base class, so they would + * otherwise pool every subclass together: a saturated replay lane would + * look exactly like a stalled ledger acquisition. The job name already + * identifies the subclass, so it is the cheapest discriminator available + * and needs no extra state. + * + * @return True for the InboundLedger lane, false for every other. + */ + [[nodiscard]] bool + isLedgerAcquisition() const + { + return queueJobParameter_.jobName == "InboundLedger"; + } + private: /** * Calls onTimer() if in the right state.