These changes were developed on the phase-10 branch but belong to content this
branch and its upstreams introduced. Carrying them on phase-10 made its PR diff
report churn in files phase-10 does not own, and left each PR claiming a scope
that did not match its contents.
Moved here from phase-10 (identical content, no functional change):
- Dashboards: all 14 existing boards plus the new log-derived-insights board.
- Docs: telemetry-runbook.md (minus the workload/benchmark sections, which
describe phase-10 tooling) and the new telemetry-glossary.md.
- Grafana Cloud + Alloy export path: collector config, compose override, the
two .env examples and alloy/config.alloy.
- Local stack: otel-collector-config.yaml gains sub-millisecond and
second-scale spanmetrics buckets, pins unit=ms, and promotes
close_time_correct; integration-test.sh and TESTING.md follow.
- Node configs: exported_instance -> service_instance_id in comments; the
mainnet sample now logs at warning to bound log volume.
- Metrics code: Telemetry.cpp builds the metrics pipeline in the constructor
via initMetrics() so the global MeterProvider is published before any
subsystem creates a beast::insight instrument, and the histogram view keeps
each instrument's own name instead of collapsing them under one series.
MetricsRegistry gains a last_close_time gauge and skips negative job-queue
durations. OTelCollector drops an unused accessor.
- Naming CI: xrpl_work_item joins EXTERNAL_INFRA_LABELS and Rule E accepts the
dotted perf-iac resource-attribute form. This must travel with the
dashboards and runbook that reference those labels, or the rules fail.
- Doxygen input glob no longer recurses dot-directories.
Sections describing phase-10 tooling stay on phase-10 and keep their
"Future Enhancement" / "Planned, not yet implemented" markers here; phase-10
removes those markers when it lands the tooling.
Resolves the telemetry-startup conflict between the two branches. Both
sides move the telemetry start earlier in setup(); they disagree only on
how far the pipeline had been split at that point.
phase-1b (arriving) moved nodeIdentity_, setServiceInstanceId() and the
telemetry start up to just after the wallet DB is proven usable. phase-9
had split the metrics pipeline in two and left its copy of that block at
the old, later position.
Kept both intentions: the block stays at phase-1b's early position, and
metricsRegistry_ construction moves up with it so it precedes
startTelemetry() -- the metrics half is guarded on the registry existing,
so leaving the construction behind would have started tracing while
silently skipping metrics. phase-9's later copy is dropped as the stale
duplicate. The two-phase split is preserved: startTelemetryGauges() still
runs after overlay_ is constructed, because the observable callbacks read
it and getOverlay() asserts.
Net effect is that the metrics provider now starts earlier than on either
branch, and still before beginConsensus() emits the first spans and the
only operating-mode transition.
MetricsRegistry::start() fused three steps with different prerequisites:
the exporter/provider and the synchronous instruments need only config
strings, while the observable gauges read live Application services. The
whole pipeline therefore waited on the latest prerequisite and ran near
the end of setup() -- after beginConsensus() had already recorded the
process's only operating-mode transition. state_changes_total was
emitted into a pipeline that did not exist yet, so the series never
appeared at all.
Split the two halves. start() keeps the provider and the synchronous
instruments and now runs as soon as the registry is constructed; the new
startAsyncGauges() registers the observable callbacks and runs once
overlay_ exists, still before the first consensus round. Application
gains a matching startTelemetryGauges() so each phase has its own call
site and its own precondition.
Move the jq_trans_overflow_total observable out of initSyncInstruments()
into the gauge phase. Its callback reads getOverlay(), which asserts
overlay_ is non-null, so creating it in the early phase armed the reader
thread against a half-built application -- an assert is not caught by
the callback's catch-all. The instrument is an observable counter rather
than a gauge, which is how it was mistaken for a push-only instrument.
Both start log lines are kept, one per phase, because that timeline is
what made the original ordering bug diagnosable.
Comments and preconditions are corrected to state the rule rather than
the current arrangement: start() may only create instruments whose
values are pushed, and any observable whose callback reads a service
belongs in the gauge phase. The gauge precondition now lists the
services the callbacks actually read.
telemetry_->start() ran at the end of ApplicationImp::start(), after
overlay_->start(). Spans are emitted well before that, during setup():
beginConsensus() runs the first consensus round there. SpanGuard drops a
span whenever the global Telemetry instance is not yet live, so that
round's spans were never recorded.
Move the start into setup(), behind a new startTelemetry() seam, right
after the node identity is known. getNodeIdentity() needs only the
cmdline, the config, or the wallet DB, and initRelationalDatabase()
has already created the latter -- the adjacent peerReservations_ load
proves it is usable -- so the identity block moves up with it.
The new position is bounded on both sides: after initRelationalDatabase()
because the identity needs the wallet DB and a DB failure aborts setup(),
and before beginConsensus() because that emits the first spans.
Six related defects in the RPC/gRPC span surface, all cases where a failure
was recorded as success or an attribute was missing on an error path.
GRPCServer: the non-exception branch set the span Ok unconditionally, then
sent a possibly-failed grpc::Status. The handler can return a non-OK status
without throwing, so every failed call traced as successful. Status now
follows result.second, with the error message as the span description.
ServerHandler: eight per-item error branches appended an error reply without
recording that the request failed. Batch responses and ripplerpc < 3.0 always
carry HTTP 200, so those failures were invisible and an entirely failed batch
ended its span as successful. Added an appendItemError() helper next to the
existing httpReplyError() lambda and routed all eight sites through it, so the
flag cannot be forgotten at a new call site.
ServerHandler: the early-return validation paths set the span error but not the
rpc_status attribute. Added it to httpReplyError() so every such path gets it.
RPCHandler: the fillHandler error path set only command and rpc_status, while
callMethod sets command, version and rpc_role. Error spans were therefore not
filterable by API version or role. The error path now mirrors that set.
RPCHandler: resolveCommandSpanName() checked only that command/method were
present, not that they agreed, while fillHandler rejects a mismatch as
rpcUNKNOWN_COMMAND. A request supplying both with different values was labelled
with one of the two names, misattributing the error to a command that never
dispatched. It now mirrors fillHandler's rule and collapses to "unknown".
ServerHandler: processRequest returned bool solely so the caller could set its
span status. Telemetry should read state, not shape the signature of the code it
observes, so the signature returns to void and rpc.process sets its own status
from spanHadError. The enclosing rpc.http_request span now leaves status unset:
the OTel spec has instrumentation leave status unset unless the operation itself
errored, and reserves Ok for an operator asserting verified success.
The counters that attribute deferrals and timeouts to ledger acquisition
compared a string literal in TimeoutCounter against a separate literal in
InboundLedger. Renaming the job would have silently sent both metrics to
zero: no build error, no failing test, and documentation that quietly
became wrong. Both now use one shared constant.
Both counters are recorded in TimeoutCounter, a base shared by five
subclasses with different job limits, so they pooled every lane
together. The documented fingerprint for a stalled acquisition is
deferrals rising while timeouts stay flat -- but a saturated replay lane
reproduces that shape while ledger acquisition is healthy, and the two
counters being compared were not drawn from the same population.
Adds ledger-acquisition-scoped counts alongside the totals, discriminated
by the job name already held at both call sites, so no new state and no
signature change. The all-lane counters stay for callers that want them.
Their exporters went in with the preceding commit, which shared a file.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
recordCompletion() was reached only from done(), but init() can satisfy an
acquisition entirely from the local store and return without ever calling
done(). Those completions went uncounted, so acquire_completions read zero
for a whole class of outcome. On a live clean-database sync it read 0 for
510 seconds while the node reached full, which was misread as the node
completing nothing.
Counted in init() rather than by calling done(), because done() drives the
state machine: it stores the ledger, dispatches AcqDone, updates the
fetch-rate average, and sets signaled_, which would disarm a later genuine
done(). A counter must not change behaviour. A completionCounted_ latch,
separate from signaled_, makes the count idempotent across the two
independent exits so a completion is counted exactly once however it was
reached.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Drops nodestore_read_us and everything added to reach it. read_mean_us already
carries microsecond precision and separated the two sync failure modes cleanly
in live testing -- 8.8 us on a clean store against a 223 us cold-store peak --
so the distribution added no signal that changed a diagnosis.
The cost of getting it was disproportionate. NodeStoreScheduler had no path to
the metrics registry, so its production constructor grew a ServiceRegistry
parameter: a metric addition changing a production signature. That in turn
forced an edit to a pre-existing test, src/test/app/SHAMapStore_test.cpp, whose
only stake in this is that it constructs a scheduler. Worse, the scheduler is
built in Application's member initializer list, long before metricsRegistry_
exists, so the registry could not be captured once and had to be re-resolved on
every fetch -- a lookup on a path that runs millions of times per sync.
The constructor returns to taking JobQueue& alone and SHAMapStore_test.cpp
returns to the single-argument call, leaving that file differing from its
pre-change form only by the NodeStore:: to node_store:: rename it picked up from
develop.
FetchReport::elapsed stays microseconds and onFetch keeps its explicit
duration_cast to milliseconds for addLoadEvents, which takes milliseconds. That
widening was a separate fix and is what makes read latency measurable at all.
kSubMillisecondBoundaries loses its only consumer and regains [[maybe_unused]],
which is the state the commit that introduced it left it in; without the
attribute an unused constant is an error under wextra with werr.
Also removes the ledger-data-sync panel that charted the histogram and the
fetch_type and found template variables, which filtered on labels no metric
emits any more, plus the runbook and reference-doc sections and the two
instrument and view counts that named it.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
kSubMillisecondBoundaries existed but nothing used it, so per-fetch read
latency never reached Grafana -- only the coarse read_mean_us gauge did,
which cannot separate "every read took 9us" from "most took 2 and a few
took 900".
Add a nodestore_read_us histogram, register its view against the sub-
millisecond ladder rather than kMicrosecondBoundaries (whose first edge
is 100us, above the entire range a warm read occupies), and record into
it from NodeStoreScheduler::onFetch using FetchReport::elapsed, which a
previous change widened to microseconds for exactly this purpose.
The name and its labels live in a new include/xrpl/telemetry header
because the view registration (xrpld.telemetry) and the record site
(xrpld.app) sit in different levelization modules; a copy-pasted literal
would let them drift and silently drop the bucket override. Same reason
and same placement as GetObjectMetricNames.h. No new levelization edge:
xrpld.app > xrpl.telemetry already exists.
NodeStoreScheduler had no registry access, so it now takes a
ServiceRegistry and resolves the registry per call. It is constructed in
Application's initializer list, long before metricsRegistry_ is assigned
in setup() and started in startTelemetry(), so capturing a pointer at
construction would capture nullptr forever; the metric macros null-check
the registry, the meter and the instrument, so early fetches are simply
not recorded.
Labels are fetch_type and found, both already carried on the report --
4 series, fixed at compile time. A slow async read delays prefetch while
a slow sync read blocks a caller, and a miss can cost a read of every
backend, so neither dimension can be collapsed.
Negative elapsed times are skipped: the SDK rejects them and logs a
warning on every call, which on a per-fetch path is a log flood. Zero is
still recorded, since a page-cache-served read genuinely rounds to it.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
FetchReport::elapsed was milliseconds, so every nodestore read rounded to
zero: a warm store answers in single-digit microseconds and a cold one in
low hundreds, and both became 0 ms. That difference is the whole signal
separating a cold-read stall from a healthy node, and it was being
discarded at the type. Database::fetchNodeObject now measures once and
uses that one value for both the cumulative counter and the report, so
the two can never disagree. The job-queue call still takes milliseconds
and now casts explicitly.
BatchWriteReport::elapsed stays milliseconds and is documented as such:
a batch write covers many objects and reaches the disk, so it belongs in
that range.
Also adds a sub-millisecond histogram ladder, because the existing bucket
edges start at 100 microseconds and put the entire warm range in bucket
0. It is not wired to a view yet: no sub-millisecond instrument exists to
name, so the edges wait for the instrument that records read latency.
The new test captures what the nodestore reports and asserts the reported
total equals the internal microsecond accumulator exactly, plus that at
least one report is not a whole number of milliseconds -- which a
millisecond-typed field can never satisfy on any hardware.
Both files use telemetry::consensus::span::* but reached the declarations
only transitively, which misc-include-cleaner rejects. Add the direct
include now that the header lives under xrpl/consensus/.
A saturated ledgerData lane makes TimeoutCounter re-arm its timer
without running the timer body, so timeouts_ never advances and the
six-timeout give-up can never fire. Acquisitions then neither finish
nor fail until the one-minute sweep destroys their partial maps, and
the work restarts. Every step of that chain was debug-log-only, so a
node at warning level could not be diagnosed after the fact.
The counters are separate on purpose: deferrals rising while timeouts
stay flat is the signature, and no single counter shows it.
Completions are recorded in done() rather than at the "Done: complete"
log line, because that line also fires for failures and misses the
checkLocal and receiveNode paths; done() is the one funnel every
outcome passes through and its signaled_ guard makes it idempotent.
AcquireStats is only forward-declared in ServiceRegistry so libxrpl
still includes nothing from xrpld. The src/ include path for the test
binary moves out of the telemetry guard, since a header-only type
under src/xrpld/ is testable in every build.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The consensus headers moved into the isolated xrpl/consensus module and
took a dependency on xrpl/telemetry for the tracing span constants, but
two things were left behind:
- Four includes still pointed at the old src/xrpld/consensus/ location,
which no longer exists, so the build failed with
"fatal error: 'xrpld/consensus/ConsensusParms.h' file not found".
- xrpl.libxrpl.consensus never linked xrpl.libxrpl.telemetry. add_module
isolates each module's headers, so xrpl/telemetry/SpanNames.h was not
on the include path even once the include was repointed.
Repoint the stale includes at xrpl/consensus/, and declare the telemetry
module before consensus so consensus can link it. Regenerate ordering.txt
for the resulting edge.
