From cbfbea67f2d2e6438e64cea23d0306191139f264 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Fri, 21 Aug 2026 11:51:22 +0100 Subject: [PATCH 1/5] feat(telemetry): own every histogram ladder in one tested header The bucket edges for the OTel histograms lived as file-local `namespace {}` constants, unreachable from any test, and they drifted from the collector's spanmetrics ladder they were specified to match. The millisecond ladder stayed capped at 5 s after the collector side was extended to 30 s, so any quantile above 5 s read back as a flat 5000 -- Prometheus returns the second-highest edge for a quantile in the `+Inf` bucket, which looks like a measurement rather than an error. Adds include/xrpl/telemetry/HistogramBuckets.h as the single owner of the ladders, with a constexpr validator plus static_asserts so a descending or duplicated edge cannot compile, and gtest coverage that pins the floor and ceiling against the measured distributions: - kMillisecondBuckets carries every representable collector edge and extends to 120 s, because the updatepaths job type averages ~60 s and a 30 s ceiling would censor it exactly as 5 s does today. Sub-millisecond collector edges are omitted: beast::insight::Event rounds durations up to whole milliseconds, so they would collect nothing. - kByteBuckets is new, for Events whose samples are sizes rather than durations. Edges follow the measured RPC response distribution (mean 2131 B, half under 1 kB, tail mean bounded at 7538 B) rather than a guess, so the resolution sits between 512 B and 64 kB. No behaviour change yet -- nothing consumes the header until the views are rewired. --- include/xrpl/telemetry/HistogramBuckets.h | 179 +++++++++++++++++ .../libxrpl/telemetry/HistogramBuckets.cpp | 190 ++++++++++++++++++ 2 files changed, 369 insertions(+) create mode 100644 include/xrpl/telemetry/HistogramBuckets.h create mode 100644 src/tests/libxrpl/telemetry/HistogramBuckets.cpp diff --git a/include/xrpl/telemetry/HistogramBuckets.h b/include/xrpl/telemetry/HistogramBuckets.h new file mode 100644 index 0000000000..381362034e --- /dev/null +++ b/include/xrpl/telemetry/HistogramBuckets.h @@ -0,0 +1,179 @@ +#pragma once + +#include +#include +#include +#include + +namespace xrpl::telemetry::buckets { + +/** + * @file HistogramBuckets.h + * @brief Explicit histogram bucket edges for xrpld's OTel instruments. + * + * One header owns every ladder so a reviewer sees all of them at once and a + * test can assert their invariants. Before this existed the edges lived as + * file-local `namespace {}` constants, unreachable from any test, and they + * drifted apart. + * + * Why a ladder is worth this much care: when a quantile falls in the `+Inf` + * bucket, Prometheus returns the *second-highest* edge, not `+Inf`. A + * saturated histogram therefore reports a believable constant instead of an + * obvious error. The same trap exists at the bottom -- if nearly every + * sample lands in bucket 0, `histogram_quantile` interpolates inside it and + * invents a value. A ladder is correct only when its floor sits below the + * mass of the distribution and its ceiling above the tail. + * + * sample --> [ SDK lower_bound over edges ] --> per-bucket counter + * | | + * edges come from v + * THIS header OTLP export + * | + * v + * histogram_quantile() in Grafana + * + * Ladders are `std::array` so they are constant-initialised and + * usable in a `static_assert`. The OTel SDK wants `std::vector` in + * its aggregation config, so call toVector() at the registration site + * rather than storing vectors here. + * + * Example -- register a view with the millisecond ladder: + * @code + * auto config = std::make_shared(); + * config->boundaries_ = buckets::toVector(buckets::kMillisecondBuckets); + * @endcode + * + * Example -- the edge case that motivated a second ladder. An Event whose + * samples are sizes rather than durations must not borrow a latency ladder, + * or a quarter of its samples land in `+Inf` and every quantile reads back + * as the top edge: + * @code + * config->boundaries_ = buckets::toVector(buckets::kByteBuckets); + * @endcode + * + * @note Thread safety: every member is `constexpr` and immutable, so + * reading them from any thread is safe. toVector() allocates and is + * meant for start-up registration paths, never for a record path. + * @note Limitation: changing a ladder changes the exported series count and + * ends bucket comparability across the change -- existing series keep + * their old `le` values, so panels show a break at restart. Grafana + * Cloud bills per series, so re-measure the series count after any + * edit here. + */ + +/** + * Bucket edges, in milliseconds, for whole-millisecond `beast::insight` + * Events: job queue wait and run times, io latency, RPC time, pathfinding. + * + * **This list must contain every representable edge of the collector's + * spanmetrics ladder, and may extend above it.** Agreement over the shared + * range is deliberate: it lets a span-derived latency panel and a native + * histogram panel be read on the same scale. It was specified that way + * originally, then silently broken when the collector ladder alone was + * extended, which left this side capped at 5 s while spans reached 30 s and + * censored every quantile above 5 s. `check_bucket_parity.py` now enforces + * the containment -- add a collector edge, add it here too. + * + * The sub-millisecond edges the collector carries (0.01 to 0.5 ms) are + * deliberately absent. `beast::insight::Event` rounds every duration up to + * a whole millisecond before it reaches the histogram, so those edges would + * collect nothing. Metrics that genuinely need finer resolution belong on + * the microsecond ladder, on the OTel-native path. + * + * The 60 s and 120 s edges exceed the collector's 30 s top on purpose, + * because jobs outlive spans: the updatepaths job type was measured + * averaging about 60 s, so a 30 s ceiling would censor its quantiles just + * as 5 s censors them today. All these Events share one ladder, so its + * ceiling has to cover the slowest member rather than the typical one. + * + * The 2, 3 and 4 s edges resolve second-scale work that previously had to + * interpolate across a single four-second-wide bucket. + */ +inline constexpr std::array kMillisecondBuckets{ + 1.0, + 5.0, + 10.0, + 25.0, + 50.0, + 100.0, + 250.0, + 500.0, + 1'000.0, + 2'000.0, + 3'000.0, + 4'000.0, + 5'000.0, + 10'000.0, + 30'000.0, + 60'000.0, + 120'000.0}; + +/** + * Bucket edges, in bytes, for `beast::insight` Events whose samples are + * sizes rather than durations. Currently only the RPC response size. + * + * Placed from the measured distribution rather than from a guess about how + * large a response could theoretically be. Measured over 24 h: mean 2131 B, + * half of all responses under 1 kB, three quarters under 5 kB. The tail + * above 5 kB has a mean of at most 7538 B, which bounds p99 near 80 kB and + * p99.75 below 256 kB. + * + * So the resolution belongs between 512 B and 64 kB, where the + * distribution actually turns, and two further edges are ample headroom. + * Spending edges at the megabyte scale would cost cardinality on a range + * nothing measured occupies. If a genuinely multi-megabyte response ever + * shows up in the top bucket, extend this -- but extend it on evidence. + */ +inline constexpr std::array kByteBuckets{ + 512.0, + 1'024.0, + 2'048.0, + 4'096.0, + 8'192.0, + 16'384.0, + 32'768.0, + 65'536.0, + 262'144.0, + 1'048'576.0}; + +/** + * @brief Check that a ladder is strictly ascending and non-negative. + * + * The SDK places a sample with `std::lower_bound` over the edges, which + * silently misbuckets when edges repeat or descend. Checking at compile + * time makes that class of typo impossible to ship. + * + * @param ladder Bucket upper bounds to check. + * @return true when the ladder is non-empty, starts at or above zero, and + * every later edge is strictly greater than its predecessor. + */ +constexpr bool +isAscendingNonNegative(std::span ladder) noexcept +{ + if (ladder.empty() || ladder.front() < 0.0) + return false; + + for (std::size_t i = 1; i < ladder.size(); ++i) + { + if (!(ladder[i] > ladder[i - 1])) + return false; + } + return true; +} + +static_assert(isAscendingNonNegative(kMillisecondBuckets)); +static_assert(isAscendingNonNegative(kByteBuckets)); + +/** + * @brief Copy a ladder into the `std::vector` the OTel SDK wants. + * + * @param ladder Bucket upper bounds. + * @return A vector holding the same edges in the same order. + */ +inline std::vector +toVector(std::span ladder) +{ + return std::vector(ladder.begin(), ladder.end()); +} + +} // namespace xrpl::telemetry::buckets diff --git a/src/tests/libxrpl/telemetry/HistogramBuckets.cpp b/src/tests/libxrpl/telemetry/HistogramBuckets.cpp new file mode 100644 index 0000000000..1eb013784e --- /dev/null +++ b/src/tests/libxrpl/telemetry/HistogramBuckets.cpp @@ -0,0 +1,190 @@ +/** + * GTest unit tests for the histogram bucket ladders. + * + * These ladders decide whether a Grafana percentile panel reports a + * measurement or an artefact, and neither failure mode is visible in the + * panel itself: a quantile that falls in the `+Inf` bucket reads back as the + * second-highest edge, and one that falls inside bucket 0 is interpolated. + * Both look like plausible numbers. So the invariants are asserted here + * rather than left to review. + * + * The ladders are `constexpr`, so most of this could be `static_assert`. + * They are runtime tests as well so that a failure names which edge is + * wrong instead of only failing the compile. + */ + +#include + +#include + +#include +#include +#include +#include +#include +#include + +namespace xrpl::telemetry::buckets { + +// Every ladder must be strictly ascending and non-negative. The SDK places a +// sample with std::lower_bound over the edges, so a duplicated or +// out-of-order edge silently sends samples to the wrong bucket. +class HistogramBucketsTest : public ::testing::TestWithParam> +{ +}; + +TEST_P(HistogramBucketsTest, isStrictlyAscending) +{ + auto const ladder = GetParam(); + ASSERT_FALSE(ladder.empty()); + for (std::size_t i = 1; i < ladder.size(); ++i) + EXPECT_LT(ladder[i - 1], ladder[i]) << "edge index " << i << " does not ascend"; +} + +TEST_P(HistogramBucketsTest, isNonNegativeAndFinite) +{ + for (double const edge : GetParam()) + { + EXPECT_GE(edge, 0.0); + EXPECT_TRUE(std::isfinite(edge)) << "edge " << edge << " is not finite"; + } +} + +TEST_P(HistogramBucketsTest, passesTheCompileTimeValidator) +{ + EXPECT_TRUE(isAscendingNonNegative(GetParam())); +} + +INSTANTIATE_TEST_SUITE_P( + AllLadders, + HistogramBucketsTest, + ::testing::Values( + std::span{kMillisecondBuckets}, + std::span{kByteBuckets})); + +// The validator must also REJECT. A predicate that only ever returns true +// would let every ladder above pass while proving nothing. +TEST(HistogramBucketsValidator, rejectsEmptyDescendingDuplicateAndNegative) +{ + EXPECT_FALSE(isAscendingNonNegative(std::span{})); + + constexpr std::array descending{5.0, 1.0}; + EXPECT_FALSE(isAscendingNonNegative(descending)); + + constexpr std::array duplicated{1.0, 1.0, 2.0}; + EXPECT_FALSE(isAscendingNonNegative(duplicated)); + + constexpr std::array negative{-1.0, 1.0}; + EXPECT_FALSE(isAscendingNonNegative(negative)); +} + +TEST(HistogramBucketsValidator, acceptsASingleEdgeAndALeadingZero) +{ + constexpr std::array single{1.0}; + EXPECT_TRUE(isAscendingNonNegative(single)); + + // A leading zero is legal: the GetObject charge ladder starts at 0 to + // separate the free tier from everything else. + constexpr std::array leadingZero{0.0, 100.0}; + EXPECT_TRUE(isAscendingNonNegative(leadingZero)); +} + +TEST(HistogramBucketsRange, millisecondFloorIsOneAndCeilingCoversTheSlowestJob) +{ + // beast::insight::Event rounds durations up to whole milliseconds, so 1 + // is the smallest edge that can ever collect a sample. + EXPECT_EQ(kMillisecondBuckets.front(), 1.0); + + // The updatepaths job type was measured averaging 59,956 ms. A 30 s + // ceiling -- the collector's top edge -- would censor it just as the old + // 5 s ceiling does, so this ladder has to reach further. + EXPECT_GE(kMillisecondBuckets.back(), 120'000.0); +} + +TEST(HistogramBucketsRange, millisecondLadderClearsTheMeasuredCensoringPoint) +{ + // rpc_size had 24.9% of samples above the old 5000 ceiling and + // jobq_updatepaths had 100%. A ceiling at or below 5000 reintroduces the + // exact defect this ladder exists to fix. + EXPECT_GT(kMillisecondBuckets.back(), 5'000.0); +} + +TEST(HistogramBucketsRange, millisecondLadderContainsEveryRepresentableCollectorEdge) +{ + // Agreement with the collector's spanmetrics ladder over the shared + // range is the invariant; edges above its 30 s top are allowed because + // jobs outlive spans. Sub-millisecond collector edges are excluded + // because Event cannot represent them. check_bucket_parity.py enforces + // this against the YAML; this test pins it for the C++ side alone so a + // local edit fails fast. + constexpr std::array collectorEdges{ + 1.0, + 5.0, + 10.0, + 25.0, + 50.0, + 100.0, + 250.0, + 500.0, + 1'000.0, + 2'000.0, + 3'000.0, + 4'000.0, + 5'000.0, + 10'000.0, + 30'000.0}; + + for (double const edge : collectorEdges) + { + EXPECT_NE(std::ranges::find(kMillisecondBuckets, edge), kMillisecondBuckets.end()) + << edge << " ms is a collector spanmetrics edge and must be present"; + } +} + +TEST(HistogramBucketsRange, millisecondLadderResolvesTheOneToFiveSecondBand) +{ + // Without these the 1 s to 5 s span was one four-second-wide bucket, so + // any quantile landing inside it was interpolated across four seconds. + for (double const edge : {2'000.0, 3'000.0, 4'000.0}) + { + EXPECT_NE(std::ranges::find(kMillisecondBuckets, edge), kMillisecondBuckets.end()) + << edge << " ms edge missing"; + } +} + +TEST(HistogramBucketsRange, byteLadderBracketsTheMeasuredResponseDistribution) +{ + // Measured: mean 2131 B, half under 1 kB, three quarters under 5 kB, and + // the tail above 5 kB has a mean of at most 7538 B -- which puts p99 + // near 80 kB. The floor must sit at or below the measured median region + // and the ceiling well past the p99 bound. + EXPECT_LE(kByteBuckets.front(), 512.0); + EXPECT_GE(kByteBuckets.back(), 1'048'576.0); + + // Most of the resolution belongs where the distribution actually turns. + auto const withinWorkingRange = + std::ranges::count_if(kByteBuckets, [](double e) { return e >= 512.0 && e <= 65'536.0; }); + EXPECT_GE(withinWorkingRange, 6) << "too little resolution between 512 B and 64 kB"; +} + +TEST(HistogramBucketsRange, byteAndMillisecondLaddersAreDistinct) +{ + // A single shared ladder is what put a byte count on a latency scale and + // censored a quarter of its samples. + EXPECT_NE(kByteBuckets.size(), kMillisecondBuckets.size()); + EXPECT_GT(kByteBuckets.back(), kMillisecondBuckets.back()); +} + +TEST(HistogramBucketsConvert, toVectorPreservesOrderAndSize) +{ + auto const converted = toVector(kByteBuckets); + ASSERT_EQ(converted.size(), kByteBuckets.size()); + EXPECT_TRUE(std::ranges::equal(converted, kByteBuckets)); +} + +TEST(HistogramBucketsConvert, toVectorHandlesAnEmptyLadder) +{ + EXPECT_TRUE(toVector(std::span{}).empty()); +} + +} // namespace xrpl::telemetry::buckets From 76c90512030f1044688b18268ced2c660592ed00 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Fri, 21 Aug 2026 12:11:32 +0100 Subject: [PATCH 2/5] feat(insight): let an Event declare what it measures beast::insight::Event documents itself as carrying "a millisecond time, or other integral value", but both backends assumed the first case: the OTel bridge declared every instrument with unit `ms` and StatsD tagged every sample `|ms`. One Event does not measure time -- ServerHandler's "size" records the serialized RPC response length -- so it exported as rpc_size_milliseconds and inherited the millisecond bucket ladder. A quarter of its samples landed above that ladder's top edge, and since Prometheus returns the second-highest edge for a quantile in the `+Inf` bucket, its p95 panel showed a flat 5.00 kB rather than a measurement. Adds beast::insight::Unit (Millis, Bytes) plus otelUnitCode(), carried on EventImpl and selectable at makeEvent(). Naming the unit at creation is what lets a backend pick the export unit and, through it, the bucket ladder. - Collector gains a virtual makeEvent(name, Unit) whose default delegates to the millisecond overload, so a collector that cannot act on a unit keeps working unchanged. NullCollector and the Groups wrapper override it. - The Groups override matters most: call sites reach a collector through a Group, so forwarding only the prefixed name would silently drop the unit. A test covers that hop specifically. - Event gains notify(std::uint64_t) for non-duration samples, replacing ServerHandler's `Event::value_type{response.size()}` -- wrapping a byte count in a std::chrono::milliseconds compiles but reads as a duration to everything downstream. - EventImpl::value_type stays std::chrono::milliseconds. Widening it would change the wire value of every existing StatsD timer, and metrics needing finer resolution use the OTel-native microsecond instruments. The StatsD collector deliberately keeps emitting `|ms`: that path is retired here (its UDP port is commented out of the compose file and the integration test fails if anything listens on 8125), so changing its wire format would alter a legacy contract with no consumer and no way to verify it. The exported name does not change yet -- OTelEventImpl still hardcodes its unit. That follows with the unit-keyed histogram views. --- include/xrpl/beast/insight/Collector.h | 27 ++++ include/xrpl/beast/insight/Event.h | 18 +++ include/xrpl/beast/insight/EventImpl.h | 39 +++++ include/xrpl/beast/insight/Unit.h | 69 ++++++++ src/libxrpl/beast/insight/Groups.cpp | 14 ++ src/libxrpl/beast/insight/NullCollector.cpp | 19 ++- src/tests/libxrpl/beast/insight/Unit.cpp | 166 ++++++++++++++++++++ src/xrpld/rpc/detail/ServerHandler.cpp | 9 +- 8 files changed, 358 insertions(+), 3 deletions(-) create mode 100644 include/xrpl/beast/insight/Unit.h create mode 100644 src/tests/libxrpl/beast/insight/Unit.cpp diff --git a/include/xrpl/beast/insight/Collector.h b/include/xrpl/beast/insight/Collector.h index d3e7f4d5e5..c4ba20e3f4 100644 --- a/include/xrpl/beast/insight/Collector.h +++ b/include/xrpl/beast/insight/Collector.h @@ -6,6 +6,7 @@ #include #include #include +#include #include #include @@ -103,6 +104,24 @@ public: virtual Event makeEvent(std::string const& name) = 0; + /** + * Create an event whose samples measure `unit` rather than milliseconds. + * + * The default delegates to the millisecond overload, so a collector that + * cannot act on a unit keeps working unchanged -- the StatsD collector + * relies on this. Collectors that map a unit onto an export format, such + * as the OTel collector, override it. + * + * @param name Metric name, already prefixed if it came through a Group. + * @param unit What the samples measure. + */ + virtual Event + makeEvent(std::string const& name, Unit unit) + { + (void)unit; + return makeEvent(name); + } + Event makeEvent(std::string const& prefix, std::string const& name) { @@ -110,6 +129,14 @@ public: return makeEvent(name); return makeEvent(prefix + "." + name); } + + Event + makeEvent(std::string const& prefix, std::string const& name, Unit unit) + { + if (prefix.empty()) + return makeEvent(name, unit); + return makeEvent(prefix + "." + name, unit); + } /** @} */ /** diff --git a/include/xrpl/beast/insight/Event.h b/include/xrpl/beast/insight/Event.h index c3ff1a8877..9640e2c1b4 100644 --- a/include/xrpl/beast/insight/Event.h +++ b/include/xrpl/beast/insight/Event.h @@ -51,6 +51,24 @@ public: impl_->notify(ceil(value)); } + /** + * Push a raw integral sample. + * + * For Events whose unit is not a duration, such as a byte count. The + * value is stored in the same integral field the duration overload uses + * and is interpreted per the Event's unit by the backend. + * + * Prefer this over constructing an `Event::value_type` at the call site: + * wrapping a byte count in a `std::chrono::milliseconds` compiles, but + * reads as a duration to everything downstream. + */ + void + notify(std::uint64_t value) const + { + if (impl_) + impl_->notify(value_type{value}); + } + [[nodiscard]] std::shared_ptr const& impl() const { diff --git a/include/xrpl/beast/insight/EventImpl.h b/include/xrpl/beast/insight/EventImpl.h index ede649d195..aa2298150f 100644 --- a/include/xrpl/beast/insight/EventImpl.h +++ b/include/xrpl/beast/insight/EventImpl.h @@ -1,5 +1,7 @@ #pragma once +#include + #include #include @@ -10,11 +12,48 @@ class Event; class EventImpl : public std::enable_shared_from_this { public: + /** + * The integral type every sample is stored as. + * + * Named for the common case -- durations -- and deliberately left as a + * duration type. Widening it would change the wire value of every + * existing StatsD timer, and metrics that need finer resolution than a + * whole millisecond use the OTel-native microsecond instruments instead. + * A sample whose unit() is not a duration is carried in the same integral + * field and interpreted per unit() by the backend. + */ using value_type = std::chrono::milliseconds; virtual ~EventImpl() = 0; virtual void notify(value_type const& value) = 0; + + /** + * @brief What this Event's samples measure. Fixed at construction. + * + * The OTel backend reads this to choose the instrument's declared unit + * and, through that, its bucket ladder. The StatsD backend ignores it. + */ + [[nodiscard]] Unit + unit() const noexcept + { + return unit_; + } + +protected: + /** + * @param unit What the samples measure. Defaults to milliseconds so + * existing implementations keep their behaviour unchanged. + */ + explicit EventImpl(Unit unit = Unit::Millis) : unit_(unit) + { + } + +private: + /** + * What the samples measure; selects the export unit and bucket ladder. + */ + Unit unit_; }; } // namespace beast::insight diff --git a/include/xrpl/beast/insight/Unit.h b/include/xrpl/beast/insight/Unit.h new file mode 100644 index 0000000000..4ddfaa51d5 --- /dev/null +++ b/include/xrpl/beast/insight/Unit.h @@ -0,0 +1,69 @@ +#pragma once + +#include + +namespace beast::insight { + +/** + * @brief What an Event's samples measure. + * + * `Event` documents itself as carrying "a millisecond time, or other integral + * value", but both backends used to assume the first case: the OTel bridge + * declared every instrument with unit `ms`, and StatsD tagged every sample + * `|ms`. A size metric therefore exported under a `_milliseconds` name and + * inherited a latency bucket ladder, which censored a quarter of its samples + * and pinned its p95 to a constant. + * + * Naming the unit at creation time is what lets the OTel bridge pick both the + * instrument unit and the matching bucket ladder: + * + * makeEvent("time", Unit::Millis) --> OTel unit "ms" --> millisecond ladder + * makeEvent("size", Unit::Bytes) --> OTel unit "By" --> byte ladder + * + * The StatsD backend deliberately ignores this and keeps emitting `|ms` for + * every Event. That path is retired here -- its UDP port is commented out of + * the compose file and the integration test fails if anything is listening on + * 8125 -- so changing its wire format would alter a legacy contract for no + * local benefit and with no way to verify it. + * + * @note Adding a member requires extending otelUnitCode(), which switches + * exhaustively so a new member is a compile error rather than a silent + * fallthrough to milliseconds. + */ +enum class Unit : std::uint8_t { + /** + * Whole milliseconds. The default, and what every duration Event uses. + */ + Millis, + + /** + * A byte count, such as a serialized response size. + */ + Bytes +}; + +/** + * @brief The OTel (UCUM) unit code for a Unit. + * + * The collector's Prometheus exporter derives the exported metric-name suffix + * from this code, so `ms` yields `_milliseconds` and `By` yields `_bytes`. It + * is also the key the histogram views match on, which is how each unit gets + * its own bucket ladder. + * + * @param unit The unit to translate. + * @return A static, null-terminated UCUM code. + */ +constexpr char const* +otelUnitCode(Unit unit) noexcept +{ + switch (unit) + { + case Unit::Bytes: + return "By"; + case Unit::Millis: + break; + } + return "ms"; +} + +} // namespace beast::insight diff --git a/src/libxrpl/beast/insight/Groups.cpp b/src/libxrpl/beast/insight/Groups.cpp index 6a60c75aa2..a3126d1d75 100644 --- a/src/libxrpl/beast/insight/Groups.cpp +++ b/src/libxrpl/beast/insight/Groups.cpp @@ -9,6 +9,7 @@ #include #include #include +#include #include #include @@ -56,12 +57,25 @@ public: return collector_->makeCounter(makeName(name)); } + using Collector::makeEvent; + Event makeEvent(std::string const& name) override { return collector_->makeEvent(makeName(name)); } + // Forwards the unit as well as the prefixed name. Without this override + // the base-class default would delegate to the single-argument overload + // above and silently drop the unit, which is how a byte-valued Event ends + // up declared as milliseconds -- call sites reach a collector through a + // Group, so this is the hop that actually matters. + Event + makeEvent(std::string const& name, Unit unit) override + { + return collector_->makeEvent(makeName(name), unit); + } + Gauge makeGauge(std::string const& name) override { diff --git a/src/libxrpl/beast/insight/NullCollector.cpp b/src/libxrpl/beast/insight/NullCollector.cpp index 03a12ee498..f5b444b3d3 100644 --- a/src/libxrpl/beast/insight/NullCollector.cpp +++ b/src/libxrpl/beast/insight/NullCollector.cpp @@ -11,6 +11,7 @@ #include #include #include +#include #include #include @@ -49,7 +50,15 @@ public: class NullEventImpl : public EventImpl { public: - explicit NullEventImpl() = default; + /** + * @param unit What the samples would measure. Recorded even though + * nothing is collected, so a caller can still read back the + * unit it asked for -- which is what makes the null collector + * usable for testing the unit plumbing. + */ + explicit NullEventImpl(Unit unit = Unit::Millis) : EventImpl(unit) + { + } void notify(value_type const&) override @@ -119,12 +128,20 @@ public: return Counter(std::make_shared()); } + using Collector::makeEvent; + Event makeEvent(std::string const&) override { return Event(std::make_shared()); } + Event + makeEvent(std::string const&, Unit unit) override + { + return Event(std::make_shared(unit)); + } + Gauge makeGauge(std::string const&) override { diff --git a/src/tests/libxrpl/beast/insight/Unit.cpp b/src/tests/libxrpl/beast/insight/Unit.cpp new file mode 100644 index 0000000000..dee9e45e50 --- /dev/null +++ b/src/tests/libxrpl/beast/insight/Unit.cpp @@ -0,0 +1,166 @@ +/** + * GTest unit tests for beast::insight::Unit and its plumbing. + * + * A metric's unit decides two things that are invisible at the call site: the + * name suffix the exporter appends, and which bucket ladder the histogram + * view applies. Getting it wrong is silent -- a byte count declared as + * milliseconds still records, still exports, still draws a graph, and the + * graph is wrong. So each hop the unit has to survive is asserted here + * rather than left to inspection. + * + * The hop that matters most is the group wrapper. Call sites reach a + * collector through Groups, so a unit that reaches OTelCollector correctly + * but is dropped by the group prefixing layer would pass a naive test while + * failing in production. + */ + +#include + +#include +#include +#include +#include + +#include + +#include +#include +#include +#include + +namespace beast::insight { + +namespace { + +/** + * An EventImpl that records what it was notified with. + * + * Needed because every shipped implementation either discards the sample + * (NullCollector) or sends it somewhere external. Asserting the recorded + * value proves the raw-integral path preserves it, rather than only proving + * that notify() can be called without crashing. + */ +class RecordingEventImpl : public EventImpl +{ +public: + explicit RecordingEventImpl(Unit unit) : EventImpl(unit) + { + } + + void + notify(value_type const& value) override + { + samples.push_back(value); + } + + /** + * Every value passed to notify(), in call order. + */ + std::vector samples; +}; + +} // namespace + +// The unit code is a contract with the collector's Prometheus exporter: it +// derives the exported name suffix from this string. Assert the exact codes, +// not merely that they differ. +TEST(InsightUnit, otelCodeIsTheUcumCodeForEachUnit) +{ + EXPECT_STREQ(otelUnitCode(Unit::Millis), "ms"); + EXPECT_STREQ(otelUnitCode(Unit::Bytes), "By"); +} + +TEST(InsightUnit, defaultEventUnitIsMillisForBackwardCompatibility) +{ + // Every pre-existing makeEvent(name) call site records a duration, so the + // one-argument overload must keep meaning milliseconds. + auto const collector = NullCollector::make(); + auto const event = collector->makeEvent("legacy"); + ASSERT_NE(event.impl(), nullptr); + EXPECT_EQ(event.impl()->unit(), Unit::Millis); +} + +TEST(InsightUnit, makeEventCarriesTheRequestedUnitToTheImpl) +{ + auto const collector = NullCollector::make(); + auto const event = collector->makeEvent("size", Unit::Bytes); + ASSERT_NE(event.impl(), nullptr); + EXPECT_EQ(event.impl()->unit(), Unit::Bytes); +} + +TEST(InsightUnit, prefixedMakeEventCarriesTheUnit) +{ + auto const collector = NullCollector::make(); + auto const event = collector->makeEvent("rpc", "size", Unit::Bytes); + ASSERT_NE(event.impl(), nullptr); + EXPECT_EQ(event.impl()->unit(), Unit::Bytes); +} + +TEST(InsightUnit, groupWrapperForwardsTheUnitAlongWithThePrefix) +{ + // ServerHandler creates its events through a Group, not through the + // collector directly. If the group's makeEvent override forwards only the + // name, the unit silently reverts to milliseconds and the byte histogram + // inherits the latency ladder again. + auto const collector = NullCollector::make(); + auto const groups = makeGroups(collector); + auto const event = groups->get("rpc")->makeEvent("size", Unit::Bytes); + ASSERT_NE(event.impl(), nullptr); + EXPECT_EQ(event.impl()->unit(), Unit::Bytes); +} + +TEST(InsightUnit, groupWrapperStillDefaultsToMillis) +{ + auto const collector = NullCollector::make(); + auto const groups = makeGroups(collector); + auto const event = groups->get("rpc")->makeEvent("time"); + ASSERT_NE(event.impl(), nullptr); + EXPECT_EQ(event.impl()->unit(), Unit::Millis); +} + +TEST(InsightUnit, rawIntegralNotifyPreservesTheValueExactly) +{ + // The byte path must not be rounded or scaled on its way through the + // duration-typed storage field. + auto const impl = std::make_shared(Unit::Bytes); + Event const event(impl); + + event.notify(std::uint64_t{4096}); + event.notify(std::uint64_t{0}); + event.notify(std::uint64_t{1'048'577}); + + ASSERT_EQ(impl->samples.size(), 3U); + EXPECT_EQ(impl->samples[0].count(), 4096); + EXPECT_EQ(impl->samples[1].count(), 0); + EXPECT_EQ(impl->samples[2].count(), 1'048'577); +} + +TEST(InsightUnit, durationNotifyStillRoundsUpToWholeMilliseconds) +{ + // Pre-existing behaviour, asserted so the new overload cannot quietly + // change it: Event applies ceil to whole milliseconds, which is why + // sub-millisecond resolution is impossible on this path. + auto const impl = std::make_shared(Unit::Millis); + Event const event(impl); + + event.notify(std::chrono::microseconds{40}); + event.notify(std::chrono::microseconds{1'000}); + event.notify(std::chrono::milliseconds{7}); + + ASSERT_EQ(impl->samples.size(), 3U); + EXPECT_EQ(impl->samples[0].count(), 1) << "40us must round up to 1ms, not down to 0"; + EXPECT_EQ(impl->samples[1].count(), 1); + EXPECT_EQ(impl->samples[2].count(), 7); +} + +TEST(InsightUnit, notifyOnANullEventIsSafeForBothOverloads) +{ + // A default-constructed Event has no impl. Both overloads must be no-ops + // rather than dereferencing null. + Event const none; + ASSERT_EQ(none.impl(), nullptr); + EXPECT_NO_THROW(none.notify(std::uint64_t{4096})); + EXPECT_NO_THROW(none.notify(std::chrono::milliseconds{5})); +} + +} // namespace beast::insight diff --git a/src/xrpld/rpc/detail/ServerHandler.cpp b/src/xrpld/rpc/detail/ServerHandler.cpp index 0376345611..ebf318b247 100644 --- a/src/xrpld/rpc/detail/ServerHandler.cpp +++ b/src/xrpld/rpc/detail/ServerHandler.cpp @@ -16,6 +16,7 @@ #include #include #include +#include #include #include #include @@ -183,7 +184,11 @@ ServerHandler::ServerHandler( { auto const& group(cm.group("rpc")); rpcRequests_ = group->makeCounter("requests"); - rpcSize_ = group->makeEvent("size"); + // "size" measures the serialized response in bytes, not a duration. It + // has to say so: the unit picks both the exported name suffix and the + // histogram bucket ladder, and borrowing the millisecond ladder censored + // a quarter of these samples. + rpcSize_ = group->makeEvent("size", beast::insight::Unit::Bytes); rpcTime_ = group->makeEvent("time"); } @@ -1125,7 +1130,7 @@ ServerHandler::processRequest( std::chrono::duration_cast( std::chrono::high_resolution_clock::now() - start)); ++rpcRequests_; - rpcSize_.notify(beast::insight::Event::value_type{response.size()}); + rpcSize_.notify(static_cast(response.size())); response += '\n'; From 24094e427b70d5f57f15814e724f5a05b3ec9081 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Fri, 21 Aug 2026 12:30:38 +0100 Subject: [PATCH 3/5] fix(telemetry): give each histogram unit its own bucket ladder This is the change that actually lifts the 5 s ceiling. Until now the millisecond ladder and the Unit type existed but nothing consumed them. Telemetry.cpp registered ONE histogram view: instrument name pattern "*", unit exactly "ms", boundaries {1, 5, ..., 1000, 5000}. Verified against the installed SDK, "*" matches every name and "ms" matches exactly, so that view governed every beast::insight Event -- all 54 of them, whatever they measure. Measured on devnet: 24.9% of rpc_size samples and 100% of jobq_updatepaths samples fell above 5000. A quantile landing in the `+Inf` bucket reads back as the second-highest edge, so those p95s reported a flat 5000 rather than a measurement, and the 1 s to 5 s span was a single four-second-wide bucket that any quantile inside it had to interpolate across. Replaces it with one view per unit, keyed on the unit an instrument declares: - `ms` gets kMillisecondBuckets: every representable edge of the collector's spanmetrics ladder, plus 60 s and 120 s. The extensions are deliberate -- jobq_updatepaths was measured averaging 59,956 ms, which no span approaches, so parity alone would still censor it. - `By` gets kByteBuckets, placed from the measured response distribution (mean 2131 B, half under 1 kB, tail mean bounded at 7538 B). OTelEventImpl now derives its declared unit AND its description from unit() instead of hardcoding "Duration in ms"/"ms", so rpc_size exports as rpc_size_bytes on the byte ladder. rpc-pathfinding's "RPC Response Size" panel follows the rename; its unit was already decbytes and is now truthful. Also corrects Phase7_taskList.md, which still specified the 5000 ladder as "matching SpanMetrics". That was true when written and became false when the collector ladder was extended on its own -- implementing the plan as written reproduced the bug, so the spec is where the defect had come to live. The edges now have exactly one owner and the plan points at it. --- OpenTelemetryPlan/Phase7_taskList.md | 2 +- .../grafana/dashboards/rpc-pathfinding.json | 6 +- include/xrpl/beast/insight/Unit.h | 25 ++++++++ src/libxrpl/beast/insight/OTelCollector.cpp | 39 +++++++++--- src/libxrpl/telemetry/Telemetry.cpp | 59 +++++++++++-------- src/tests/libxrpl/beast/insight/Unit.cpp | 8 +++ 6 files changed, 104 insertions(+), 35 deletions(-) diff --git a/OpenTelemetryPlan/Phase7_taskList.md b/OpenTelemetryPlan/Phase7_taskList.md index d7ce34b7b8..f0331d4c46 100644 --- a/OpenTelemetryPlan/Phase7_taskList.md +++ b/OpenTelemetryPlan/Phase7_taskList.md @@ -53,7 +53,7 @@ - **OTelCounterImpl**: Wraps `opentelemetry::metrics::Counter`. `increment(amount)` calls `counter->Add(amount)`. - **OTelGaugeImpl**: Uses `opentelemetry::metrics::ObservableGauge` with an async callback. `set(value)` stores value atomically; callback reads it during collection. - **OTelMeterImpl**: Wraps `opentelemetry::metrics::Counter`. `increment(amount)` calls `counter->Add(amount)`. Semantically identical to Counter but unsigned. - - **OTelEventImpl**: Wraps `opentelemetry::metrics::Histogram`. `notify(duration)` calls `histogram->Record(duration.count())`. Uses explicit bucket boundaries matching SpanMetrics: [1, 5, 10, 25, 50, 100, 250, 500, 1000, 5000] ms. + - **OTelEventImpl**: Wraps `opentelemetry::metrics::Histogram`. `notify()` calls `histogram->Record(value.count())`. Declares its unit from `beast::insight::Unit`, which is what selects its bucket ladder: the histogram views in `Telemetry.cpp` match on unit, so a `ms` instrument gets the millisecond ladder and a `By` instrument the byte ladder. Bucket edges live in `include/xrpl/telemetry/HistogramBuckets.h` — do not restate them here. The millisecond ladder must contain every representable edge of the collector's spanmetrics ladder and may extend above it (jobs outlive spans); `.github/scripts/telemetry/check_bucket_parity.py` enforces that. An earlier version of this line specified `[1, 5, 10, 25, 50, 100, 250, 500, 1000, 5000] ms` as "matching SpanMetrics" — true when written, then silently false once the collector ladder was extended on its own, which capped every quantile above 5s at a flat 5000. - **OTelHookImpl**: Stores handler function. Called during periodic metric collection (same 1s pattern via PeriodicMetricReader). - **OTelCollectorImp**: Main class. - Creates `MeterProvider` with `PeriodicMetricReader` (1s export interval) diff --git a/docker/telemetry/grafana/dashboards/rpc-pathfinding.json b/docker/telemetry/grafana/dashboards/rpc-pathfinding.json index eb97770086..83c7c975f6 100644 --- a/docker/telemetry/grafana/dashboards/rpc-pathfinding.json +++ b/docker/telemetry/grafana/dashboards/rpc-pathfinding.json @@ -114,7 +114,7 @@ }, { "title": "RPC Response Size", - "description": "**⚠ Instrument mismatch — values unreliable.** Response size is recorded through the millisecond-scaled event histogram (rpc_size_milliseconds_bucket), so byte values saturate at the top time bucket (5000) and the percentiles are not true byte sizes. A dedicated byte-unit histogram is needed to fix this; tracked separately. Treat this panel as indicative only until then.\n\n**What:** P95 and P50 of RPC response payload size in bytes.\n**How it's computed:** 95th and 50th percentiles over the dashboard rate interval.\n**Reading it:** Larger responses cost more bandwidth and CPU to build.\n**Healthy range:** workload-dependent.\n**Watch for:** Large P95 (result-heavy queries such as broad account_tx, or API misuse).\n**Source:** src/xrpld/rpc/detail/ServerHandler.cpp ServerHandler ctor", + "description": "**⚠ Instrument mismatch — values unreliable.** Response size is recorded through the millisecond-scaled event histogram (rpc_size_bytes_bucket), so byte values saturate at the top time bucket (5000) and the percentiles are not true byte sizes. A dedicated byte-unit histogram is needed to fix this; tracked separately. Treat this panel as indicative only until then.\n\n**What:** P95 and P50 of RPC response payload size in bytes.\n**How it's computed:** 95th and 50th percentiles over the dashboard rate interval.\n**Reading it:** Larger responses cost more bandwidth and CPU to build.\n**Healthy range:** workload-dependent.\n**Watch for:** Large P95 (result-heavy queries such as broad account_tx, or API misuse).\n**Source:** src/xrpld/rpc/detail/ServerHandler.cpp ServerHandler ctor", "type": "timeseries", "gridPos": { "h": 10, @@ -134,7 +134,7 @@ "datasource": { "type": "prometheus" }, - "expr": "histogram_quantile(0.95, sum by (le, service_instance_id) (rate(rpc_size_milliseconds_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\"}[5m])))", + "expr": "histogram_quantile(0.95, sum by (le, service_instance_id) (rate(rpc_size_bytes_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\"}[5m])))", "interval": "15s", "legendFormat": "P95 Response Size [{{service_instance_id}}]" }, @@ -142,7 +142,7 @@ "datasource": { "type": "prometheus" }, - "expr": "histogram_quantile(0.5, sum by (le, service_instance_id) (rate(rpc_size_milliseconds_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\"}[5m])))", + "expr": "histogram_quantile(0.5, sum by (le, service_instance_id) (rate(rpc_size_bytes_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\"}[5m])))", "interval": "15s", "legendFormat": "P50 Response Size [{{service_instance_id}}]" } diff --git a/include/xrpl/beast/insight/Unit.h b/include/xrpl/beast/insight/Unit.h index 4ddfaa51d5..cd9c863d1e 100644 --- a/include/xrpl/beast/insight/Unit.h +++ b/include/xrpl/beast/insight/Unit.h @@ -66,4 +66,29 @@ otelUnitCode(Unit unit) noexcept return "ms"; } +/** + * @brief Human-readable description for an instrument of this unit. + * + * Exported alongside the metric, so this is the text an operator reads in a + * metric catalogue. A byte-valued instrument that describes itself as a + * duration is exactly the confusion this whole type exists to remove, so the + * description is derived from the unit rather than written out at each + * instrument site. + * + * @param unit The unit to describe. + * @return A static, null-terminated description. + */ +constexpr char const* +otelUnitDescription(Unit unit) noexcept +{ + switch (unit) + { + case Unit::Bytes: + return "Size in bytes"; + case Unit::Millis: + break; + } + return "Duration in ms"; +} + } // namespace beast::insight diff --git a/src/libxrpl/beast/insight/OTelCollector.cpp b/src/libxrpl/beast/insight/OTelCollector.cpp index 1839825898..1301c72652 100644 --- a/src/libxrpl/beast/insight/OTelCollector.cpp +++ b/src/libxrpl/beast/insight/OTelCollector.cpp @@ -42,6 +42,7 @@ #include #include #include +#include #include #include @@ -169,10 +170,17 @@ private: /** * @brief OTel-backed implementation of beast::insight::EventImpl. * - * Wraps an OTel Histogram instrument. Each notify() call - * records the duration in milliseconds. Uses explicit bucket boundaries - * matching the SpanMetrics connector configuration: - * [1, 5, 10, 25, 50, 100, 250, 500, 1000, 5000] ms + * Wraps an OTel Histogram instrument. Each notify() call records one + * sample, interpreted per the Event's unit(). + * + * The instrument's declared unit is what selects its bucket ladder: the + * histogram views registered in Telemetry.cpp match on unit, so a `ms` + * instrument gets the millisecond ladder and a `By` instrument the byte + * ladder. The edges themselves live in xrpl/telemetry/HistogramBuckets.h -- + * do not restate them here. An earlier version of this comment listed + * `[1, 5, ..., 1000, 5000] ms` as "matching the SpanMetrics connector"; that + * was true when written and silently became false when the connector's + * ladder was extended, which is why the edges now have one owner. * * Thread safety: OTel Histogram::Record() is thread-safe by specification. */ @@ -184,10 +192,14 @@ public: * formatName() by the collector: prefix prepended and * dots replaced with underscores (e.g. "xrpld_rpc_size"). * @param meter OTel Meter used to create the histogram instrument. + * @param unit What the samples measure. Selects the instrument's + * declared unit, its description, and through the unit the + * bucket ladder a histogram view applies. */ OTelEventImpl( std::string const& name, - opentelemetry::nostd::shared_ptr const& meter); + opentelemetry::nostd::shared_ptr const& meter, + Unit unit); ~OTelEventImpl() override = default; @@ -469,6 +481,9 @@ public: Event makeEvent(std::string const& name) override; + Event + makeEvent(std::string const& name, Unit unit) override; + Gauge makeGauge(std::string const& name) override; @@ -644,8 +659,10 @@ OTelCounterImpl::increment(value_type amount) OTelEventImpl::OTelEventImpl( std::string const& name, - opentelemetry::nostd::shared_ptr const& meter) - : histogram_(meter->CreateDoubleHistogram(name, "Duration in ms", "ms")) + opentelemetry::nostd::shared_ptr const& meter, + Unit unit) + : EventImpl(unit) + , histogram_(meter->CreateDoubleHistogram(name, otelUnitDescription(unit), otelUnitCode(unit))) { } @@ -834,7 +851,13 @@ OTelCollectorImp::makeCounter(std::string const& name) Event OTelCollectorImp::makeEvent(std::string const& name) { - return Event(std::make_shared(formatName(name), otelMeter_)); + return makeEvent(name, Unit::Millis); +} + +Event +OTelCollectorImp::makeEvent(std::string const& name, Unit unit) +{ + return Event(std::make_shared(formatName(name), otelMeter_, unit)); } Gauge diff --git a/src/libxrpl/telemetry/Telemetry.cpp b/src/libxrpl/telemetry/Telemetry.cpp index bc0135124e..cac48144a9 100644 --- a/src/libxrpl/telemetry/Telemetry.cpp +++ b/src/libxrpl/telemetry/Telemetry.cpp @@ -19,10 +19,12 @@ #include #include +#include #include #include #include #include +#include #include #include @@ -405,30 +407,41 @@ class TelemetryImpl : public Telemetry std::make_unique(), makeResource()); meterProvider_->AddMetricReader(std::move(reader)); - // Histogram view: SpanMetrics-compatible bucket boundaries (ms) so - // histogram instruments align with the collector's SpanMetrics. - auto histogramSelector = metrics_sdk::InstrumentSelectorFactory::Create( - metrics_sdk::InstrumentType::kHistogram, "*", "ms"); + // One histogram view per unit. The unit is the selector, so an + // instrument gets the ladder that fits what it measures -- a byte + // count no longer inherits a latency ladder. Edges come from + // HistogramBuckets.h, which owns every ladder. + // + // Both views keep the "*" name pattern and an EMPTY view name: a + // non-empty view name would rename every matching histogram to it and + // collapse them into a single series. + // + // The meter selector MUST match the meter name used by getMeter() and + // the beast OTelCollector, or a view never applies and instruments + // fall back to the SDK default ladder (ceiling 10,000). + auto const addUnitView = [this]( + std::string const& unitCode, + std::vector boundaries, + std::string const& description) { + auto selector = metrics_sdk::InstrumentSelectorFactory::Create( + metrics_sdk::InstrumentType::kHistogram, "*", unitCode); + auto meterSelector = + metrics_sdk::MeterSelectorFactory::Create(std::string(kMeterName), "", ""); + auto config = std::make_shared(); + config->boundaries_ = std::move(boundaries); + auto view = metrics_sdk::ViewFactory::Create( + "", description, metrics_sdk::AggregationType::kHistogram, std::move(config)); + meterProvider_->AddView(std::move(selector), std::move(meterSelector), std::move(view)); + }; - // Must match the meter name used by getMeter() and the beast - // OTelCollector, or the view never applies. - auto meterSelector = - metrics_sdk::MeterSelectorFactory::Create(std::string(kMeterName), "", ""); - - auto histogramConfig = std::make_shared(); - histogramConfig->boundaries_ = - std::vector{1.0, 5.0, 10.0, 25.0, 50.0, 100.0, 250.0, 500.0, 1000.0, 5000.0}; - - // An empty view name applies the buckets without renaming. A name here - // would collapse every matching histogram into one series. - auto histogramView = metrics_sdk::ViewFactory::Create( - "", - "SpanMetrics-compatible histogram buckets", - metrics_sdk::AggregationType::kHistogram, - std::move(histogramConfig)); - - meterProvider_->AddView( - std::move(histogramSelector), std::move(meterSelector), std::move(histogramView)); + addUnitView( + beast::insight::otelUnitCode(beast::insight::Unit::Millis), + buckets::toVector(buckets::kMillisecondBuckets), + "Duration buckets, 1 ms to 120 s"); + addUnitView( + beast::insight::otelUnitCode(beast::insight::Unit::Bytes), + buckets::toVector(buckets::kByteBuckets), + "Size buckets, 512 B to 1 MiB"); // Publish as the global meter provider so developers (and the beast // OTelCollector shim) reach the same pipeline. diff --git a/src/tests/libxrpl/beast/insight/Unit.cpp b/src/tests/libxrpl/beast/insight/Unit.cpp index dee9e45e50..29ceac2b32 100644 --- a/src/tests/libxrpl/beast/insight/Unit.cpp +++ b/src/tests/libxrpl/beast/insight/Unit.cpp @@ -70,6 +70,14 @@ TEST(InsightUnit, otelCodeIsTheUcumCodeForEachUnit) EXPECT_STREQ(otelUnitCode(Unit::Bytes), "By"); } +// The description is what an operator reads in the metric catalogue, so a +// byte-valued instrument must not describe itself as a duration. +TEST(InsightUnit, descriptionMatchesWhatTheUnitActuallyMeasures) +{ + EXPECT_STREQ(otelUnitDescription(Unit::Millis), "Duration in ms"); + EXPECT_STREQ(otelUnitDescription(Unit::Bytes), "Size in bytes"); +} + TEST(InsightUnit, defaultEventUnitIsMillisForBackwardCompatibility) { // Every pre-existing makeEvent(name) call site records a duration, so the From 6e2b2da7728660d17c17dde7c0e475d28ea79c2a Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Fri, 21 Aug 2026 12:46:56 +0100 Subject: [PATCH 4/5] fix(telemetry): resolve microsecond latencies below 100us The microsecond ladder's first edge was 100us, which sat ABOVE the mass of every instrument using it. Measured on devnet: 99.3% of job_queued_us samples, 92.5% of job_running_us and 90.4% of getobject_lookup_us fell in that first bucket. histogram_quantile then interpolated inside bucket 0 and returned `quantile / fraction_in_bucket_0 x first_edge` -- p75/p95/p99 of job_queued_us read 75.52/95.66/99.69us against a prediction of 75.53/95.67/99.70. Three-decimal agreement: those panels were reporting arithmetic on the bucket edge, not latency. The fix was already half-written. kSubMillisecondBoundaries had been parked in MetricsRegistry.cpp as [[maybe_unused]] with a comment noting exactly this problem for nodestore reads. Its edges are now folded into kMicrosecondBuckets rather than deleted, so the parked intent is carried forward: 1..1000us resolution where the mass is, upper edges unchanged so multi-second stalls stay measurable. Also moves the GetObject count and charge ladders into HistogramBuckets.h, so all five ladders have one owner and one set of invariant tests (29 now). Adds check_bucket_parity.py, wired into the existing OTel naming workflow. The C++ millisecond ladder and the collector's spanmetrics ladder are specified to agree over their shared range; they were identical when shipped, then the collector side alone was extended and nothing noticed for eleven phases. The check asserts containment rather than equality, because jobs outlive spans -- jobq_updatepaths averages ~60s, which no span approaches, so demanding equality would force a ceiling that censors it. Verified it rejects a missing collector edge, a bogus in-range edge, and a return to the 5s ceiling. ledger-data-sync's "Job Queue Wait p95 By Type" moves off the beast jobq_*_q_milliseconds pair onto job_queued_us filtered by job_type. Those beast metrics are ms-quantised at the source (Event rounds up to a whole millisecond), so 94-100% of their samples sat in the first bucket and no ladder change could fix them. Note the label values are camelCase (job_type="ledgerData"), not the lowercase metric-name fragments. Both histogram-fed alert thresholds re-validated and left unchanged, with the measured basis recorded so neither gets tuned against the old artefact: only 0.0022% of job_queued_us samples exceed the 1s threshold, and every edge bracketing the 1000ms ios_latency threshold survived the ladder change. Docs: the rpc_size "known issue -- tracked separately" notes in the runbook and 09-data-collection-reference are now resolved notes, the stale 10-edge span_duration bucket list is corrected to the collector's real 20, and the runbook gains a "Reading A Histogram Percentile" section covering both saturation traps and the expected discontinuity after a ladder change. --- .../scripts/telemetry/check_bucket_parity.py | 128 ++++++++++++++++++ .github/workflows/on-pr.yml | 1 + .../workflows/reusable-check-otel-naming.yml | 8 ++ .../09-data-collection-reference.md | 27 ++-- .../grafana/dashboards/ledger-data-sync.json | 16 +-- .../grafana/provisioning/alerting/rules.yaml | 15 ++ docs/telemetry-runbook.md | 64 +++++++-- include/xrpl/telemetry/HistogramBuckets.h | 65 +++++++++ .../libxrpl/telemetry/HistogramBuckets.cpp | 47 ++++++- src/xrpld/telemetry/MetricsRegistry.cpp | 80 ++--------- 10 files changed, 354 insertions(+), 97 deletions(-) create mode 100755 .github/scripts/telemetry/check_bucket_parity.py diff --git a/.github/scripts/telemetry/check_bucket_parity.py b/.github/scripts/telemetry/check_bucket_parity.py new file mode 100755 index 0000000000..4c723fb4c0 --- /dev/null +++ b/.github/scripts/telemetry/check_bucket_parity.py @@ -0,0 +1,128 @@ +#!/usr/bin/env python3 +"""Assert the C++ millisecond ladder agrees with the collector's spanmetrics ladder. + +The two are specified to match so a span-derived latency panel and a native +histogram panel can be read on the same scale. They *were* identical when first +shipped. Then the collector ladder alone was extended -- sub-millisecond edges +below 1ms and second-scale edges up to 30s -- and nothing checked the other +side, so the C++ ladder stayed capped at 5s. Every quantile above 5s then read +back as a flat 5000, because Prometheus returns the second-highest edge for a +quantile landing in the `+Inf` bucket. That looks like a measurement rather +than an error, which is why it survived for eleven phases. + +The rule is containment, not equality: + + * every representable collector edge MUST appear in the C++ ladder, so the + shared range reads identically; + * the C++ ladder MAY carry extra edges ABOVE the collector's highest edge, + because jobs outlive spans -- the updatepaths job type was measured + averaging ~60s, which no span approaches. Demanding equality would force a + ceiling that censors it, reintroducing the bug this guards against; + * collector edges below 1ms are expected to be ABSENT rather than missing: + beast::insight::Event rounds every duration up to a whole millisecond + before it reaches the histogram, so those edges could never collect a + sample. + +Exit 0 when the ladders agree, 1 with a diff when they do not. +""" + +import re +import sys +from pathlib import Path + +HEADER = Path("include/xrpl/telemetry/HistogramBuckets.h") +COLLECTOR = Path("docker/telemetry/otel-collector-config.yaml") + +# beast::insight::Event applies ceil, so anything below 1ms +# collapses onto the 1ms edge. +REPRESENTABLE_FLOOR_MS = 1.0 + +UNIT_TO_MS = {"ms": 1.0, "s": 1000.0} + + +def collector_edges_ms(): + """Parse the spanmetrics bucket list, normalising each edge to milliseconds.""" + text = COLLECTOR.read_text() + match = re.search(r"buckets:\s*\[(.*?)\]", text, re.S) + if not match: + sys.exit(f"{COLLECTOR}: no 'buckets:' list found") + + edges = [] + for raw in match.group(1).split(","): + token = raw.strip() + if not token: + continue + parsed = re.fullmatch(r"([0-9.]+)(ms|s)", token) + if not parsed: + sys.exit(f"{COLLECTOR}: cannot parse bucket edge {token!r}") + edges.append(float(parsed.group(1)) * UNIT_TO_MS[parsed.group(2)]) + return edges + + +def cpp_edges_ms(): + """Parse kMillisecondBuckets out of the header that owns every ladder.""" + text = HEADER.read_text() + match = re.search(r"kMillisecondBuckets\{(.*?)\};", text, re.S) + if not match: + sys.exit(f"{HEADER}: kMillisecondBuckets not found") + return [ + float(token.strip().replace("'", "")) + for token in match.group(1).split(",") + if token.strip() + ] + + +def main(): + collector = collector_edges_ms() + cpp = cpp_edges_ms() + required = [edge for edge in collector if edge >= REPRESENTABLE_FLOOR_MS] + if not required: + sys.exit(f"{COLLECTOR}: no edges at or above {REPRESENTABLE_FLOOR_MS} ms") + collector_top = max(required) + + missing = [edge for edge in required if edge not in cpp] + # An extra C++ edge inside the collector's range means the two scales + # disagree where they overlap. Above the collector's top it is a deliberate + # extension. + inside_range = [e for e in cpp if e not in required and e < collector_top] + + if not missing and not inside_range: + extensions = [e for e in cpp if e > collector_top] + summary = f"OK: all {len(required)} representable collector edges present" + if extensions: + pretty = ", ".join(f"{e:g}" for e in extensions) + summary += ( + f"; {len(extensions)} extension edge(s) above " + f"{collector_top:g} ms: [{pretty}]" + ) + print(summary) + return 0 + + print("Bucket ladder parity violated.", file=sys.stderr) + print( + f" collector (>= {REPRESENTABLE_FLOOR_MS:g} ms): " + f"{[f'{e:g}' for e in required]}", + file=sys.stderr, + ) + print( + f" HistogramBuckets.h : {[f'{e:g}' for e in cpp]}", file=sys.stderr + ) + for edge in missing: + print(f" MISSING from the C++ ladder: {edge:g} ms", file=sys.stderr) + for edge in inside_range: + print( + f" C++ edge {edge:g} ms lies inside the collector's range but is not " + "a collector edge -- add it to the collector or drop it here", + file=sys.stderr, + ) + print( + "\nThe two ladders must agree over their shared range. Extra C++ edges are\n" + "permitted only ABOVE the collector's highest edge. Change both sides, or\n" + "change the spec in OpenTelemetryPlan/Phase7_taskList.md.", + file=sys.stderr, + ) + return 1 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/.github/workflows/on-pr.yml b/.github/workflows/on-pr.yml index 9fd8b14b27..5135f45b43 100644 --- a/.github/workflows/on-pr.yml +++ b/.github/workflows/on-pr.yml @@ -72,6 +72,7 @@ jobs: .github/scripts/levelization/** .github/scripts/otel-naming/** .github/scripts/rename/** + .github/scripts/telemetry/** .github/workflows/reusable-check-levelization.yml .github/workflows/reusable-check-otel-naming.yml .github/workflows/reusable-check-rename.yml diff --git a/.github/workflows/reusable-check-otel-naming.yml b/.github/workflows/reusable-check-otel-naming.yml index 54cab30640..a37e7e1632 100644 --- a/.github/workflows/reusable-check-otel-naming.yml +++ b/.github/workflows/reusable-check-otel-naming.yml @@ -33,3 +33,11 @@ jobs: # it enforces each rule only when the layer it needs is present, so it # works whether telemetry changes land in one PR or several. run: python .github/scripts/otel-naming/check_otel_naming.py + - name: Check histogram bucket parity + # The C++ millisecond ladder and the collector's spanmetrics ladder are + # specified to agree over their shared range. They were identical when + # first shipped, then the collector side alone was extended and nothing + # noticed for eleven phases: native histograms stayed capped at 5s while + # spans reached 30s, so every quantile above 5s reported a flat 5000. + # Nothing but a check keeps two lists in step. + run: python .github/scripts/telemetry/check_bucket_parity.py diff --git a/OpenTelemetryPlan/09-data-collection-reference.md b/OpenTelemetryPlan/09-data-collection-reference.md index 3578774b37..fd0d8135f6 100644 --- a/OpenTelemetryPlan/09-data-collection-reference.md +++ b/OpenTelemetryPlan/09-data-collection-reference.md @@ -531,12 +531,12 @@ a destructor must not depend on still existing. A query that only groups by The OTel Collector's SpanMetrics connector automatically generates RED (Rate, Errors, Duration) metrics from every span. No custom metrics code in xrpld is needed. -| Prometheus Metric | Type | Description | -| ----------------------------------- | --------- | ------------------------------------------------------------------------------ | -| `span_calls_total` | Counter | Total span invocations | -| `span_duration_milliseconds_bucket` | Histogram | Latency distribution (buckets: 1, 5, 10, 25, 50, 100, 250, 500, 1000, 5000 ms) | -| `span_duration_milliseconds_count` | Histogram | Observation count | -| `span_duration_milliseconds_sum` | Histogram | Cumulative latency | +| Prometheus Metric | Type | Description | +| ----------------------------------- | --------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `span_calls_total` | Counter | Total span invocations | +| `span_duration_milliseconds_bucket` | Histogram | Latency distribution. Buckets come from the collector's spanmetrics config: 0.01, 0.05, 0.1, 0.25, 0.5, 1, 5, 10, 25, 50, 100, 250, 500 ms then 1, 2, 3, 4, 5, 10, 30 s. The sub-millisecond edges exist because most xrpld spans are far below 1 ms; without them every p95/p99 pinned to a constant 0.95 ms | +| `span_duration_milliseconds_count` | Histogram | Observation count | +| `span_duration_milliseconds_sum` | Histogram | Cumulative latency | **Standard labels on every metric**: `span_name`, `status_code`, `service_name`, `span_kind` @@ -684,13 +684,14 @@ prefix=xrpld Quantiles collected: 0th, 50th, 90th, 95th, 99th, 100th percentile. -\* **`rpc_size` instrument mismatch (known issue):** response size in bytes is -recorded through the millisecond-scaled event histogram (`makeEvent`), so it is -exported as `rpc_size_milliseconds_bucket` with time-scaled boundaries that top -out at 5000. Byte values above ~5 KB saturate in the last bucket, so the -percentiles are not true byte sizes. The _RPC & Pathfinding_ panel is flagged -accordingly. A dedicated byte-unit histogram is needed to fix this; tracked -separately. +\* **`rpc_size` now records bytes as bytes (fixed).** It used to go through the +millisecond-scaled event histogram and export as `rpc_size_milliseconds_bucket` +on a ladder topping out at 5000, so the 24.9% of responses larger than 5 kB all +landed in the last bucket and every percentile read back as a flat 5000 — a +plausible-looking constant rather than a byte size. `beast::insight::Event` now +declares a `Unit`, so this instrument is created with unit `By` and exports as +**`rpc_size_bytes_bucket`** on `kByteBuckets` (512 B to 1 MiB, placed from the +measured distribution). Queries and panels must use the new name. **Grafana dashboards**: _Node Health_ (`ios_latency`), _RPC & Pathfinding_ (`rpc_time`, `rpc_size`, `pathfind_*`) diff --git a/docker/telemetry/grafana/dashboards/ledger-data-sync.json b/docker/telemetry/grafana/dashboards/ledger-data-sync.json index 4eabe25f03..8f9e33efc5 100644 --- a/docker/telemetry/grafana/dashboards/ledger-data-sync.json +++ b/docker/telemetry/grafana/dashboards/ledger-data-sync.json @@ -1251,7 +1251,7 @@ }, { "title": "Job Queue Wait p95 By Type", - "description": "###### What this is:\n*95th-percentile time a job waits in the queue before a worker thread picks it up, for the sync-critical job types. This is the metric form of the 'ProcessLData wait: NNNNms' warnings in the debug log.*\n\n###### How it's computed:\n*histogram_quantile(0.95, rate(jobq__q_milliseconds_bucket[$__rate_interval])) for ledgerdata, acceptledger, fetchtxndata, transaction, advanceledger, ledgerrequest.*\n\n###### Reading it:\n*Queue wait should be single-digit to low-tens of ms. High ledgerdata/fetchtxndata wait = the node cannot process inbound ledger data fast enough.*\n\n###### Healthy range:\n*< ~50ms p95 per type on a healthy node.*\n\n###### Watch for:\n*ledgerdata or fetchtxndata q-wait spiking to seconds = worker threads are blocked (usually on NuDB reads - see the cause tier).*\n\n###### Keywords:\n- **Job queue / job type** *(per node)* \u2014 xrpld's worker-thread pool; every unit of background work is enqueued under a named job type.\n- **Deferred job** *(per node)* \u2014 a job held back because its type is already at its concurrency limit; the leading indicator of queue backpressure.\n\n###### Computation boundary:\n*Result: Per node \u2014 each series is one server's own value.*\n*Recorded in xrpld code as a native metric (beast::insight); the collector only forwards it; the Grafana query selects and aggregates it.*\n\n###### Source:\n[core/JobQueue.cpp](https://github.com/XRPLF/rippled/blob/develop/src/libxrpl/core/detail/JobQueue.cpp)\n\n###### Function:\n`JobQueue::getJson (per-type queue timing)`\n\n###### References:\n[Telemetry glossary](https://github.com/XRPLF/rippled/blob/develop/docs/telemetry-glossary.md#job-queue-job-type)", + "description": "###### What this is:\n*95th-percentile time a job waits in the queue before a worker thread picks it up, for the sync-critical job types. This is the metric form of the 'ProcessLData wait: NNNNms' warnings in the debug log.*\n\n###### How it's computed:\n*histogram_quantile(0.95, rate(job_queued_us_bucket{job_type=\"\"}[$__rate_interval])) for ledgerData, acceptLedger, fetchTxnData, transaction, advanceLedger, ledgerRequest. Reads the OTel-native microsecond instrument rather than the beast jobq_* pair: beast Events round every duration up to a whole millisecond, so 94-100% of their samples landed in the first bucket and every percentile was an interpolation inside it rather than a measurement.*\n\n###### Reading it:\n*Queue wait is normally tens to hundreds of microseconds. High ledgerData/fetchTxnData wait = the node cannot process inbound ledger data fast enough.*\n\n###### Healthy range:\n*< ~500us p95 per type on a healthy node; sustained milliseconds is already backpressure.*\n\n###### Watch for:\n*ledgerData or fetchTxnData q-wait spiking to seconds = worker threads are blocked (usually on NuDB reads - see the cause tier).*\n\n###### Keywords:\n- **Job queue / job type** *(per node)* \u2014 xrpld's worker-thread pool; every unit of background work is enqueued under a named job type.\n- **Deferred job** *(per node)* \u2014 a job held back because its type is already at its concurrency limit; the leading indicator of queue backpressure.\n\n###### Computation boundary:\n*Result: Per node \u2014 each series is one server's own value.*\n*Recorded in xrpld code by MetricsRegistry as an OTel-native histogram in microseconds; the collector only forwards it; the Grafana query selects and aggregates it.*\n\n###### Source:\n[core/JobQueue.cpp](https://github.com/XRPLF/rippled/blob/develop/src/libxrpl/core/detail/JobQueue.cpp)\n\n###### Function:\n`JobQueue::getJson (per-type queue timing)`\n\n###### References:\n[Telemetry glossary](https://github.com/XRPLF/rippled/blob/develop/docs/telemetry-glossary.md#job-queue-job-type)", "type": "timeseries", "gridPos": { "h": 10, @@ -1272,48 +1272,48 @@ "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, - "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(jobq_ledgerdata_q_milliseconds_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"ledgerdata q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" + "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(job_queued_us_bucket{job_type=\"ledgerData\", service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"ledgerData q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" }, { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, - "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(jobq_acceptledger_q_milliseconds_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"acceptledger q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" + "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(job_queued_us_bucket{job_type=\"acceptLedger\", service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"acceptLedger q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" }, { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, - "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(jobq_fetchtxndata_q_milliseconds_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"fetchtxndata q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" + "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(job_queued_us_bucket{job_type=\"fetchTxnData\", service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"fetchTxnData q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" }, { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, - "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(jobq_transaction_q_milliseconds_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"transaction q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" + "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(job_queued_us_bucket{job_type=\"transaction\", service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"transaction q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" }, { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, - "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(jobq_advanceledger_q_milliseconds_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"advanceledger q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" + "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(job_queued_us_bucket{job_type=\"advanceLedger\", service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"advanceLedger q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" }, { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, - "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(jobq_ledgerrequest_q_milliseconds_bucket{service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"ledgerrequest q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" + "expr": "label_replace(label_join(label_replace(histogram_quantile(0.95, sum by (le, service_instance_id, xrpl_branch, xrpl_node_role, xrpl_work_item) (rate(job_queued_us_bucket{job_type=\"ledgerRequest\", service_instance_id=~\"$node\", deployment_environment=~\"$deployment_environment\", xrpl_network_type=~\"$xrpl_network_type\", service_name=~\"$service_name\", xrpl_work_item=~\"$xrpl_work_item\", xrpl_branch=~\"$xrpl_branch\", xrpl_node_role=~\"$xrpl_node_role\"}[$__rate_interval]))), \"series\", \"ledgerRequest q-wait p95\", \"\", \"\"), \"xrpl_ident\", \", \", \"service_instance_id\", \"xrpl_branch\", \"xrpl_work_item\"), \"xrpl_ident\", \"[$1]\", \"xrpl_ident\", \"(?:, )*(.*[^, ])(?:, )*\")" } ], "fieldConfig": { "defaults": { "displayName": "${__field.labels.series} ${__field.labels.xrpl_ident}", - "unit": "ms", + "unit": "µs", "custom": { "axisLabel": "p95 Wait (ms)", "spanNulls": 1800000, diff --git a/docker/telemetry/grafana/provisioning/alerting/rules.yaml b/docker/telemetry/grafana/provisioning/alerting/rules.yaml index 9746559b28..7d909074b2 100644 --- a/docker/telemetry/grafana/provisioning/alerting/rules.yaml +++ b/docker/telemetry/grafana/provisioning/alerting/rules.yaml @@ -480,6 +480,15 @@ groups: # p99 time a job waits in the queue before running. A sustained p99 # above 1s means the node is saturated and work is backing up. `le` must # stay inside the inner sum or histogram_quantile cannot interpolate. + # + # Threshold re-validated after the microsecond ladder was re-cut. Do NOT + # tune it down against a casual reading of this p99: before that change + # the ladder's first edge was 100us with 99.3% of samples beneath it, so + # p99 reported 99.7us -- the bucket edge scaled by the quantile, not a + # latency. Measured cumulative distribution: 99.26% of samples land + # within 100us, 99.969% within 5ms, 99.990% within 100ms, and only + # 0.0022% exceed 1s. So 1s sits about four orders of magnitude above the + # healthy p99 and fires only on genuine saturation, which is the intent. - uid: xrpld-jobqueue-latency-high title: JobQueueLatencyHigh condition: C @@ -544,6 +553,12 @@ groups: # first and explains the others. Measured p99-of-p95 is 37-49ms on # healthy nodes and 488-566ms on nodes that are actively flapping, so # 1000ms flags genuine degradation rather than the current baseline. + # + # Still valid after the millisecond ladder was extended: that change only + # ADDED edges above 5s (2s/3s/4s/10s/30s/60s/120s) and removed none, so + # every edge bracketing this threshold -- 25/50/100/250/500/1000ms -- is + # unchanged and the measurements above still hold. ios_latency's own mean + # is 12.9ms, far below the threshold. - uid: xrpld-nodestore-io-latency-high title: NodeStoreIOLatencyHigh condition: C diff --git a/docs/telemetry-runbook.md b/docs/telemetry-runbook.md index 3b903a784c..a95a0ab12e 100644 --- a/docs/telemetry-runbook.md +++ b/docs/telemetry-runbook.md @@ -2262,22 +2262,68 @@ Requires `trace_peer=1` in the `[telemetry]` config section. | ------------------------- | ---------- | ------------------------------------------------------------- | ----------- | | RPC Request Rate | stat | `rate(rpc_requests[5m])` | — | | RPC Response Time | timeseries | `histogram_quantile(0.95, rpc_time_milliseconds_bucket)` | — | -| RPC Response Size | timeseries | `histogram_quantile(0.95, rpc_size_milliseconds_bucket)` | — | +| RPC Response Size | timeseries | `histogram_quantile(0.95, rpc_size_bytes_bucket)` | — | | RPC Response Time Heatmap | heatmap | `rpc_time_milliseconds_bucket` | — | | Pathfinding Fast Duration | timeseries | `histogram_quantile(0.95, pathfind_fast_milliseconds_bucket)` | — | | Pathfinding Full Duration | timeseries | `histogram_quantile(0.95, pathfind_full_milliseconds_bucket)` | — | | Resource Warnings Rate | stat | `rate(warn_total[$__rate_interval])` | — | | Resource Drops Rate | stat | `rate(drop_total[$__rate_interval])` | — | -> **The `_milliseconds` suffix comes from the exporter, not from xrpld.** These -> histograms are created with unit `"ms"` -> ([OTelCollector.cpp:615](../src/libxrpl/beast/insight/OTelCollector.cpp#L615)), -> so the Prometheus exporter appends the unit to the family name — `rpc_time` -> becomes `rpc_time_milliseconds_bucket`. Querying the bare `rpc_time_bucket`, +> **The unit suffix comes from the exporter, not from xrpld.** Each histogram +> declares a unit, and the Prometheus exporter appends the unit's name to the +> family name — a `ms` instrument like `rpc_time` becomes +> `rpc_time_milliseconds_bucket`. Querying the bare `rpc_time_bucket`, > `ios_latency_bucket` or `pathfind_fast_bucket` returns no data and no error. -> **Known issue**: `rpc_size` counts bytes but shares the same `"ms"` histogram -> constructor, so it is exported as `rpc_size_milliseconds_bucket` — the suffix -> is wrong, the name is nonetheless the one to query. +> +> The unit an `Event` declares also selects its bucket ladder, because the +> histogram views match on unit. `rpc_size` measures bytes, so it declares +> `Unit::Bytes` and exports as **`rpc_size_bytes_bucket`** on the byte ladder. +> It used to share the `ms` constructor and export as +> `rpc_size_milliseconds_bucket` on a latency ladder — if you find that name in +> an old query or bookmark, it no longer exists. + +#### Reading A Histogram Percentile + +Two failure modes make a percentile panel lie, and neither looks like an error — +both produce a believable number. Check for them before trusting any p95/p99. + +**Saturated at the top.** If the quantile falls in the `+Inf` bucket, Prometheus +returns the **second-highest** bucket edge, not `+Inf`. A panel pinned to a round +number that happens to equal the ladder's top edge is the signature. Confirm by +comparing the top finite bucket against the total: + +```promql +1 - ( + sum(last_over_time(_bucket{le=""}[15m])) + / sum(last_over_time(_bucket{le="+Inf"}[15m])) +) +``` + +A non-trivial result means samples are being censored and the percentile is a +lower bound, not a measurement. + +**Saturated at the bottom.** If nearly every sample lands in the first bucket, +`histogram_quantile` interpolates _inside_ it and returns +`quantile / fraction_in_bucket_0 × first_edge`. The signature is a p75/p95/p99 +that sit in near-constant proportion to each other and to the first edge — for +example 75.5 / 95.7 / 99.7 against a 100 µs floor. Confirm with: + +```promql +sum(last_over_time(_bucket{le=""}[15m])) +/ sum(last_over_time(_bucket{le="+Inf"}[15m])) +``` + +Anything close to 1 means the panel is reporting arithmetic on the bucket edge. + +**After a ladder change, expect a discontinuity.** Existing series keep their old +`le` values, so a percentile panel shows a step at the restart that introduced +new edges. That break is the ladder changing, not an incident. + +Bucket edges for the native instruments live in one place — +[`include/xrpl/telemetry/HistogramBuckets.h`](../include/xrpl/telemetry/HistogramBuckets.h). +The millisecond ladder is required to contain every representable edge of the +collector's spanmetrics ladder; `.github/scripts/telemetry/check_bucket_parity.py` +enforces that in CI, because the two silently drifted once already. ### Span → Metric → Dashboard Summary diff --git a/include/xrpl/telemetry/HistogramBuckets.h b/include/xrpl/telemetry/HistogramBuckets.h index 381362034e..6a00417961 100644 --- a/include/xrpl/telemetry/HistogramBuckets.h +++ b/include/xrpl/telemetry/HistogramBuckets.h @@ -136,6 +136,68 @@ inline constexpr std::array kByteBuckets{ 262'144.0, 1'048'576.0}; +/** + * Bucket edges, in microseconds, for the OTel-native duration instruments + * created directly on MetricsRegistry: job queue wait and run times, RPC + * method latency, and GetObject lookup latency. + * + * The edges from 1 to 1000 us are the ones that matter most. An earlier + * version of this ladder started at 100 us, which sat ABOVE the mass of every + * instrument using it: 99.3% of job_queued_us samples, 92.5% of + * job_running_us and 90.4% of getobject_lookup_us fell in that first bucket. + * `histogram_quantile` then interpolated inside bucket 0 and returned the + * boundary scaled by the requested quantile -- p75/p95/p99 of job_queued_us + * read 75.5/95.7/99.7 us, which is arithmetic on the bucket edge, not a + * latency. A warm nodestore read is around 1.5 us, so single-microsecond + * resolution is not excessive here. + * + * The upper edges reach a minute so multi-second stalls stay measurable. The + * SDK's own default ladder stops at 10,000, which every one of these + * instruments exceeds during catch-up. + */ +inline constexpr std::array kMicrosecondBuckets{ + 1.0, + 2.0, + 5.0, + 10.0, + 25.0, + 50.0, + 100.0, + 250.0, + 500.0, + 1'000.0, + 5'000.0, + 25'000.0, + 100'000.0, + 500'000.0, + 1'000'000.0, + 5'000'000.0, + 10'000'000.0, + 30'000'000.0, + 60'000'000.0}; + +/** + * Bucket edges for the GetObject request object count. + * + * Counts run from 1 to the hard reply cap (kHardMaxReplyNodes, 12288). The + * honest sync path asks for at most 8 objects, so the low edges are + * fine-grained; the upper ones follow the charge size bands up to the cap. + * Because the top edge IS the hard cap, this ladder cannot saturate. + */ +inline constexpr std::array + kObjectCountBuckets{1.0, 2.0, 4.0, 8.0, 16.0, 64.0, 256.0, 1'024.0, 4'096.0, 12'288.0}; + +/** + * Bucket edges for the GetObject resource charge. + * + * Charges span 0 (the free tier) to roughly 99k for a full-size all-miss + * request. The edges bracket the two thresholds that decide a peer's fate -- + * the warning threshold at 5000 and the drop threshold at 25000 -- so a + * dashboard can show how close charges run to each. + */ +inline constexpr std::array + kChargeBuckets{0.0, 100.0, 500.0, 1'000.0, 5'000.0, 10'000.0, 25'000.0, 50'000.0, 100'000.0}; + /** * @brief Check that a ladder is strictly ascending and non-negative. * @@ -163,6 +225,9 @@ isAscendingNonNegative(std::span ladder) noexcept static_assert(isAscendingNonNegative(kMillisecondBuckets)); static_assert(isAscendingNonNegative(kByteBuckets)); +static_assert(isAscendingNonNegative(kMicrosecondBuckets)); +static_assert(isAscendingNonNegative(kObjectCountBuckets)); +static_assert(isAscendingNonNegative(kChargeBuckets)); /** * @brief Copy a ladder into the `std::vector` the OTel SDK wants. diff --git a/src/tests/libxrpl/telemetry/HistogramBuckets.cpp b/src/tests/libxrpl/telemetry/HistogramBuckets.cpp index 1eb013784e..f54a7ecde1 100644 --- a/src/tests/libxrpl/telemetry/HistogramBuckets.cpp +++ b/src/tests/libxrpl/telemetry/HistogramBuckets.cpp @@ -60,7 +60,52 @@ INSTANTIATE_TEST_SUITE_P( HistogramBucketsTest, ::testing::Values( std::span{kMillisecondBuckets}, - std::span{kByteBuckets})); + std::span{kByteBuckets}, + std::span{kMicrosecondBuckets}, + std::span{kObjectCountBuckets}, + std::span{kChargeBuckets})); + +TEST(HistogramBucketsRange, microsecondFloorLandsBelowTheMeasuredMass) +{ + // Measured: 99.3% of job_queued_us samples sat below the old 100 us floor, + // so p75/p95/p99 all interpolated inside bucket 0 and returned + // 75.5/95.7/99.7 us -- the boundary scaled by the requested quantile, + // not a latency. Warm nodestore reads are ~1.5 us, so the floor has to + // reach single microseconds and several edges must precede 100 us. + EXPECT_LE(kMicrosecondBuckets.front(), 1.0); + + auto const belowHundred = + std::ranges::count_if(kMicrosecondBuckets, [](double edge) { return edge < 100.0; }); + EXPECT_GE(belowHundred, 5) << "too little resolution below 100 us"; +} + +TEST(HistogramBucketsRange, microsecondCeilingStillReachesOneMinute) +{ + // Job waits and RPC latencies routinely exceed the SDK default ceiling of + // 10,000; multi-second stalls must stay measurable rather than censored. + EXPECT_EQ(kMicrosecondBuckets.back(), 60'000'000.0); +} + +TEST(HistogramBucketsRange, objectCountLadderCannotSaturate) +{ + // GetObject counts run 1..kHardMaxReplyNodes, so the top edge IS the hard + // cap and censoring is impossible by construction. + EXPECT_EQ(kObjectCountBuckets.front(), 1.0); + EXPECT_EQ(kObjectCountBuckets.back(), 12'288.0); +} + +TEST(HistogramBucketsRange, chargeLadderBracketsTheResourceThresholds) +{ + // The two edges that decide a peer's fate must be present so a dashboard + // can show how close charges run to each: warning at 5000, drop at 25000. + // A leading 0 separates the free tier from everything else. + EXPECT_EQ(kChargeBuckets.front(), 0.0); + for (double const threshold : {5'000.0, 25'000.0}) + { + EXPECT_NE(std::ranges::find(kChargeBuckets, threshold), kChargeBuckets.end()) + << threshold << " is a resource threshold and must be an edge"; + } +} // The validator must also REJECT. A predicate that only ever returns true // would let every ladder above pass while proving nothing. diff --git a/src/xrpld/telemetry/MetricsRegistry.cpp b/src/xrpld/telemetry/MetricsRegistry.cpp index 69aa120705..04c2670fab 100644 --- a/src/xrpld/telemetry/MetricsRegistry.cpp +++ b/src/xrpld/telemetry/MetricsRegistry.cpp @@ -63,6 +63,7 @@ #include #include #include +#include #include #include @@ -84,7 +85,6 @@ #include #include -#include #include #include #include @@ -119,66 +119,16 @@ constexpr char kRpcMethodDurationUs[] = "rpc_method_us"; constexpr char kJobTypeLabel[] = "job_type"; constexpr char kHandlerLabel[] = "handler"; -/** - * Bucket boundaries for microsecond-valued duration instruments. - * - * 100 µs, 500 µs, 1 ms, 5 ms, 10 ms, 25 ms, 50 ms, 100 ms, 250 ms, 500 ms, - * 1 s, 2.5 s, 5 s, 10 s, 30 s, 60 s. Covers sub-millisecond jobs through - * multi-second stalls without saturating. - */ -constexpr std::array kMicrosecondBoundaries{ - 100.0, - 500.0, - 1'000.0, - 5'000.0, - 10'000.0, - 25'000.0, - 50'000.0, - 100'000.0, - 250'000.0, - 500'000.0, - 1'000'000.0, - 2'500'000.0, - 5'000'000.0, - 10'000'000.0, - 30'000'000.0, - 60'000'000.0}; - -/** - * Bucket boundaries for latencies that are normally sub-millisecond. - * - * 1 µs, 2 µs, 5 µs, 10 µs, 25 µs, 50 µs, 100 µs, 250 µs, 500 µs, 1 ms, 5 ms, - * 25 ms. - * - * kMicrosecondBoundaries starts at 100 µs, which is above the entire range a - * healthy nodestore read occupies, so every warm read falls in its first - * bucket and the distribution reads as flat. These edges resolve the warm - * range instead, while still reaching far enough to show a cold tail against - * it. - * - * Currently unused: no sub-millisecond histogram instrument exists yet. The - * edges live here so the instrument that records nodestore read latency gets - * a ladder that fits it, rather than silently inheriting the wrong one. - */ -[[maybe_unused]] constexpr std::array kSubMillisecondBoundaries{ - 1.0, - 2.0, - 5.0, - 10.0, - 25.0, - 50.0, - 100.0, - 250.0, - 500.0, - 1'000.0, - 5'000.0, - 25'000.0}; - /** * Register an explicit-bucket histogram view. * * The SDK's default boundaries top out at 10,000, so any instrument whose - * values exceed that saturates and every quantile reads as the ceiling. + * values exceed that saturates and every quantile reads as the ceiling. The + * floor matters just as much and is easier to miss: a ladder whose first edge + * sits above the mass of the distribution makes every low quantile an + * interpolation inside bucket 0 -- a number derived from the bucket edge + * rather than from any sample. Both ends are chosen from measured + * distributions in HistogramBuckets.h. * * @param views The registry to add the view to. * @param name Instrument name to match (e.g. "job_running_us"). @@ -206,7 +156,7 @@ addHistogramView( * Register the microsecond-ladder view for a duration instrument. * * Job wait/run times and RPC latencies routinely exceed the SDK default - * ceiling, so they all share `kMicrosecondBoundaries`. + * ceiling, so they all share `buckets::kMicrosecondBuckets`. * * @param views The registry to add the view to. * @param name Instrument name to match. @@ -214,7 +164,10 @@ addHistogramView( void addMicrosecondHistogramView(metric_sdk::ViewRegistry& views, std::string const& name) { - addHistogramView(views, name, {kMicrosecondBoundaries.begin(), kMicrosecondBoundaries.end()}); + addHistogramView( + views, + name, + xrpl::telemetry::buckets::toVector(xrpl::telemetry::buckets::kMicrosecondBuckets)); } } // namespace @@ -352,18 +305,13 @@ MetricsRegistry::initExporterAndProvider( // asks for at most 8, so the low buckets are fine-grained and the upper // ones follow the charge size bands (64, 1024) up to the hard cap. addHistogramView( - *views, - kGetObjectRequestObjects, - {1.0, 2.0, 4.0, 8.0, 16.0, 64.0, 256.0, 1'024.0, 4'096.0, 12'288.0}); + *views, kGetObjectRequestObjects, buckets::toVector(buckets::kObjectCountBuckets)); // Charge values span 0 (free tier) to ~99k for a full-size all-miss // request. Boundaries bracket the resource thresholds that decide a // peer's fate -- kWarningThreshold (5000) and kDropThreshold (25000) -- // so a dashboard can show how close charges run to each. - addHistogramView( - *views, - kGetObjectCharge, - {0.0, 100.0, 500.0, 1'000.0, 5'000.0, 10'000.0, 25'000.0, 50'000.0, 100'000.0}); + addHistogramView(*views, kGetObjectCharge, buckets::toVector(buckets::kChargeBuckets)); // Create MeterProvider with resource, then attach the metric reader. provider_ = metric_sdk::MeterProviderFactory::Create(std::move(views), resourceAttrs); From 12826452891e92e66479db0f80d42672c29e3dca Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Fri, 21 Aug 2026 12:49:56 +0100 Subject: [PATCH 5/5] test(telemetry): invalidate job-queue baselines captured on the old ladder The workload harness gates regressions on histogram_quantile over job_queued_us / job_running_us, so re-cutting the microsecond ladder changes what those queries return and the stored baselines no longer describe the same measurement. baseline-timings.json's job.acceptLedger.queued.p95 was 96.79us, which is 0.95 / 0.9926 x 100 -- the old 100us bucket edge scaled by the quantile, with 99.3% of samples beneath it. It was never a latency. Keeping it would make the gate LESS sensitive rather than more: a genuine regression from a real 40us to 90us would still sit under 96.79us + 50% and pass. Removes the four job.* entries and records why, including their values. The comparer reports a metric absent from the baseline as "new metric (not in baseline)" and skips it, so the span baselines stay live and gating continues for everything unaffected. is_placeholder() still returns False, so this does not disable the gate wholesale. Recapture the job.* numbers on a node running the re-cut ladder. Also corrects _bucket_note in regression-thresholds.json. It described the spanmetrics ladder as 15 edges starting at 1ms; the collector config has 20, including five sub-millisecond edges. The note's own reasoning was void too -- it justified the 10ms absolute span bound as "~2 low-end bucket widths", but the low-end bucket width is 0.01ms, not 5ms. The bound is kept and justified on the band where span quantiles actually sit, rather than on a derivation from a ladder that no longer exists. --- .../workload/baselines/baseline-timings.json | 17 +---------------- .../workload/regression-thresholds.json | 2 +- 2 files changed, 2 insertions(+), 17 deletions(-) diff --git a/docker/telemetry/workload/baselines/baseline-timings.json b/docker/telemetry/workload/baselines/baseline-timings.json index 4784953609..4e9633568b 100644 --- a/docker/telemetry/workload/baselines/baseline-timings.json +++ b/docker/telemetry/workload/baselines/baseline-timings.json @@ -1,23 +1,8 @@ { + "_note": "job.* entries were removed on 2026-08-21. They were captured against the old microsecond ladder whose first edge was 100us, with 99.3% of job_queued_us samples beneath it, so job.acceptLedger.queued.p95 = 96.79us was 0.95/0.9926 x 100 -- arithmetic on the bucket edge, not a latency. Recapture them on a node running the re-cut ladder (floor 1us); until then the comparer reports them as \"new metric (not in baseline)\" and gates only the span metrics, which are unaffected. Removed values, for reference: job.acceptLedger.queued.p95=96.79us, job.acceptLedger.running.p95=10562.50us, job.transaction.queued.p95=478.97us, job.transaction.running.p95=494.14us.", "captured_at": "2026-06-05T18:41:52Z", "git_sha": "fd1c8c6060f7a15cc9e65b16f99629d9ab7ac7dc", "metrics": { - "job.acceptLedger.queued.p95": { - "unit": "us", - "value": 96.78571428571428 - }, - "job.acceptLedger.running.p95": { - "unit": "us", - "value": 10562.499999999945 - }, - "job.transaction.queued.p95": { - "unit": "us", - "value": 478.96551724137925 - }, - "job.transaction.running.p95": { - "unit": "us", - "value": 494.1361256544502 - }, "span.consensus.accept.p50": { "unit": "ms", "value": 1.059405940594059 diff --git a/docker/telemetry/workload/regression-thresholds.json b/docker/telemetry/workload/regression-thresholds.json index ae6789f1ba..0dba5b6845 100644 --- a/docker/telemetry/workload/regression-thresholds.json +++ b/docker/telemetry/workload/regression-thresholds.json @@ -1,6 +1,6 @@ { "_description": "Per-metric regression thresholds. A metric regresses when current - baseline exceeds BOTH the percentage and absolute bounds (AND, not OR — this tolerates small-value noise). Defaults apply unless a per-metric override exists.", - "_bucket_note": "SpanMetrics latency histograms use explicit buckets [1,5,10,25,50,100,250,500,1000,2000,3000,4000,5000,10000,30000]ms. A quantile sitting near a low-end boundary can jump a full bucket (e.g. 1ms->5ms) between runs with no real change, so absolute span bounds are set to ~2 low-end bucket widths (10ms) to tolerate that quantization noise while still catching genuine multi-bucket regressions. Second-scale consensus spans now have 2s/3s/4s boundaries (previously all fell in one 1s-5s bucket); their quantiles quantize to ~1s widths there. The job_queue running bound is widened similarly — per-ledger apply work scales with TxQ burst load.", + "_bucket_note": "SpanMetrics latency histograms use explicit buckets [0.01,0.05,0.1,0.25,0.5,1,5,10,25,50,100,250,500]ms then [1,2,3,4,5,10,30]s (20 edges; docker/telemetry/otel-collector-config.yaml is the authoritative list). An earlier version of this note claimed 15 edges starting at 1ms and justified the 10ms absolute span bound as \"~2 low-end bucket widths\" — that derivation is void, because the sub-millisecond edges make the low-end bucket width 0.01ms, not 5ms. The 10ms bound is retained on its own merit: it is roughly two bucket widths in the 5-25ms band where most span quantiles actually sit, so it still absorbs single-bucket quantization jitter while catching multi-bucket regressions. Second-scale consensus spans have 2s/3s/4s boundaries, so their quantiles quantize to ~1s widths there. The job_queue running bound is widened similarly — per-ledger apply work scales with TxQ burst load. NOTE: the native job_queue histograms are microsecond-valued and their ladder was re-cut (floor 100us → 1us), so any job_queue baseline captured before that change is an interpolation artefact, not a latency.", "defaults": { "span": { "p50": { "max_pct_increase": 50.0, "max_abs_increase_ms": 10.0 },