mirror of
https://github.com/XRPLF/rippled.git
synced 2026-08-22 14:50:54 +00:00
refactor(telemetry): retire the duplicate nodestore_latency gauge
nodestore_latency published six values that nodestore_state already publishes from the same Database accessors, so the two gauges were duplicate readings of the same atomics: write_count -> node_writes getStoreCount() read_count -> node_reads_total getFetchTotalCount() write_duration_us -> node_writes_duration_us getStoreDurationUs() read_duration_us -> node_reads_duration_us getFetchDurationUs() write_mean_us -> write_mean_us store duration / count read_mean_us -> read_mean_us fetch duration / count nodestore_state is kept because its means go through scaledMean(), which saturates at INT64_MAX instead of wrapping and omits a mean when the denominator is zero rather than reporting a misleading 0 us. Removes registerNodeStoreLatencyGauge, its instrument member, the metric::nodestoreLatency constant and the lval::nodestore_latency label namespace. The gauge-over-histogram rationale and the "p99 is not obtainable" consequence are folded into observeNodeStoreTotals' docs. Retargets the gauge-contract test onto nodestore_state rather than deleting it: the scaledMean arithmetic is covered by the static_asserts in tests/libxrpl/telemetry/MetricsRegistry.cpp, but nothing else asserts that these named series multiplex onto one instrument keyed by `metric`. The test now calls the production scaledMean instead of a copy of the division, and its sub-microsecond case asserts scaledMean's actual behaviour (a genuine mean of 0 on a zero numerator with a non-zero count), which differs from the retired gauge's extra numerator guard. Rewrites both ledger-sync-health copies' panel 38/39 queries and drops the obsolete claim that the write numerator was never written: all three concrete store paths call recordStoreDuration, so write_mean_us is live on an ordinary node. The same stale [import_db] caveat is removed from the runbook, the 09 reference row and the workload validator's note.
This commit is contained in:
@@ -23,6 +23,7 @@
|
||||
|
||||
#include <xrpld/overlay/Overlay.h>
|
||||
#include <xrpld/telemetry/MetricNames.h>
|
||||
#include <xrpld/telemetry/MetricsRegistry.h>
|
||||
|
||||
#include <xrpl/basics/MallocTrim.h>
|
||||
#include <xrpl/core/JobQueue.h>
|
||||
@@ -2719,17 +2720,20 @@ TEST(MetricMacros, ledger_replay_counters_emit_nothing_when_disabled)
|
||||
EXPECT_EQ(app.registry().meterCalls(), 0);
|
||||
}
|
||||
|
||||
// The nodestore_latency gauge derives a mean from two cumulative totals the
|
||||
// node store already keeps. This mirrors the production callback in
|
||||
// MetricsRegistry::registerNodeStoreLatencyGauge, whose enabled path cannot be
|
||||
// linked into this binary, so the derivation is asserted here against the same
|
||||
// four inputs.
|
||||
TEST(MetricMacros, nodestore_latency_gauge_observes_exact_derived_means)
|
||||
// The nodestore_state gauge derives its two mean latencies from cumulative
|
||||
// totals the node store already keeps. This mirrors the production callback in
|
||||
// MetricsRegistry::observeNodeStoreTotals, whose enabled path cannot be linked
|
||||
// into this binary (MetricsRegistry.cpp is excluded from xrpl_tests when
|
||||
// telemetry is ON -- see src/tests/libxrpl/CMakeLists.txt), so the derivation
|
||||
// is asserted here against the same inputs. The division itself is the real
|
||||
// MetricsRegistry::scaledMean, a public constexpr inline that IS linkable, so
|
||||
// this test exercises production arithmetic rather than a copy of it.
|
||||
TEST(MetricMacros, nodestore_state_gauge_observes_exact_derived_means)
|
||||
{
|
||||
// Each scenario gets a FRESH provider. The reader reports cumulative
|
||||
// temporality (see CollectOnDemandReader), so a series observed by one
|
||||
// scenario would still be present in the next collect() -- which would
|
||||
// defeat the two assertions below that a mean is ABSENT when its
|
||||
// defeat the assertions below that a mean is ABSENT when its
|
||||
// denominator is zero.
|
||||
|
||||
// The four totals the production callback reads, chosen so each mean
|
||||
@@ -2754,8 +2758,8 @@ TEST(MetricMacros, nodestore_latency_gauge_observes_exact_derived_means)
|
||||
auto collectWith = [](NodeStoreTotals& state) {
|
||||
CollectingProvider const provider;
|
||||
auto gauge = provider.meter()->CreateInt64ObservableGauge(
|
||||
telemetry::metric::nodestoreLatency,
|
||||
"NodeStore mean store/fetch latency in microseconds, with counts");
|
||||
telemetry::metric::nodestoreState,
|
||||
"NodeStore I/O counters, latencies, write-queue depth and acquisition stalls");
|
||||
gauge->AddCallback(
|
||||
[](opentelemetry::metrics::ObserverResult result, void* state) {
|
||||
auto const* self = static_cast<NodeStoreTotals const*>(state);
|
||||
@@ -2764,19 +2768,27 @@ TEST(MetricMacros, nodestore_latency_gauge_observes_exact_derived_means)
|
||||
opentelemetry::metrics::ObserverResultT<std::int64_t>>>(result)
|
||||
->Observe(value, {{telemetry::label::metric, field}});
|
||||
};
|
||||
observe("write_count", static_cast<std::int64_t>(self->storeCount));
|
||||
observe("read_count", static_cast<std::int64_t>(self->fetchCount));
|
||||
if (self->storeCount > 0 && self->storeDurationUs > 0)
|
||||
// The four cumulative totals, observed unconditionally: for a
|
||||
// total, zero is the meaningful "nothing yet" reading.
|
||||
observe("node_writes", static_cast<std::int64_t>(self->storeCount));
|
||||
observe("node_reads_total", static_cast<std::int64_t>(self->fetchCount));
|
||||
observe(
|
||||
"node_writes_duration_us", static_cast<std::int64_t>(self->storeDurationUs));
|
||||
observe("node_reads_duration_us", static_cast<std::int64_t>(self->fetchDurationUs));
|
||||
|
||||
// The two derived means, through the production helper. It
|
||||
// returns nullopt when the denominator is 0, and the series is
|
||||
// then omitted rather than observed as 0: a reported 0 us would
|
||||
// claim the operation is instantaneous, which is worse than a
|
||||
// visible gap.
|
||||
using Registry = telemetry::MetricsRegistry;
|
||||
if (auto const mean = Registry::scaledMean(self->fetchDurationUs, self->fetchCount))
|
||||
{
|
||||
observe(
|
||||
"write_mean_us",
|
||||
static_cast<std::int64_t>(self->storeDurationUs / self->storeCount));
|
||||
observe("read_mean_us", *mean);
|
||||
}
|
||||
if (self->fetchCount > 0 && self->fetchDurationUs > 0)
|
||||
if (auto const mean = Registry::scaledMean(self->storeDurationUs, self->storeCount))
|
||||
{
|
||||
observe(
|
||||
"read_mean_us",
|
||||
static_cast<std::int64_t>(self->fetchDurationUs / self->fetchCount));
|
||||
observe("write_mean_us", *mean);
|
||||
}
|
||||
},
|
||||
&state);
|
||||
@@ -2785,37 +2797,43 @@ TEST(MetricMacros, nodestore_latency_gauge_observes_exact_derived_means)
|
||||
|
||||
auto const busy = collectWith(totals);
|
||||
|
||||
// Exactly four series: two means and the two denominators that let a
|
||||
// dashboard recover interval latency from these cumulative totals.
|
||||
ASSERT_EQ(busy.at("nodestore_latency").size(), 4u);
|
||||
EXPECT_EQ(gaugeValue(busy, "nodestore_latency", attrs("metric", "write_mean_us")), 4000);
|
||||
EXPECT_EQ(gaugeValue(busy, "nodestore_latency", attrs("metric", "read_mean_us")), 1000);
|
||||
EXPECT_EQ(gaugeValue(busy, "nodestore_latency", attrs("metric", "write_count")), 500);
|
||||
EXPECT_EQ(gaugeValue(busy, "nodestore_latency", attrs("metric", "read_count")), 1000);
|
||||
// Exactly six series: the two means and the four cumulative totals that let
|
||||
// a dashboard recover interval latency from them.
|
||||
ASSERT_EQ(busy.at("nodestore_state").size(), 6u);
|
||||
EXPECT_EQ(gaugeValue(busy, "nodestore_state", attrs("metric", "write_mean_us")), 4000);
|
||||
EXPECT_EQ(gaugeValue(busy, "nodestore_state", attrs("metric", "read_mean_us")), 1000);
|
||||
EXPECT_EQ(gaugeValue(busy, "nodestore_state", attrs("metric", "node_writes")), 500);
|
||||
EXPECT_EQ(gaugeValue(busy, "nodestore_state", attrs("metric", "node_reads_total")), 1000);
|
||||
EXPECT_EQ(
|
||||
gaugeValue(busy, "nodestore_state", attrs("metric", "node_writes_duration_us")), 2'000'000);
|
||||
EXPECT_EQ(
|
||||
gaugeValue(busy, "nodestore_state", attrs("metric", "node_reads_duration_us")), 1'000'000);
|
||||
|
||||
// The write mean is the new signal, and it must be legible next to the
|
||||
// read mean rather than merely present.
|
||||
// The write mean is the signal this pair exists for, and it must be legible
|
||||
// next to the read mean rather than merely present.
|
||||
EXPECT_GT(
|
||||
gaugeValue(busy, "nodestore_latency", attrs("metric", "write_mean_us")),
|
||||
gaugeValue(busy, "nodestore_latency", attrs("metric", "read_mean_us")));
|
||||
gaugeValue(busy, "nodestore_state", attrs("metric", "write_mean_us")),
|
||||
gaugeValue(busy, "nodestore_state", attrs("metric", "read_mean_us")));
|
||||
|
||||
// Single fixed-cardinality label group, keyed exactly `metric`.
|
||||
auto const& firstKey = busy.at("nodestore_latency").begin()->first;
|
||||
auto const& firstKey = busy.at("nodestore_state").begin()->first;
|
||||
ASSERT_EQ(firstKey.size(), 1u);
|
||||
EXPECT_EQ(firstKey.begin()->first, "metric");
|
||||
|
||||
// EDGE CASE: a node that has never written. The zero denominator must skip
|
||||
// the mean rather than divide by zero, while the count is still reported --
|
||||
// the mean rather than divide by zero, while the total is still reported --
|
||||
// that is what distinguishes "nothing written yet" from "writes are
|
||||
// instant". The read side is unaffected and still reports both.
|
||||
totals = NodeStoreTotals{
|
||||
.storeCount = 0, .storeDurationUs = 0, .fetchCount = 4, .fetchDurationUs = 800};
|
||||
auto const idle = collectWith(totals);
|
||||
|
||||
EXPECT_EQ(idle.at("nodestore_latency").count(attrs("metric", "write_mean_us")), 0u);
|
||||
EXPECT_EQ(gaugeValue(idle, "nodestore_latency", attrs("metric", "write_count")), 0);
|
||||
EXPECT_EQ(gaugeValue(idle, "nodestore_latency", attrs("metric", "read_mean_us")), 200);
|
||||
EXPECT_EQ(gaugeValue(idle, "nodestore_latency", attrs("metric", "read_count")), 4);
|
||||
EXPECT_EQ(idle.at("nodestore_state").count(attrs("metric", "write_mean_us")), 0u);
|
||||
EXPECT_EQ(gaugeValue(idle, "nodestore_state", attrs("metric", "node_writes")), 0);
|
||||
EXPECT_EQ(gaugeValue(idle, "nodestore_state", attrs("metric", "read_mean_us")), 200);
|
||||
EXPECT_EQ(gaugeValue(idle, "nodestore_state", attrs("metric", "node_reads_total")), 4);
|
||||
// Five series, not six: every total plus the one mean that is derivable.
|
||||
EXPECT_EQ(idle.at("nodestore_state").size(), 5u);
|
||||
|
||||
// EDGE CASE: integer division truncates rather than rounding. 7 stores
|
||||
// over 100 us is 14.28 us, reported as 14 -- asserted so a future change
|
||||
@@ -2824,30 +2842,35 @@ TEST(MetricMacros, nodestore_latency_gauge_observes_exact_derived_means)
|
||||
.storeCount = 7, .storeDurationUs = 100, .fetchCount = 0, .fetchDurationUs = 0};
|
||||
auto const truncating = collectWith(totals);
|
||||
|
||||
EXPECT_EQ(gaugeValue(truncating, "nodestore_latency", attrs("metric", "write_mean_us")), 14);
|
||||
EXPECT_EQ(gaugeValue(truncating, "nodestore_state", attrs("metric", "write_mean_us")), 14);
|
||||
// The read side now has the zero denominator, so its mean drops out too.
|
||||
EXPECT_EQ(truncating.at("nodestore_latency").count(attrs("metric", "read_mean_us")), 0u);
|
||||
EXPECT_EQ(gaugeValue(truncating, "nodestore_latency", attrs("metric", "read_count")), 0);
|
||||
EXPECT_EQ(truncating.at("nodestore_state").count(attrs("metric", "read_mean_us")), 0u);
|
||||
EXPECT_EQ(gaugeValue(truncating, "nodestore_state", attrs("metric", "node_reads_total")), 0);
|
||||
|
||||
// EDGE CASE, and the one that matters most on a real node: stores were
|
||||
// counted but never TIMED. Database::store() is pure virtual and only the
|
||||
// paths calling recordStoreDuration() contribute a numerator, so a node
|
||||
// whose concrete store override does not time itself has a non-zero count
|
||||
// with a zero duration. The mean must be OMITTED, not reported as 0 --
|
||||
// a 0 would read as "writes are instantaneous", which is worse than a
|
||||
// visible gap. This assertion is the guard on that choice.
|
||||
// EDGE CASE: stores counted, but every one measured below a microsecond.
|
||||
// recordStoreDuration() only adds when the cast to microseconds is > 0, so
|
||||
// sub-microsecond stores leave the duration total at 0 while the count
|
||||
// climbs. scaledMean divides on the COUNT alone, so it reports a genuine
|
||||
// mean of 0 here rather than omitting the series. That is the correct
|
||||
// reading: the stores really did complete
|
||||
// in under a microsecond each, and the total beside it proves they
|
||||
// happened. Absence is reserved for "no samples at all".
|
||||
totals = NodeStoreTotals{
|
||||
.storeCount = 9000, .storeDurationUs = 0, .fetchCount = 10, .fetchDurationUs = 50};
|
||||
auto const untimed = collectWith(totals);
|
||||
auto const subMicrosecond = collectWith(totals);
|
||||
|
||||
EXPECT_EQ(untimed.at("nodestore_latency").count(attrs("metric", "write_mean_us")), 0u);
|
||||
// The count is still published, so the gap is visible rather than silent:
|
||||
// a panel shows real write throughput with no latency line beside it.
|
||||
EXPECT_EQ(gaugeValue(untimed, "nodestore_latency", attrs("metric", "write_count")), 9000);
|
||||
// The read side is independent and unaffected by the write-side gap.
|
||||
EXPECT_EQ(gaugeValue(untimed, "nodestore_latency", attrs("metric", "read_mean_us")), 5);
|
||||
// Exactly three series: both counts plus the one mean that is derivable.
|
||||
EXPECT_EQ(untimed.at("nodestore_latency").size(), 3u);
|
||||
EXPECT_EQ(subMicrosecond.at("nodestore_state").count(attrs("metric", "write_mean_us")), 1u);
|
||||
EXPECT_EQ(gaugeValue(subMicrosecond, "nodestore_state", attrs("metric", "write_mean_us")), 0);
|
||||
// The count is published beside it, so the reading is interpretable: real
|
||||
// write throughput with a sub-microsecond per-operation cost.
|
||||
EXPECT_EQ(gaugeValue(subMicrosecond, "nodestore_state", attrs("metric", "node_writes")), 9000);
|
||||
EXPECT_EQ(
|
||||
gaugeValue(subMicrosecond, "nodestore_state", attrs("metric", "node_writes_duration_us")),
|
||||
0);
|
||||
// The read side is independent and unaffected by the write-side reading.
|
||||
EXPECT_EQ(gaugeValue(subMicrosecond, "nodestore_state", attrs("metric", "read_mean_us")), 5);
|
||||
// All six series present: both means are derivable here.
|
||||
EXPECT_EQ(subMicrosecond.at("nodestore_state").size(), 6u);
|
||||
}
|
||||
|
||||
// consensus_round_duration_ms: exact recorded values, not "greater than zero".
|
||||
@@ -3123,7 +3146,7 @@ TEST(MetricMacros, sweep_malloc_trim_skips_reclaim_when_rss_grew)
|
||||
// rotation_state is polled from the node store, so the production callback in
|
||||
// MetricsRegistry::registerRotationStateGauge cannot be linked into this
|
||||
// binary. The derivation it performs is asserted here against the same two
|
||||
// inputs, mirroring how nodestore_latency is tested above.
|
||||
// inputs, mirroring how nodestore_state is tested above.
|
||||
TEST(MetricMacros, rotation_state_gauge_observes_in_flight_window_and_copy_forward_total)
|
||||
{
|
||||
// Each scenario gets a FRESH provider: the reader is cumulative, so a
|
||||
|
||||
@@ -40,7 +40,7 @@
|
||||
* `clock_close_offset_seconds`, `sync_state`,
|
||||
* `server_stall_events_total`, `sync_acquire`, `shamap_cache_hit_rate`,
|
||||
* `jobq_saturation`, `peer_ledger_supply`,
|
||||
* `peerfinder_slot_census`, `amendment_block`, `nodestore_latency`):
|
||||
* `peerfinder_slot_census`, `amendment_block`, `nodestore_state`):
|
||||
* this file CANNOT assert an observed gauge
|
||||
* value, because on this build the gauges do not exist -- their registration
|
||||
* methods and the OTel instrument members are inside
|
||||
@@ -854,7 +854,7 @@ TEST_F(MetricsRegistryTest, disabled_lifecycle_never_consults_gauge_services)
|
||||
// registerSyncAcquireGauge() / registerCacheHitRateDetailGauge() /
|
||||
// registerJobQueueBacklogGauge() / registerJobQueueSaturationGauge() /
|
||||
// registerPeerLedgerSupplyGauge() / registerSlotCensusGauge() /
|
||||
// registerAmendmentBlockGauge() / registerNodeStoreLatencyGauge() --
|
||||
// registerAmendmentBlockGauge() / registerNodeStoreGauge() --
|
||||
// would run.
|
||||
EXPECT_NO_THROW(registry.start("http://localhost:4318/v1/metrics"));
|
||||
|
||||
@@ -900,12 +900,11 @@ TEST_F(MetricsRegistryTest, disabled_lifecycle_never_consults_gauge_services)
|
||||
// table's mutex. Not consulted above, so the countdown never ran. (Its
|
||||
// `warned` half reads NetworkOPs, already covered by the getOPs() check.)
|
||||
EXPECT_THROW(mockApp_.getAmendmentTable(), std::logic_error);
|
||||
// The service the WP-A6 nodestore latency gauge reads: nodestore_latency
|
||||
// polls getStoreDurationUs()/getStoreCount() and
|
||||
// getFetchDurationUs()/getFetchTotalCount() on the node-store Database.
|
||||
// Not consulted above, so the latency gauge never read those atomics on a
|
||||
// telemetry-off build. (The existing nodestore_state gauge reads the same
|
||||
// service, so this single throw covers both.)
|
||||
// The service the nodestore gauge reads: nodestore_state polls
|
||||
// getStoreDurationUs()/getStoreCount() and
|
||||
// getFetchDurationUs()/getFetchTotalCount() on the node-store Database,
|
||||
// alongside its I/O totals and write-queue detail. Not consulted above,
|
||||
// so the gauge never read those atomics on a telemetry-off build.
|
||||
EXPECT_THROW(mockApp_.getNodeStore(), std::logic_error);
|
||||
}
|
||||
|
||||
@@ -929,7 +928,7 @@ TEST_F(MetricsRegistryTest, enabled_flag_alone_registers_no_gauges_when_compiled
|
||||
// registerSyncAcquireGauge()/registerCacheHitRateDetailGauge()/
|
||||
// registerJobQueueBacklogGauge()/registerJobQueueSaturationGauge()/
|
||||
// registerPeerLedgerSupplyGauge()/registerSlotCensusGauge()/
|
||||
// registerAmendmentBlockGauge()/registerNodeStoreLatencyGauge(), a
|
||||
// registerAmendmentBlockGauge()/registerNodeStoreGauge(), a
|
||||
// callback would reach getValidators()/getTimeKeeper()/getOPs()/
|
||||
// getLoadManager()/getInboundLedgers()/getNodeFamily()/getJobQueue()/
|
||||
// getOverlay()/getAmendmentTable()/getNodeStore() and
|
||||
|
||||
@@ -256,10 +256,6 @@ inline constexpr char peerfinderSlotCensus[] = "peerfinder_slot_census";
|
||||
* Amendment-block warning and the countdown to this node ceasing to validate.
|
||||
*/
|
||||
inline constexpr char amendmentBlock[] = "amendment_block";
|
||||
/**
|
||||
* NodeStore mean store/fetch latency, with the operation counts.
|
||||
*/
|
||||
inline constexpr char nodestoreLatency[] = "nodestore_latency";
|
||||
|
||||
// ===== Consensus =============================================================
|
||||
|
||||
@@ -658,23 +654,6 @@ inline constexpr char inFlight[] = "in_flight";
|
||||
inline constexpr char copyForward[] = "copy_forward";
|
||||
} // namespace rotation_state
|
||||
|
||||
/**
|
||||
* `nodestore_latency` sub-metrics: mean latency per direction, with counts.
|
||||
*/
|
||||
namespace nodestore_latency {
|
||||
inline constexpr char writeCount[] = "write_count";
|
||||
inline constexpr char readCount[] = "read_count";
|
||||
inline constexpr char writeMeanUs[] = "write_mean_us";
|
||||
inline constexpr char readMeanUs[] = "read_mean_us";
|
||||
// Cumulative microsecond totals. The means above are convenient to read at a
|
||||
// glance but cannot be rated: they are already a ratio, and a gauge of a ratio
|
||||
// has no meaningful derivative. Dividing the rate of these totals by the rate of
|
||||
// the matching count yields the latency over the panel's own window, which is
|
||||
// what a dashboard actually wants.
|
||||
inline constexpr char writeDurationUs[] = "write_duration_us";
|
||||
inline constexpr char readDurationUs[] = "read_duration_us";
|
||||
} // namespace nodestore_latency
|
||||
|
||||
/**
|
||||
* `ledger_quorum_publish` sub-metrics: the gate, and how late publish is.
|
||||
*/
|
||||
|
||||
@@ -726,7 +726,6 @@ MetricsRegistry::registerAsyncGauges()
|
||||
registerPeerLedgerSupplyGauge();
|
||||
registerSlotCensusGauge();
|
||||
registerAmendmentBlockGauge();
|
||||
registerNodeStoreLatencyGauge();
|
||||
registerLedgerQuorumPublishGauge();
|
||||
}
|
||||
|
||||
@@ -2313,95 +2312,6 @@ MetricsRegistry::registerAmendmentBlockGauge()
|
||||
this);
|
||||
}
|
||||
|
||||
void
|
||||
MetricsRegistry::registerNodeStoreLatencyGauge()
|
||||
{
|
||||
// --- Sync diagnostics: is the node store slow, and on which side? ---
|
||||
// The write mean is the new signal. storeDurationUs_ was declared and
|
||||
// never written, so no write latency existed anywhere; only the read side
|
||||
// had a duration total. A node with a large existing DB back-fills slower
|
||||
// than a fresh one, and back-fill is write-bound, so the read-side
|
||||
// metrics cannot show it. Exporting both means from one reading also makes
|
||||
// the two sides directly comparable.
|
||||
//
|
||||
// Gauge rather than histogram: a histogram would cost one Record() per
|
||||
// node object on the store/fetch path, which runs thousands of times per
|
||||
// ledger write. This reads four atomics per ~10 s tick instead. The
|
||||
// trade-off is that percentiles are unavailable -- see the header comment.
|
||||
nodeStoreLatencyGauge_ = meter_->CreateInt64ObservableGauge(
|
||||
metric::nodestoreLatency,
|
||||
"NodeStore mean store/fetch latency in microseconds, with counts");
|
||||
nodeStoreLatencyGauge_->AddCallback(
|
||||
[](opentelemetry::metrics::ObserverResult result, void* state) {
|
||||
auto* self = static_cast<MetricsRegistry*>(state);
|
||||
if (self->callbacksDetached_.load(std::memory_order_acquire))
|
||||
return;
|
||||
auto& app = self->app_;
|
||||
|
||||
try
|
||||
{
|
||||
auto observe = [&](char const* field, int64_t value) {
|
||||
opentelemetry::nostd::get<opentelemetry::nostd::shared_ptr<
|
||||
opentelemetry::metrics::ObserverResultT<int64_t>>>(result)
|
||||
->Observe(value, {{"metric", field}});
|
||||
};
|
||||
|
||||
auto& db = app.getNodeStore();
|
||||
|
||||
// One reading of each pair, so a mean and its own denominator
|
||||
// describe the same instant.
|
||||
auto const storeCount = db.getStoreCount();
|
||||
auto const storeDurationUs = db.getStoreDurationUs();
|
||||
auto const fetchCount = db.getFetchTotalCount();
|
||||
auto const fetchDurationUs = db.getFetchDurationUs();
|
||||
|
||||
// Counts are always observed, including zero: that is what
|
||||
// separates "nothing written yet" from "writes are instant".
|
||||
observe(lval::nodestore_latency::writeCount, static_cast<int64_t>(storeCount));
|
||||
observe(lval::nodestore_latency::readCount, static_cast<int64_t>(fetchCount));
|
||||
|
||||
// A mean needs a non-zero denominator, and it needs a
|
||||
// numerator that was actually measured. Both are required, and
|
||||
// the series is omitted rather than observed as 0 when either
|
||||
// is missing: a reported 0 us would claim writes are
|
||||
// instantaneous, which is worse than no reading at all.
|
||||
//
|
||||
// The numerator guard covers the pre-first-write window only.
|
||||
// Both concrete databases time their backend write, so the
|
||||
// total advances on any ordinary node; before the first write
|
||||
// it is still 0, and omitting the mean then is better than
|
||||
// publishing a false "writes take 0 us".
|
||||
// The cumulative totals are observed unconditionally, so a
|
||||
// panel can divide rate(duration) by rate(count) and read the
|
||||
// latency over its own window rather than a since-boot average
|
||||
// that flattens as uptime grows.
|
||||
observe(
|
||||
lval::nodestore_latency::writeDurationUs,
|
||||
static_cast<int64_t>(storeDurationUs));
|
||||
observe(
|
||||
lval::nodestore_latency::readDurationUs, static_cast<int64_t>(fetchDurationUs));
|
||||
|
||||
if (storeCount > 0 && storeDurationUs > 0)
|
||||
{
|
||||
observe(
|
||||
lval::nodestore_latency::writeMeanUs,
|
||||
static_cast<int64_t>(storeDurationUs / storeCount));
|
||||
}
|
||||
if (fetchCount > 0 && fetchDurationUs > 0)
|
||||
{
|
||||
observe(
|
||||
lval::nodestore_latency::readMeanUs,
|
||||
static_cast<int64_t>(fetchDurationUs / fetchCount));
|
||||
}
|
||||
}
|
||||
catch (...) // NOLINT(bugprone-empty-catch)
|
||||
{
|
||||
// Silently skip if services are not yet ready.
|
||||
}
|
||||
},
|
||||
this);
|
||||
}
|
||||
|
||||
void
|
||||
MetricsRegistry::registerLedgerQuorumPublishGauge()
|
||||
{
|
||||
|
||||
@@ -69,7 +69,6 @@
|
||||
* +-- Peer ledger supply (how many peers can serve the needed sequence)
|
||||
* +-- PeerFinder slot census (slots, attempts, fixed peers, address caches)
|
||||
* +-- Amendment block (warned flag + seconds until the node stops validating)
|
||||
* +-- NodeStore latency (mean us per store and per fetch, with counts)
|
||||
* +-- Ledger quorum + publish (validation tally vs quorum target,
|
||||
* | time to first validated, publish lag)
|
||||
* +-- jq_trans_overflow_total (observed from Overlay)
|
||||
@@ -801,13 +800,6 @@ private:
|
||||
*/
|
||||
opentelemetry::nostd::shared_ptr<opentelemetry::metrics::ObservableInstrument>
|
||||
amendmentBlockGauge_;
|
||||
/**
|
||||
* Observable gauge for node-store read and write latency, as mean
|
||||
* microseconds per operation derived from the cumulative duration and
|
||||
* operation-count totals the node store already keeps.
|
||||
*/
|
||||
opentelemetry::nostd::shared_ptr<opentelemetry::metrics::ObservableInstrument>
|
||||
nodeStoreLatencyGauge_;
|
||||
/**
|
||||
* Observable gauge for the pre-accept quorum gate and the publish lag:
|
||||
* the trusted-validation tally against the quorum it must reach, the
|
||||
@@ -983,8 +975,33 @@ private:
|
||||
/**
|
||||
* Observe the NodeStore I/O totals and the means derived from them.
|
||||
*
|
||||
* Publishes the four cumulative totals (`node_reads_total`,
|
||||
* `node_writes`, `node_reads_duration_us`, `node_writes_duration_us`)
|
||||
* unconditionally, plus `read_mean_us` and `write_mean_us` derived from
|
||||
* them via scaledMean(). `write_mean_us` is the signal for the "a node
|
||||
* with a large existing database syncs slower than a fresh one" symptom:
|
||||
* back-fill is write-bound, so no read-side reading can show it. All
|
||||
* three concrete store paths time themselves through
|
||||
* Database::recordStoreDuration(), so the write mean is live on an
|
||||
* ordinary node.
|
||||
*
|
||||
* Gauge rather than histogram, deliberately. A histogram would give true
|
||||
* percentiles, but it costs one Record() per node object on the
|
||||
* store/fetch path, and one ledger write walks thousands of SHAMap
|
||||
* nodes. This reads the existing atomics once per ~10 s tick and adds
|
||||
* nothing to the hot path. Consequence, stated plainly: p99 is NOT
|
||||
* obtainable from this signal. A histogram added later would also need an
|
||||
* explicit-bucket View registered via addMicrosecondHistogramView(),
|
||||
* because the SDK's default buckets top out at 10,000.
|
||||
*
|
||||
* @param db NodeStore to read the counters from.
|
||||
* @param observe Sink for one `metric`-labelled value.
|
||||
*
|
||||
* @note The totals are monotonic and never reset, so a panel wanting
|
||||
* current rather than since-boot latency divides the two rates. That is
|
||||
* why the counts and duration totals are exported beside the means.
|
||||
* @note A mean is omitted when its count is 0, so a dashboard shows a gap
|
||||
* rather than a plausible-looking 0 us.
|
||||
*/
|
||||
static void
|
||||
observeNodeStoreTotals(node_store::Database& db, ObserveFn const& observe);
|
||||
@@ -1343,78 +1360,6 @@ private:
|
||||
void
|
||||
registerAmendmentBlockGauge(); // sync diagnostics: amendment countdown
|
||||
|
||||
/**
|
||||
* Register the `nodestore_latency` gauge.
|
||||
*
|
||||
* Four series under the `metric` attribute, from the node store's own
|
||||
* cumulative totals:
|
||||
*
|
||||
* `write_mean_us` — **the signal this gauge exists for.** Mean
|
||||
* microseconds per store, `getStoreDurationUs() / getStoreCount()`.
|
||||
* No write-side latency existed anywhere before this:
|
||||
* `storeDurationUs_` was declared in Database.h and never written, and
|
||||
* there was no accessor for it. This is the fingerprint of the
|
||||
* "a node with a large existing DB syncs slower than a fresh one"
|
||||
* symptom, which is write-bound and therefore invisible in every
|
||||
* read-side metric.
|
||||
* `read_mean_us` — mean microseconds per fetch,
|
||||
* `getFetchDurationUs() / getFetchTotalCount()`, so the write mean has
|
||||
* a same-instant, same-derivation counterpart to be compared against.
|
||||
* `write_count` / `read_count` — the denominators, exported so a
|
||||
* dashboard can recover *interval* latency as
|
||||
* `rate(duration) / rate(count)`. Without them the means above are
|
||||
* since-boot averages, which on a long-running node move so slowly
|
||||
* that a current stall is invisible.
|
||||
*
|
||||
* Gauge, not a histogram — deliberate. A histogram would give true
|
||||
* percentiles, which a mean cannot, but it costs one `Record()` per
|
||||
* operation on a path that runs per node object: a single ledger write
|
||||
* walks thousands of SHAMap nodes, and fetches are more frequent still.
|
||||
* That is a per-object synchronous instrument call plus bucket search on
|
||||
* the hot store/fetch path. This gauge instead reads four already-existing
|
||||
* atomics once per ~10 s collection tick, adding nothing whatsoever to the
|
||||
* hot path — the store side pays only the one clock-sample pair per store
|
||||
* that the read side has always paid per fetch. For the question this work
|
||||
* package answers ("is the write path slow, and slower than the read
|
||||
* path?") a rate-derived mean is sufficient, and a tail latency that
|
||||
* matters will move the mean. Consequence, stated plainly: p99 is NOT
|
||||
* obtainable from this signal. Adding a histogram later would also require
|
||||
* an explicit-bucket View registered in initExporterAndProvider() via
|
||||
* addMicrosecondHistogramView(), because the SDK's default buckets top out
|
||||
* at 10,000 and every microsecond duration above 10 ms would saturate.
|
||||
*
|
||||
* Distinct from `nodestore_state`, which already carries the raw
|
||||
* cumulative `node_reads_duration_us`, `node_reads_total` and
|
||||
* `node_writes` fields, and from the Ledger Data Sync dashboard's "NuDB
|
||||
* Read Latency" panel that divides the first two in PromQL. Neither has
|
||||
* any write-duration input to divide — that quantity did not exist. This
|
||||
* gauge adds the missing write numerator and publishes both means from one
|
||||
* reading so the two sides are directly comparable.
|
||||
*
|
||||
* @note Pulled on the OTel reader thread (~10 s tick). Four relaxed atomic
|
||||
* loads and two integer divisions; no lock, no allocation, no hot-path
|
||||
* cost.
|
||||
* @note A mean is observed only when both its count and its duration total
|
||||
* are non-zero; otherwise the series is omitted rather than reported as 0,
|
||||
* because a 0 would claim the operation is instantaneous. The counts are
|
||||
* always observed, so `write_count` still distinguishes "nothing written
|
||||
* yet" from "writes are instant".
|
||||
* @warning `write_mean_us` is currently produced only by store paths that
|
||||
* call `Database::recordStoreDuration()`, which today is
|
||||
* `Database::importInternal` (the `[import_db]` admin path). `store()` is
|
||||
* pure virtual, and neither `DatabaseNodeImp::store` nor
|
||||
* `DatabaseRotatingImp::store` calls it yet, so on an ordinary node
|
||||
* `write_count` climbs while `write_mean_us` is absent. That is a
|
||||
* deliberate, visible gap: closing it means adding one clock-sample pair to
|
||||
* those two concrete store overrides, which live outside this work
|
||||
* package's file scope.
|
||||
* @note Both totals are monotonic and never reset. A panel wanting current
|
||||
* rather than since-boot latency must divide the two rates, which is why
|
||||
* the counts are exported alongside the means.
|
||||
*/
|
||||
void
|
||||
registerNodeStoreLatencyGauge(); // sync diagnostics: store/fetch latency
|
||||
|
||||
/**
|
||||
* Register the `ledger_quorum_publish` gauge.
|
||||
*
|
||||
|
||||
Reference in New Issue
Block a user