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.
clang-tidy had been skipped on this branch while CMake configure was
failing, so these findings in makeStageSpan surfaced only now:
- brace the three single-statement if bodies (readability-braces-around-statements)
- compare the pointer parameter explicitly against nullptr
(readability-implicit-bool-conversion)
- include xrpl/protocol/Protocol.h for LedgerIndex (misc-include-cleaner)
NuDB serializes every insert behind one global mutex held for the whole
call, so a caller cannot see how long it waited. Record instead the
writer depth joined at and the wall time spent; with mean depth L and
mean insert time W, Little's Law gives service time W/L and queueing
W - W/L. That distinguishes a serialized write path from a saturated
disk: measured on a dev box the device sat 89 percent idle while
throughput stayed flat at 42k inserts per second.
The accounting runs from a ScopeExit guard because the insert can
allocate and therefore throw; leaking the depth would strand the gauge
above zero for the life of the process.
getWriteLoad also stops returning a hardcoded zero. It now reports
writer depth, which is bounded by the writing-thread count and so stays
far below the kMaxWriteLoadAcquire cutoff that gates history
acquisition, where returning bytes or microseconds would have silently
suppressed it.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
fetchDurationUs_ had no getter, so telemetry reached it by building a JSON
object, stringifying a uint64 and parsing it back with stoll on every
collect tick. storeDurationUs_ was declared and never written or read at
all, along with the jss::node_writes_duration_us key.
Both now have accessors, both production store paths time their backend
call, and the registry reads them without the round trip. get_counts also
reports the write duration, so the RPC and the metric agree. Mean read
latency is the signal that separates a cold store from a warm one: warm
reads are single-digit microseconds, cold ones low hundreds.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Resolved five files. In each case both sides had content worth keeping,
so nothing was taken wholesale:
- MetricsRegistry.cpp: kept the incoming `handler` label on the job
instruments and re-applied this branch's `queuedDurUs >= 0` guard,
which the incoming side does not have.
- telemetry-runbook.md: took the incoming gauge table, which adds the
three per-job-type rows, and re-applied this branch's corrected
`jobq_job_count` name.
- 09-data-collection-reference.md: kept this branch's validation
inventory (newer counts, extra Config File column) and inserted the
incoming call-site and per-job-type gauge rows plus their explanation.
- node-health.json: merged structurally rather than by text. This
branch's panels are authoritative; only the two incoming job-queue
panels were appended, below the existing layout. The
`Validated Ledger Seq` panels added directly in Grafana are preserved.
- job-queue.json, ledger-data-sync.json: panel sets were identical, so
took the incoming side for its `$handler` variable, the handler filter
on existing queries, and the new panels. Verified no panel was lost.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Slowness on the peer object-fetch path could be observed but not
attributed. Job duration metrics carry only `job_type`, and both
`RcvGetLedger` and `RcvGetObjByHash` report as `ledgerRequest`, so a
queue-wait spike could not be traced to a handler. Nothing measured
NodeStore cost, request size, or the differential charge.
Latency now decomposes into three additive parts, each separately
measurable:
end-to-end = queue wait + NodeStore lookup + everything else
- `handler` label on job_queued_total/_started_total/_finished_total and
job_queued_us/job_running_us. The value is sanitised: a name passes
through only if non-empty and all ASCII letters, else "other". Two job
names embed a ledger sequence, so a raw label would mint one series
per ledger; the rule bounds the domain at 43 names plus "other".
- getobject_lookup_us, _request_objects, _lookups_total{result},
_rejected_total{reason} and _charge, recorded at their call sites.
All three histograms get explicit bucket views: the SDK default stops
at 10,000, which every one of them exceeds.
- Per-job-type waiting/running/deferred gauges for the 35 non-special
job types. `deferred` is the leading indicator, since addJob never
rejects -- it defers, so backpressure otherwise shows up only as
latency after the fact.
`JobQueue::collect()` snapshots the counters under the queue lock and
publishes gauges after releasing it. Writing them while holding the lock
would invert a lock order against the collector's own lock, which the
collector's flush thread already holds when it calls this hook.
Tests assert exact values, including that the charge is priced on the
requested count rather than the capped iteration count.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Add shared current_ledger_seq / current_ledger_hash span attributes so a
transaction's work can be joined to the ledger trace that produced it, and
fix discrepancy D1 (txq.enqueue was a detached trace root).
- Define current_ledger_seq / current_ledger_hash once in SpanNames.h and
re-export via `using` from TxQ/TxApply/Tx span-name headers. These name the
ledger being worked on (open/tentative apply or in-flight consensus build),
distinct from ledger_seq (the built/validated ledger on ledger.build /
consensus.round). Named after the RPC field ledger_current_index.
- txq.enqueue: set current_ledger_seq/hash from the view, and parent the span
to the caller's tx.process span via an explicit captured SpanContext (new
trailing TxQ::apply param) instead of a detached root. The parent is
explicit, not ambient-inherited, and the ScopedSpanGuard scope is RAII-bound
to the synchronous apply, so it cannot leak onto a reused worker (D1 fix).
On the open-ledger rebuild path no tx.process context exists, so it stays a
root and the attribute provides the correlation.
- tx.preclaim / tx.transactor: set both attributes from their ledger view.
tx.preflight is stateless (no view) and is the documented exception.
- tx.process / tx.receive: set current_ledger_seq from the current open ledger
index at submit/receive time (no hash: not yet applied to a ledger).
- Contract test pins the two new attribute key strings.
Neither key is a spanmetrics dimension, so there is no metric-cardinality
impact. Dashboards/collector/docs land on the later phases per the chain split.
Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Replace the raw "trace_id="/" span_id=" prefix literals and the bare 32/16
hex-width magic numbers in the log trace-context injection with named
constexpr constants (kTraceIdPrefix, kSpanIdPrefix, kTraceIdHexLen,
kSpanIdHexLen), documenting that the widths are the W3C 16-byte trace_id /
8-byte span_id rendered as lowercase hex. No behavior change.
Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
