diff --git a/.github/scripts/telemetry/check_bucket_parity.py b/.github/scripts/telemetry/check_bucket_parity.py index 4c723fb4c0..b0baef2f90 100755 --- a/.github/scripts/telemetry/check_bucket_parity.py +++ b/.github/scripts/telemetry/check_bucket_parity.py @@ -2,13 +2,13 @@ """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. +histogram panel can be read on the same scale. Nothing else couples them, so +extending one ladder alone -- sub-millisecond edges below 1ms, second-scale +edges up to 30s -- silently leaves the other short. That failure is quiet: +Prometheus returns the second-highest edge for a quantile landing in the +`+Inf` bucket, so every quantile above a too-low ceiling reads back as a flat +number that looks like a measurement rather than an error. This check is what +makes the drift loud. The rule is containment, not equality: @@ -17,7 +17,7 @@ The rule is containment, not equality: * 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; + ceiling that censors it, recreating the failure 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 @@ -117,8 +117,10 @@ def main(): ) 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.", + "permitted only ABOVE the collector's highest edge. To re-price the shared\n" + f"range, edit the ladder in {HEADER} and the\n" + f"spanmetrics 'buckets:' list in {COLLECTOR}\n" + "in the same change, so both sides stay in step.", file=sys.stderr, ) return 1 diff --git a/.github/scripts/telemetry/test_check_regression_bounds.py b/.github/scripts/telemetry/test_check_regression_bounds.py index 5e7a4b7811..ac66eb2f1b 100644 --- a/.github/scripts/telemetry/test_check_regression_bounds.py +++ b/.github/scripts/telemetry/test_check_regression_bounds.py @@ -93,8 +93,7 @@ class CheckerCase(unittest.TestCase): Read from the scratch copies of the real inputs rather than written as literals, because a literal here is a copy of one particular baseline: - two of these tests previously hard-coded values from the 2026-08-24 - capture and both broke the moment the baseline was refreshed, which is + a hard-coded figure breaks the moment the baseline is refreshed, which is the very drift check_regression_bounds.py exists to catch. Deriving the figure keeps the assertion pinned to the rule instead of to a snapshot. """ diff --git a/OpenTelemetryPlan/05-configuration-reference.md b/OpenTelemetryPlan/05-configuration-reference.md index 2f91b7aa46..a5dec3fc52 100644 --- a/OpenTelemetryPlan/05-configuration-reference.md +++ b/OpenTelemetryPlan/05-configuration-reference.md @@ -69,7 +69,7 @@ The authoritative `[telemetry]` example lives in `cfg/xrpld-example.cfg`. Teleme | Option | Type | Default | Description | | -------------------------- | ------ | ---------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | | `enabled` | 0 or 1 | `0` | Enable/disable telemetry | -| `endpoint` | string | `http://localhost:4318/v1/traces` | OTLP/HTTP collector endpoint for **traces** | +| `traces_endpoint` | string | `http://localhost:4318/v1/traces` | OTLP/HTTP collector endpoint for **traces** | | `metrics_endpoint` | string | `http://localhost:4318/v1/metrics` | OTLP/HTTP collector endpoint for the native metrics pipeline (`MetricsRegistry`). Read in `Application.cpp:1670` | | `use_tls` | 0 or 1 | `0` | Enable TLS for exporter connection | | `tls_ca_cert` | string | `""` | Path to CA certificate file | @@ -131,10 +131,10 @@ The parser `makeTelemetrySetup()` in `src/libxrpl/telemetry/TelemetryConfig.cpp` `metrics_endpoint` is deliberately **not** handled here: it is read separately in `ApplicationImp::startTelemetry()` (`Application.cpp:1670`) and passed to `MetricsRegistry::start()`. Note the consequence — the two metric exporters resolve their URL differently: -| Metric source | Exporter built by | URL comes from | -| ------------------------------------------ | -------------------------------------------- | -------------------------------------------------------------------- | -| `beast::insight` (`[insight] server=otel`) | `Telemetry::initMetrics()` (global provider) | `endpoint` with a trailing `/v1/traces` rewritten to `/v1/metrics` | -| Native `XRPL_METRIC_*` (`MetricsRegistry`) | `MetricsRegistry::initExporterAndProvider()` | `metrics_endpoint`, defaulting to `http://localhost:4318/v1/metrics` | +| Metric source | Exporter built by | URL comes from | +| ------------------------------------------ | -------------------------------------------- | ------------------------------------------------------------------------- | +| `beast::insight` (`[insight] server=otel`) | `Telemetry::initMetrics()` (global provider) | `traces_endpoint` with a trailing `/v1/traces` rewritten to `/v1/metrics` | +| Native `XRPL_METRIC_*` (`MetricsRegistry`) | `MetricsRegistry::initExporterAndProvider()` | `metrics_endpoint`, defaulting to `http://localhost:4318/v1/metrics` | Setting a non-default `endpoint` therefore moves the insight metrics with it, but leaves the native metrics on localhost unless `metrics_endpoint` is set too. diff --git a/OpenTelemetryPlan/09-data-collection-reference.md b/OpenTelemetryPlan/09-data-collection-reference.md index 68f2056ed8..90a0cb9c29 100644 --- a/OpenTelemetryPlan/09-data-collection-reference.md +++ b/OpenTelemetryPlan/09-data-collection-reference.md @@ -2230,7 +2230,7 @@ endpoint=http://localhost:4318/v1/metrics ```ini [telemetry] enabled=1 -endpoint=http://otel-collector:4318/v1/traces +traces_endpoint=http://otel-collector:4318/v1/traces trace_peer=0 batch_size=1024 max_queue_size=4096 diff --git a/docker/telemetry/TESTING.md b/docker/telemetry/TESTING.md index 048e6b8526..73daa140c4 100644 --- a/docker/telemetry/TESTING.md +++ b/docker/telemetry/TESTING.md @@ -38,8 +38,10 @@ The binary is at `.build/xrpld`. ## Test 1: Single-Node Standalone (Quick Verification) -This test verifies RPC and transaction spans in standalone mode. Consensus -spans will not fire because standalone mode does not run consensus. +This test verifies RPC and transaction spans in standalone mode, plus the +consensus spans that a simulated round still produces. The proposal, voting +and peer-facing consensus spans do not fire — see the expected-spans table at +the end of this test for which do and which do not. ### Step 1: Start the observability stack @@ -125,32 +127,7 @@ curl -s http://localhost:5005 -d '{"method":"ledger_accept"}' ### Step 5: Verify traces in Tempo -Wait 5 seconds for the batch export, then: - -```bash -TEMPO="http://localhost:3200" - -# Check xrpld service is registered -curl -s "$TEMPO/api/v2/search/tag/resource.service.name/values" | jq '.tagValues[].value' - -# Check RPC spans -curl -s "$TEMPO/api/search" \ - --data-urlencode 'q={resource.service.name="xrpld" && name="rpc.http_request"}' \ - --data-urlencode 'limit=5' | jq '.traces | length' - -curl -s "$TEMPO/api/search" \ - --data-urlencode 'q={resource.service.name="xrpld" && name="rpc.process"}' \ - --data-urlencode 'limit=5' | jq '.traces | length' - -curl -s "$TEMPO/api/search" \ - --data-urlencode 'q={resource.service.name="xrpld" && name="rpc.command.server_info"}' \ - --data-urlencode 'limit=5' | jq '.traces | length' - -# Check transaction spans -curl -s "$TEMPO/api/search" \ - --data-urlencode 'q={resource.service.name="xrpld" && name="tx.process"}' \ - --data-urlencode 'limit=5' | jq '.traces | length' -``` +Wait 5 seconds for the batch export, then see the "Verification Queries" section below. Its span loop is a superset of what standalone mode produces, so compare its output against the "Expected spans (standalone mode)" table above rather than running a second, narrower set of queries here. Or open Grafana Explore with Tempo datasource: http://localhost:3000 @@ -164,23 +141,24 @@ kill $(pgrep -f 'xrpld.*xrpld-telemetry') docker compose -f docker/telemetry/docker-compose.yml down # Clean xrpld data -rm -rf data/ +rm -rf docker/telemetry/data/ ``` ### Expected spans (standalone mode) -| Span Name | Expected | Notes | -| --------------------------- | -------- | ----------------------------- | -| `rpc.http_request` | Yes | Every HTTP RPC call | -| `rpc.process` | Yes | Every RPC processing | -| `rpc.command.server_info` | Yes | server_info RPC | -| `rpc.command.server_state` | Yes | server_state RPC | -| `rpc.command.ledger` | Yes | ledger RPC | -| `rpc.command.submit` | Yes | submit RPC | -| `rpc.command.ledger_accept` | Yes | ledger_accept RPC | -| `tx.process` | Yes | Transaction submission | -| `tx.receive` | No | No peers in standalone | -| `consensus.*` | No | Consensus disabled standalone | +| Span Name | Expected | Notes | +| ---------------------------------------------------------------------------------------------------------- | -------- | ------------------------------------------------- | +| `rpc.http_request` | Yes | Every HTTP RPC call | +| `rpc.process` | Yes | Every RPC processing | +| `rpc.command.server_info` | Yes | server_info RPC | +| `rpc.command.server_state` | Yes | server_state RPC | +| `rpc.command.ledger` | Yes | ledger RPC | +| `rpc.command.submit` | Yes | submit RPC | +| `rpc.command.ledger_accept` | Yes | ledger_accept RPC | +| `tx.process` | Yes | Transaction submission | +| `tx.receive` | No | No peers in standalone | +| `consensus.round`, `.phase.open`, `.ledger_close`, `.accept`, `.accept.apply` | Yes | `ledger_accept` drives a simulated round | +| `consensus.establish`, `.update_positions`, `.check`, `.proposal.*`, `.validation.receive`, `.mode_change` | No | `simulate` jumps straight to `Accepted`; no peers | --- @@ -197,17 +175,11 @@ Run the integration test script: bash docker/telemetry/integration-test.sh ``` -The script will: +It checks prerequisites, clears the previous run, brings up the observability stack, generates six validator key pairs and their node configs, starts the nodes, waits for consensus and then for a validated ledger, exercises RPC and submits a transaction, verifies traces in Tempo and both the spanmetrics and the StatsD-derived metrics in Prometheus, then prints a summary and leaves the stack running. -1. Start the observability stack -2. Generate 6 validator key pairs -3. Create config files for each node -4. Start all 6 nodes -5. Wait for consensus ("proposing" state) -6. Exercise RPC, submit transactions -7. Verify all span categories in Tempo -8. Verify spanmetrics in Prometheus -9. Print results and leave the stack running +The script announces each step as it runs, so read its `Step N:` headers for the authoritative sequence — they are not restated here, because a numbered copy of them drifts as soon as a step is added. + +Its Tempo checks cover the RPC, transaction, consensus, ledger and peer span categories from a fixed list, which is narrower than the loop in the "Verification Queries" section below. ### Manual @@ -243,7 +215,7 @@ Kill the temporary node: ```bash kill $TEMP_PID -rm -rf data/ +rm -rf docker/telemetry/data/ ``` #### Step 3: Create node configs @@ -296,7 +268,7 @@ online_delete=256 [telemetry] enabled=1 -endpoint=http://localhost:4318/v1/traces +traces_endpoint=http://localhost:4318/v1/traces batch_size=512 batch_delay_ms=2000 max_queue_size=2048 @@ -371,9 +343,11 @@ curl -s http://localhost:5005 -d '{ "Amount": "10000000" } }] -}' +}' | jq .result.engine_result ``` +Expected result: `"tesSUCCESS"`, the same as Test 1 Step 4. + Wait 15 seconds for consensus and batch export. #### Step 8: Verify in Tempo diff --git a/docker/telemetry/docker-compose.yml b/docker/telemetry/docker-compose.yml index b39e60ce43..ebab967702 100644 --- a/docker/telemetry/docker-compose.yml +++ b/docker/telemetry/docker-compose.yml @@ -24,7 +24,7 @@ # Configure xrpld to export traces by adding to xrpld.cfg: # [telemetry] # enabled=1 -# endpoint=http://localhost:4318/v1/traces +# traces_endpoint=http://localhost:4318/v1/traces services: # One-shot init for the collector's offset store. Docker creates a fresh diff --git a/docker/telemetry/integration-test.sh b/docker/telemetry/integration-test.sh index b24d90015a..26d4c288da 100755 --- a/docker/telemetry/integration-test.sh +++ b/docker/telemetry/integration-test.sh @@ -384,7 +384,7 @@ ${IPS_FIXED} [telemetry] enabled=1 service_instance_id=Node-${i} -endpoint=http://localhost:4318/v1/traces +traces_endpoint=http://localhost:4318/v1/traces exporter=otlp_http batch_size=512 batch_delay_ms=2000 @@ -619,6 +619,9 @@ log "--- Spanmetrics ---" log "Waiting 20s for Prometheus scrape cycle..." sleep 20 +# Names come from the spanmetrics connector's `namespace: "span"` in +# otel-collector-config.yaml. Without that namespace the connector emits +# traces_span_metrics_*, so these queries must move whenever it changes. calls_count=$(curl -sf "$PROM/api/v1/query?query=span_calls_total" | jq '.data.result | length' 2>/dev/null || echo 0) if [ "$calls_count" -gt 0 ]; then @@ -662,6 +665,12 @@ check_otel_metric() { fi } +# Names are what OTelCollector::formatName() produces: the beast::insight +# name lowercased with '.' and ' ' mapped to '_', any group() segment kept, and +# no prefix. The [insight] prefix knob is logged at startup and never applied on +# this path, and the collector's prometheus exporter sets no namespace, so a +# name carrying a product prefix or capitals cannot match any exported series. + # Node health gauges (ObservableGauge — no _total suffix) check_otel_metric "ledgermaster_validated_ledger_age" check_otel_metric "ledgermaster_published_ledger_age" @@ -677,7 +686,8 @@ check_otel_metric "peer_finder_active_outbound_peers" # RPC counters (Counter — Prometheus adds _total suffix automatically) check_otel_metric "rpc_requests_total" -# Overlay traffic +# Overlay traffic — one series per TrafficCount category; "total" is the +# aggregate category. check_otel_metric "total_bytes_in" # Verify StatsD receiver is NOT required (no statsd receiver in pipeline) diff --git a/docker/telemetry/workload/README.md b/docker/telemetry/workload/README.md index ff4528a574..d3fd4d0f8d 100644 --- a/docker/telemetry/workload/README.md +++ b/docker/telemetry/workload/README.md @@ -298,19 +298,19 @@ Per-run tuning: variance is larger than it cannot be gated at all. **Five keys are excluded** for that reason: `span.ledger.validate.p95` and `.p99`, plus `span.tx.apply.p50`, `span.ledger.build.p50` and - `span.consensus.ledger_close.p50` as of the 2026-08-26 refresh. Each carries + `span.consensus.ledger_close.p50`. Each carries its measurements in `excluded_keys` in `regression-metrics.json`. Check a key's observed maximum across runs against `baseline + bound` before gating it; widening the bound is not the fix, and neither is re-baselining until a run lands favourably. See `baselines/README.md`. - A refresh moves sensitivity in **both** directions, because the trip point is derived from the baseline, and a single run carries no information about - spread. The 2026-08-26 refresh loosened `job.acceptLedger.running.p95` from a - 5.74x detection floor to 16.28x (it does not fire, so it stays gated) and cut - the three `p50` keys above from a bound that had absorbed their spread to one - that could not — `span.tx.apply.p50` read 0.7917 ms in the previous baseline - and 0.00597 ms in this one, a 132x move on the same workload, taking its bound - from 4.21 ms to 0.0440 ms. Gating those keys again needs a **multi-run + spread. `job.acceptLedger.running.p95` has been measured with a 5.74x + detection floor on one baseline and 16.28x on another (it does not fire, so it + stays gated), and the three `p50` keys above have been measured both inside and + outside a bound that absorbs their spread — `span.tx.apply.p50` has read + 0.7917 ms and 0.00597 ms on the same workload, 132x apart, which moves its + bound between 4.21 ms and 0.0440 ms. Gating those keys needs a **multi-run baseline** (or a spread measurement captured beside it), not a new threshold. All of it is measured in `baselines/README.md`; re-check after every refresh. @@ -510,7 +510,7 @@ Re-run it after any change to log formatting, span activation, the collector's ### Pathfinding is not exercised -`rpc_load_generator.py` stopped issuing `ripple_path_find` on 2026-08-25 — the weight, the request-builder branch and the docstring line went together. +`rpc_load_generator.py` issues no path-finding RPC: `DEFAULT_WEIGHTS` carries no `ripple_path_find` entry and `build_rpc_request()` has no branch for it. **Why.** Pathfinding is disabled on every node this harness starts, so those calls could only ever fail: @@ -518,16 +518,16 @@ Re-run it after any change to log formatting, span activation, the collector's - `run-full-validation.sh:308` writes `[validation_seed]` into every generated node cfg, and that script carries no `[path_search]`, `[path_search_fast]` or `[path_search_max]` section to put the default back. - `src/xrpld/rpc/handlers/orderbook/RipplePathFind.cpp:48-49` therefore returns `rpcNOT_SUPPORTED`; `PathFind.cpp:39` does the same for `path_find`. -**What removing it fixes.** The refusals were not silent. `pathfind.request` is opened at `RipplePathFind.cpp:35`, **above** that guard, so every refused call still exported a span, and the enclosing `rpc.command.ripple_path_find` span carried `rpc_status=error`. At a 3% weight that manufactured a steady ~3% error floor in `span_calls_total{status_code="STATUS_CODE_ERROR"}`. **Any error-rate threshold derived from harness data before this change was measuring the harness, not xrpld** — re-derive it. +**Why the refusals would not be harmless.** They are not silent. `pathfind.request` is opened at `RipplePathFind.cpp:35`, **above** that guard, so a refused call still exports a span, and the enclosing `rpc.command.ripple_path_find` span carries `rpc_status=error`. At a 3% weight that is a steady ~3% error floor in `span_calls_total{status_code="STATUS_CODE_ERROR"}` — a figure that reads as an xrpld error rate and is not one. **An error-rate threshold derived from a harness run that does issue path-finding load is measuring the harness, not xrpld.** -**What it costs.** Pathfinding now has no coverage here at all. Four spans (`pathfind.request`, `.compute`, `.discover`, `.update_all`) and two histograms (`pathfind_fast_milliseconds`, `pathfind_full_milliseconds`) go unexercised, and `pathfind.request` moved from required to `"optional": true` in `expected_spans.json` for that reason. Until the load returns, verify pathfinding by hand: the **PathFind** row of [`../TESTING.md`](../TESTING.md) carries a `curl` recipe, and `../xrpld-telemetry.cfg` is a non-validator config that already enables pathfinding. +**What it costs.** Pathfinding has no coverage here at all. Four spans (`pathfind.request`, `.compute`, `.discover`, `.update_all`) and two histograms (`pathfind_fast_milliseconds`, `pathfind_full_milliseconds`) go unexercised, which is why `pathfind.request` is marked `"optional": true` in `expected_spans.json`. Verify pathfinding by hand instead: the **PathFind** row of [`../TESTING.md`](../TESTING.md) carries a `curl` recipe, and `../xrpld-telemetry.cfg` is a non-validator config that already enables pathfinding. -**Putting it back.** All four steps are required. The first two alone just restore the error floor: +**Enabling it.** All four steps are required. The first two alone produce the error floor described above: 1. Add a `[path_search_max]` section to the node cfg `run-full-validation.sh` generates — or drop `[validation_seed]` and run a non-validator node. The `[path_search*]` block in `../xrpld-telemetry.cfg` is a working example. -2. Restore the `ripple_path_find` weight in `DEFAULT_WEIGHTS` and its branch in `build_rpc_request()`. `path_find` is a streaming subscription and needs its own phase instead — the generator is strictly one request, one reply. -3. Set `pathfind.request` back to required in `expected_spans.json`. Step 1 also makes `pathfind.compute` reachable, so the `pathfind.request -> pathfind.compute` relationship can lose its `"skip": true`. -4. **Re-capture `baselines/baseline-timings.json`.** Restoring the load changes the RPC mix, and `span.rpc.ws_message.{p50,p95,p99}` is a gated key — a baseline captured under a different mix is stale. See [OTel Timings Regression Gate](#otel-timings-regression-gate). +2. Add a `ripple_path_find` weight to `DEFAULT_WEIGHTS` and a branch for it in `build_rpc_request()`. `path_find` is a streaming subscription and needs its own phase instead — the generator is strictly one request, one reply. +3. Set `pathfind.request` to required in `expected_spans.json`. Step 1 also makes `pathfind.compute` reachable, so the `pathfind.request -> pathfind.compute` relationship can lose its `"skip": true`. +4. **Re-capture `baselines/baseline-timings.json`.** Adding the load changes the RPC mix, and `span.rpc.ws_message.{p50,p95,p99}` is a gated key — a baseline captured under a different mix is stale. See [OTel Timings Regression Gate](#otel-timings-regression-gate). ## Configuration Files diff --git a/docker/telemetry/workload/baselines/README.md b/docker/telemetry/workload/baselines/README.md index 91ede32e65..684e7e640d 100644 --- a/docker/telemetry/workload/baselines/README.md +++ b/docker/telemetry/workload/baselines/README.md @@ -35,7 +35,7 @@ at `6a82fc6f37` that predated two workload changes — the removal of the refuse load (`59a0595a6e`) and everything after it — so its numbers described a workload the harness no longer runs. The entries before that, captured on 2026-06-05, were voided into a placeholder: they predated the -spanmetrics ladder re-cut of 2026-08-04 (`3860c93db2`), which made every sub-millisecond quantile +spanmetrics ladder's 1 ms floor, which made every sub-millisecond quantile in that capture bucket-edge arithmetic rather than a latency (a p95 of `0.95` ms is `0.95 × 1 ms`). Because the comparator only flags a metric when the current value _exceeds_ the baseline, a stale-high baseline passes everything silently, so the entries had to be dropped rather than left @@ -206,7 +206,7 @@ proves nothing; it is spread **relative to the trip point** that decides. And be point is derived from the baseline, a baseline that lands at the **low end** of a metric's own range shrinks that trip point without anything about the metric having changed. -That is what the 2026-08-26 refresh did to three `p50` keys, and **all three are now excluded** — +That is what happened to three `p50` keys on this baseline, and **all three are excluded** — this rule being applied, not a new exception. Measured across the three CI runs `32862589645`, `32867433073` and `32964262700` (the last of which is this baseline): diff --git a/docker/telemetry/workload/expected_metrics.json b/docker/telemetry/workload/expected_metrics.json index 80d80e3d9a..1a6bbbba73 100644 --- a/docker/telemetry/workload/expected_metrics.json +++ b/docker/telemetry/workload/expected_metrics.json @@ -277,7 +277,7 @@ "not_asserted": { "description": "Emitted-and-dashboarded metrics deliberately left unasserted because they are workload-gated or defect-gated: the harness workload cannot guarantee they appear, and a check that fails on a healthy run is worse than no check. This group has no \"metrics\" key, so validate_telemetry.py skips it (validate_metrics iterates category_data.get(\"metrics\", [])). Promote an entry into an asserted group only after the workload is changed to guarantee it. This map is the ONLY machine-readable record of an emitted-but-unasserted name, so every such name belongs here rather than in a prose note inside an asserted group -- prose cannot be linted. Concretely, phase-10 adds an _unaccounted_metric_names pass that harvests this map's keys as accounted names, so a name recorded only in a prose note is reported as unaccounted once that lands. It is warning-only and cannot fail CI, and it accepts a third source as well (an accounted_patterns regex list), so this map is the right home but not the only possible one. Caveat when adding: check_otel_naming.py Rule K harvests names only from `metrics` LISTS and from metric/name keys, so these dict KEYS are never validated against the MetricNames.h constants -- a typo here is silent, and must be checked by eye against the emit site cited in its own reason string.", "metrics_excluded": { - "rpc_method_errored_total": "MetricsRegistry.cpp:332-333, push counter. 'Errored' here means a thrown C++ exception, not an error status in the JSON reply: the only caller is PerfLogImp.cpp:409 under 'if (!finish)', reached only through PerfLogImp::rpcError (PerfLogImp.h:150-153), whose only call site is the catch (std::exception&) handler in RPCHandler.cpp:213. An RPC that returns an error status normally still takes the rpcFinish path at RPCHandler.cpp:190 and increments rpc_method_finished_total. That distinction mattered here while the generator still issued ripple_path_find: those calls were in fact refused — pathfinding is off on every harness node, so doRipplePathFind returns rpcNOT_SUPPORTED (see pathfind_fast_milliseconds below) — and it would have been easy to conclude from that alone that this counter must fire. It did not, because a refusal is a normal return, not a throw. The load was removed on 2026-08-25, so the harness no longer issues that command at all and the question is moot, but the distinction is kept on record because it is the one that decides this entry. Nothing in rpc_load_generator.py's remaining server_info / fee / account / ledger / tx / DEX mix is expected to throw either, so no series may ever be created.", + "rpc_method_errored_total": "MetricsRegistry.cpp:332-333, push counter. 'Errored' here means a thrown C++ exception, not an error status in the JSON reply: the only caller is PerfLogImp.cpp:409 under 'if (!finish)', reached only through PerfLogImp::rpcError (PerfLogImp.h:150-153), whose only call site is the catch (std::exception&) handler in RPCHandler.cpp:213. An RPC that returns an error status normally still takes the rpcFinish path at RPCHandler.cpp:190 and increments rpc_method_finished_total. That distinction mattered here while the generator still issued ripple_path_find: those calls were in fact refused — pathfinding is off on every harness node, so doRipplePathFind returns rpcNOT_SUPPORTED (see pathfind_fast_milliseconds below) — and it would have been easy to conclude from that alone that this counter must fire. It does not, because a refusal is a normal return, not a throw. The harness issues no path-finding command at all, so the question is moot here, but the distinction is kept on record because it is the one that decides this entry. Nothing in rpc_load_generator.py's remaining server_info / fee / account / ledger / tx / DEX mix is expected to throw either, so no series may ever be created.", "ledger_history_mismatch_total": "MetricsRegistry.cpp:377, incremented only from LedgerHistory.cpp:332 on a built-vs-validated ledger mismatch. On a healthy run it never fires — asserting it would mean asserting a defect.", "txq_expired_total": "MetricsRegistry.cpp:379, incremented only at TxQ.cpp:1428 when a queued tx expires past its LastLedgerSequence. CI does run a txq-burst phase (workload-profiles.json:41, 30 s of single-type Payment at 60 TPS), but that does not guarantee sustained fee escalation followed by expiry: a run in which every other check passed still exposed only txq_metrics and no txq_expired_total.", "txq_dropped_total": "MetricsRegistry.cpp:381, incremented only at TxQ.cpp:1302 / :1347 on queue-full admission refusal. Same reason as txq_expired_total.", @@ -301,8 +301,8 @@ "rotation_copy_node_restore_total": "SHAMapStoreImp.cpp:283. Fires only for a clean tree node reachable from the validated state map whose sole on-disk copy an EARLIER rotation removed, so it needs at least two rotations (512 validated ledgers, ~15-20 min at the cluster's close rate) plus real prior data loss. The run window is 270 s. Note that the rotation_state gauge sub-series ARE asserted -- see sync_diagnostics._b5_rotation_note for why a series exists while a rotation never runs.", "rpc_size_bytes": "ServerHandler.cpp:191, group('rpc')->makeEvent('size', Unit::Bytes). The OTLP Prometheus exporter derives the metric-name suffix from the declared unit, so a byte unit yields rpc_size_bytes. The Unit::Bytes declaration itself landed earlier, in 76c9051203; what 24094e427b changed was the exporter finally consuming it, replacing a hardcoded CreateDoubleHistogram(name, 'Duration in ms', 'ms') with otelUnitDescription(unit)/otelUnitCode(unit), and that is what renamed the series off rpc_size_milliseconds and the millisecond bucket ladder. Neither name was ever recorded here, so the harness could confirm neither the rename nor a regression back onto that ladder. Notified from ServerHandler::processRequest:1133, the HTTP JSON-RPC path — it computes an HTTP status and appends a trailing newline — and the load generators are WebSocket-only, the same gate regression-metrics.json:4 records for rpc.process, so only the harness's handful of HTTP health polls reach it. Real coverage needs an HTTP JSON-RPC phase in rpc_load_generator.py; that is a workload change rather than a harness correction, and is deliberately out of scope here.", "rpc_time_milliseconds": "ServerHandler.cpp:192, group('rpc')->makeEvent('time') with the default millisecond unit. Notified from ServerHandler::processRequest:1129, the same HTTP JSON-RPC call site as rpc_size_bytes and behind the same WebSocket-only gate.", - "pathfind_fast_milliseconds": "PathRequestManager.h:35, makeEvent('pathfind_fast') with the default millisecond unit, so the exported form is the pathfind_fast_milliseconds_bucket/_count/_sum triple and there is no bare series — the same convention io_latency and rpc_method_us follow, and rpc-pathfinding queries the _bucket. THE OPERATIVE BLOCKER IS THE CONFIG, NOT THE CALL GRAPH: pathfinding is disabled outright on every harness node, so no PathRequest is ever constructed and no pathfind_* histogram can exist. Config.cpp:725-726 sets pathSearchMax to 0 whenever a [validation_seed] or [validator_token] section is present ('By default, validators don't have pathfinding enabled'); run-full-validation.sh writes [validation_seed] into every generated node cfg (:308) and contains no [path_search], [path_search_fast] or [path_search_max] section to put it back (grep count 0 for path_search in that file — the only [path_search*] sections in docker/telemetry/ are in xrpld-telemetry.cfg and xrpld-telemetry-mainnet.cfg, neither of which the harness uses); and doRipplePathFind returns rpcNOT_SUPPORTED at RipplePathFind.cpp:48-49, before context.loadType is set and before any branch on the ledger parameter. That config gate is why the metric could never appear even while the generator was issuing the command (a 3% ripple_path_find weight, removed on 2026-08-25 precisely because every one of those calls was refused at the front door); the harness now issues no path-finding RPC at all, so there are two independent reasons. Read that first: the structural argument below is correct and matters if pathfinding is ever enabled, but it is not why the metric is missing today. STRUCTURAL ARGUMENT (verified, applies once pathSearchMax is non-zero): reportFast's only caller is PathRequest.cpp:852, inside the 'if (fast && quickReply_ == {})' branch of PathRequest::doUpdate. The only doUpdate call that passes fast=true is in PathRequest::doCreate (PathRequest.cpp:259), guarded by '!hasCompletion()'. Both ripple_path_find entry points construct the PathRequest with a completion function, so hasCompletion() (:161-164) is true and the fast pass is skipped: with no ledger specified doRipplePathFind goes to makeLegacyPathRequest, which passes the coroutine-post lambda (RipplePathFind.cpp:140-160); with a ledger specified it goes to doLegacyPathRequest, which passes an empty-body but non-null lambda (PathRequestManager.cpp:317). Only the path_find streaming subscription reaches reportFast, because makePathRequest builds the request from a subscriber with no completion (PathRequestManager.cpp:261). The load generator has never used path_find: it fires one request per send and awaits one reply, which a streaming subscription does not fit. Covering this metric therefore needs both a [path_search_max] override (or a non-validator node) in run-full-validation.sh and a path_find subscription phase in the generator. Both are harness/workload changes and out of scope here. Grafana Cloud shows zero series in 180 days on the devnet nodes, consistent with those nodes receiving no pathfinding RPC.", - "pathfind_full_milliseconds": "PathRequestManager.h:36, makeEvent('pathfind_full'); same histogram naming as pathfind_fast_milliseconds above. Notified from reportFull (:87-90) via PathRequest.cpp:857, the 'else if (!fast && fullReply_ == {})' branch. Blocked by exactly the same config gate as pathfind_fast_milliseconds, and the probability of emission under the harness workload is zero, not low: pathSearchMax is 0 on every harness node (Config.cpp:725-726 plus the [validation_seed] section at run-full-validation.sh:308, with no [path_search*] override anywhere in that file), so doRipplePathFind returns rpcNOT_SUPPORTED at RipplePathFind.cpp:48-49 and no PathRequest object is ever constructed for reportFull to fire from. An earlier revision of this entry described the path as reachable-but-probabilistic — emitting one ledger close behind the request via PathRequestManager::updateAll's one-shot branch (PathRequestManager.cpp:160-166) — and prescribed sending an explicit ledger_index from the generator so doLegacyPathRequest would call doUpdate(cache, false) synchronously (PathRequestManager.cpp:321). Both halves were wrong. The probability is zero rather than merely unreliable, and the prescribed remedy cannot work at all, because the pathSearchMax guard fires before the ledger parameter is read: adding ledger_index changes nothing while pathfinding is off. Since 2026-08-25 the generator issues no path-finding RPC either, so covering this metric needs a [path_search_max] override (or a non-validator node) in run-full-validation.sh AND the load restored — a harness-topology plus workload change, out of scope here. The workload README section 'Pathfinding is not exercised' holds the recipe. Grafana Cloud shows zero series in 180 days on the devnet nodes, consistent with those nodes receiving no pathfinding RPC rather than with a broken exporter.", + "pathfind_fast_milliseconds": "PathRequestManager.h:35, makeEvent('pathfind_fast') with the default millisecond unit, so the exported form is the pathfind_fast_milliseconds_bucket/_count/_sum triple and there is no bare series — the same convention io_latency and rpc_method_us follow, and rpc-pathfinding queries the _bucket. THE OPERATIVE BLOCKER IS THE CONFIG, NOT THE CALL GRAPH: pathfinding is disabled outright on every harness node, so no PathRequest is ever constructed and no pathfind_* histogram can exist. Config.cpp:725-726 sets pathSearchMax to 0 whenever a [validation_seed] or [validator_token] section is present ('By default, validators don't have pathfinding enabled'); run-full-validation.sh writes [validation_seed] into every generated node cfg (:308) and contains no [path_search], [path_search_fast] or [path_search_max] section to put it back (grep count 0 for path_search in that file — the only [path_search*] sections in docker/telemetry/ are in xrpld-telemetry.cfg and xrpld-telemetry-mainnet.cfg, neither of which the harness uses); and doRipplePathFind returns rpcNOT_SUPPORTED at RipplePathFind.cpp:48-49, before context.loadType is set and before any branch on the ledger parameter. That config gate alone would keep the metric absent even if the generator did issue the command, because every such call is refused at the front door; and the generator issues no path-finding RPC in the first place. Two independent reasons. Read that first: the structural argument below is correct and matters if pathfinding is ever enabled, but it is not why the metric is missing today. STRUCTURAL ARGUMENT (verified, applies once pathSearchMax is non-zero): reportFast's only caller is PathRequest.cpp:852, inside the 'if (fast && quickReply_ == {})' branch of PathRequest::doUpdate. The only doUpdate call that passes fast=true is in PathRequest::doCreate (PathRequest.cpp:259), guarded by '!hasCompletion()'. Both ripple_path_find entry points construct the PathRequest with a completion function, so hasCompletion() (:161-164) is true and the fast pass is skipped: with no ledger specified doRipplePathFind goes to makeLegacyPathRequest, which passes the coroutine-post lambda (RipplePathFind.cpp:140-160); with a ledger specified it goes to doLegacyPathRequest, which passes an empty-body but non-null lambda (PathRequestManager.cpp:317). Only the path_find streaming subscription reaches reportFast, because makePathRequest builds the request from a subscriber with no completion (PathRequestManager.cpp:261). The load generator has never used path_find: it fires one request per send and awaits one reply, which a streaming subscription does not fit. Covering this metric therefore needs both a [path_search_max] override (or a non-validator node) in run-full-validation.sh and a path_find subscription phase in the generator. Both are harness/workload changes and out of scope here. Grafana Cloud shows zero series in 180 days on the devnet nodes, consistent with those nodes receiving no pathfinding RPC.", + "pathfind_full_milliseconds": "PathRequestManager.h:36, makeEvent('pathfind_full'); same histogram naming as pathfind_fast_milliseconds above. Notified from reportFull (:87-90) via PathRequest.cpp:857, the 'else if (!fast && fullReply_ == {})' branch. Blocked by exactly the same config gate as pathfind_fast_milliseconds, and the probability of emission under the harness workload is zero, not low: pathSearchMax is 0 on every harness node (Config.cpp:725-726 plus the [validation_seed] section at run-full-validation.sh:308, with no [path_search*] override anywhere in that file), so doRipplePathFind returns rpcNOT_SUPPORTED at RipplePathFind.cpp:48-49 and no PathRequest object is ever constructed for reportFull to fire from. An earlier revision of this entry described the path as reachable-but-probabilistic — emitting one ledger close behind the request via PathRequestManager::updateAll's one-shot branch (PathRequestManager.cpp:160-166) — and prescribed sending an explicit ledger_index from the generator so doLegacyPathRequest would call doUpdate(cache, false) synchronously (PathRequestManager.cpp:321). Both halves were wrong. The probability is zero rather than merely unreliable, and the prescribed remedy cannot work at all, because the pathSearchMax guard fires before the ledger parameter is read: adding ledger_index changes nothing while pathfinding is off. The generator also issues no path-finding RPC, so covering this metric needs a [path_search_max] override (or a non-validator node) in run-full-validation.sh AND path-finding load added — a harness-topology plus workload change, out of scope here. The workload README section 'Pathfinding is not exercised' holds the recipe. Grafana Cloud shows zero series in 180 days on the devnet nodes, consistent with those nodes receiving no pathfinding RPC rather than with a broken exporter.", "warn_total": "include/xrpl/resource/detail/Logic.h:41, makeMeter('warn'). makeMeter maps to CreateUInt64Counter (OTelCollector.cpp:878-881 -> :773-777), so the Prometheus exporter appends _total; the meter is created on the bare collector with no group, hence the unprefixed name. Incremented only at Logic.h:481, inside the 'if (notify)' branch reached when a consumer's balance crosses kWarningThreshold. A cooperating 5-node cluster plus a rate-limited load generator never charges a consumer that far, and Grafana Cloud confirms zero series in 180 days. Recorded explicitly because this was briefly mis-diagnosed as a phantom metric: the rpc-pathfinding panel that queries it is correct, and renders empty only because the condition has not occurred.", "drop_total": "include/xrpl/resource/detail/Logic.h:42, makeMeter('drop'); same CreateUInt64Counter mapping and same _total suffix as warn_total. Incremented only at Logic.h:505, when a consumer's balance is at or above kDropThreshold and the connection is dropped. Grafana Cloud shows 2 live series, so unlike warn_total this one does fire in the wild — but only on a genuinely abusive consumer, which the harness deliberately does not create, so it is condition-gated all the same. Its rpc-pathfinding panel is likewise correct rather than phantom.", "jobq_*_milliseconds, jobq_*_q_milliseconds": "This key is a pattern rather than a literal metric name — unlike every other entry in this map it stands for a whole family, one pair per job type. Created per job type in JobTypeData.h:97-98 from info.name() and info.name() + kSuffixQueued ('_q'), so the exported names are jobq__milliseconds and jobq__q_milliseconds with the job type lowercased by formatName. Which job types appear depends on which jobs a run happens to schedule, so no individual name is guaranteed. They are also rounded up to a whole millisecond at source (Event.h:47-51 applies ceil to a millisecond value type), which is why 6e2b2da772 moved the ledger-data-sync q-wait panels off jobq__q_milliseconds_bucket onto job_queued_us_bucket — they are poor assertion targets regardless." diff --git a/docker/telemetry/workload/expected_spans.json b/docker/telemetry/workload/expected_spans.json index b2a08a8903..8448a78d16 100644 --- a/docker/telemetry/workload/expected_spans.json +++ b/docker/telemetry/workload/expected_spans.json @@ -25,7 +25,7 @@ "required_attributes": [], "config_flag": "trace_rpc", "optional": true, - "note": "HTTP-only. Created solely in ServerHandler::processRequest() (ServerHandler.cpp:705), which is reached only from processSession(Session, coro) (ServerHandler.cpp:646) — the HTTP/JSON-RPC path that roots rpc.http_request at ServerHandler.cpp:640-641. The WebSocket path (processSession(WSSession, coro, jv), ServerHandler.cpp:467) never calls processRequest, so this span never appears under a WebSocket request. It does still appear under this harness, 5 traces on a normal run, because run-full-validation.sh polls each node over HTTP with curl (:449, :502) and those requests take the HTTP path. Corrected 2026-08-26; this note previously concluded the span cannot appear at all, which sent a reader looking for a way to make the harness speak HTTP that it already speaks." + "note": "HTTP-only. Created solely in ServerHandler::processRequest() (ServerHandler.cpp:705), which is reached only from processSession(Session, coro) (ServerHandler.cpp:646) — the HTTP/JSON-RPC path that roots rpc.http_request at ServerHandler.cpp:640-641. The WebSocket path (processSession(WSSession, coro, jv), ServerHandler.cpp:467) never calls processRequest, so this span never appears under a WebSocket request. It does still appear under this harness, 5 traces on a normal run, because run-full-validation.sh polls each node over HTTP with curl (:449, :502) and those requests take the HTTP path. Note that the harness does speak HTTP: a reader concluding this span is unreachable here would go looking for a way to add HTTP traffic that already exists." }, { "name": "rpc.command.*", @@ -42,7 +42,7 @@ "required_attributes": ["request_payload_size"], "config_flag": "trace_rpc", "optional": true, - "note": "HTTP/JSON-RPC root span. It DOES fire under this harness, 5 traces on a normal run -- one per node -- even though the load generator is WebSocket-only, because run-full-validation.sh polls each node's HTTP port with curl for readiness and validated-ledger progress (:449, :502). Corrected 2026-08-26; this note previously said it does not fire. Kept optional rather than promoted to required because those polls are harness scaffolding rather than workload: a future change to how the script waits for a node could remove them without anything being wrong with the node." + "note": "HTTP/JSON-RPC root span. It DOES fire under this harness, 5 traces on a normal run -- one per node -- even though the load generator is WebSocket-only, because run-full-validation.sh polls each node's HTTP port with curl for readiness and validated-ledger progress (:449, :502). Kept optional rather than required because those polls are harness scaffolding rather than workload: a future change to how the script waits for a node could remove them without anything being wrong with the node." }, { "name": "tx.process", @@ -440,7 +440,7 @@ ], "config_flag": "trace_rpc", "optional": true, - "note": "Fires on ripple_path_find / path_find RPC. Optional because the harness issues neither: the ripple_path_find weight was removed from rpc_load_generator.py's DEFAULT_WEIGHTS on 2026-08-25, and no workload-profiles.json phase names a path-finding command in a weights override, so no such RPC reaches a node at all. Created as an ambient (scoped) child inside the RPC command handler (RipplePathFind.cpp:35-36, PathFind.cpp:26-27), so its parent is the enclosing rpc.command.* span — RipplePathFind.cpp:30 states this explicitly. Note the span does NOT need pathfinding to be ENABLED, only the RPC to be issued: the ScopedSpanGuard is constructed at RipplePathFind.cpp:35, above the 'if (pathSearchMax == 0) return rpcError(RpcNotSupported)' guard at :48-49, so even a refused call opens and closes it. That positional accident is why the load alone used to satisfy this entry while pathfind.compute and pathfind.discover below stayed unasserted — and why those refusals were also manufacturing a steady ~3% STATUS_CODE_ERROR floor in span_calls_total, which removing the load has now cleared. Restoring the load alone would make this span required again and bring that error floor back; covering the whole family needs pathfinding actually enabled (a [path_search_max] override in run-full-validation.sh — see the pathfind.compute entry below). The workload README section 'Pathfinding is not exercised' carries the full restore recipe." + "note": "Fires on ripple_path_find / path_find RPC. Optional because the harness issues neither: rpc_load_generator.py's DEFAULT_WEIGHTS carries no ripple_path_find entry, and no workload-profiles.json phase names a path-finding command in a weights override, so no such RPC reaches a node at all. Created as an ambient (scoped) child inside the RPC command handler (RipplePathFind.cpp:35-36, PathFind.cpp:26-27), so its parent is the enclosing rpc.command.* span — RipplePathFind.cpp:30 states this explicitly. Note the span does NOT need pathfinding to be ENABLED, only the RPC to be issued: the ScopedSpanGuard is constructed at RipplePathFind.cpp:35, above the 'if (pathSearchMax == 0) return rpcError(RpcNotSupported)' guard at :48-49, so even a refused call opens and closes it. That positional accident means the load alone would satisfy this entry while pathfind.compute and pathfind.discover below stayed unasserted, and it is why such refusals would also drive a steady ~3% STATUS_CODE_ERROR floor in span_calls_total. Adding the load alone would make this span required and introduce that error floor; covering the whole family needs pathfinding actually enabled (a [path_search_max] override in run-full-validation.sh — see the pathfind.compute entry below). The workload README section 'Pathfinding is not exercised' carries the full recipe for enabling it." }, { "name": "pathfind.compute", @@ -449,7 +449,7 @@ "required_attributes": ["pathfind_fast"], "config_flag": "trace_rpc", "optional": true, - "note": "Created by PathRequest::doUpdate (PathRequest.cpp:749-750), which the harness never reaches: pathfinding is disabled on every harness node, so no PathRequest is ever constructed. Config.cpp:725-726 sets pathSearchMax to 0 when a [validation_seed] or [validator_token] section is present, run-full-validation.sh writes [validation_seed] for every node (:308) and has no [path_search*] override, and doRipplePathFind then returns rpcNOT_SUPPORTED at RipplePathFind.cpp:48-49 — above the request-construction branches and below the pathfind.request span guard at :35. Liquidity is not the reason and never was: the call is refused before any path search is attempted, so the outcome does not depend on what the ledger holds. Since 2026-08-25 there is a second, independent reason: the harness sends no path-finding RPC at all, the ripple_path_find weight having been removed from rpc_load_generator.py. Enabling this span therefore needs BOTH a [path_search_max] override (or a non-validator node) in run-full-validation.sh AND the load restored — see the workload README section 'Pathfinding is not exercised'." + "note": "Created by PathRequest::doUpdate (PathRequest.cpp:749-750), which the harness never reaches: pathfinding is disabled on every harness node, so no PathRequest is ever constructed. Config.cpp:725-726 sets pathSearchMax to 0 when a [validation_seed] or [validator_token] section is present, run-full-validation.sh writes [validation_seed] for every node (:308) and has no [path_search*] override, and doRipplePathFind then returns rpcNOT_SUPPORTED at RipplePathFind.cpp:48-49 — above the request-construction branches and below the pathfind.request span guard at :35. Liquidity is not the reason and never was: the call is refused before any path search is attempted, so the outcome does not depend on what the ledger holds. There is a second, independent reason: the harness sends no path-finding RPC at all, since rpc_load_generator.py carries no ripple_path_find weight. Enabling this span therefore needs BOTH a [path_search_max] override (or a non-validator node) in run-full-validation.sh AND the load restored — see the workload README section 'Pathfinding is not exercised'." }, { "name": "pathfind.discover", @@ -490,12 +490,12 @@ { "parent": "rpc.ws_message", "child": "rpc.command.*", - "description": "WebSocket message contains the per-command span — the real relationship on the harness WS path (rpc::doCommand at RPCHandler.cpp:271 creates an ambient child of the rpc.ws_message scope inside the same coroutine). Un-skipped 2026-08-26. The skip existed because _validate_parent_child() used to collapse the wildcard to one literal name via child_name.replace(\"*\", \"server_info\"), which made the check depend on which command the sampled traces happened to carry -- server_info is 25/100 of rpc_load_generator.py's DEFAULT_WEIGHTS, so a healthy run could sample three non-server_info traces and fail. That code no longer exists: d059f21bf3 replaced it with _span_name_matches(), which globs via fnmatch.fnmatchcase, and the check's own comment now reads \"globs for wildcard contracts\". Any rpc.command. under the parent therefore satisfies the contract and the command mix no longer matters. The reason had simply gone stale for two weeks." + "description": "WebSocket message contains the per-command span — the real relationship on the harness WS path (rpc::doCommand at RPCHandler.cpp:271 creates an ambient child of the rpc.ws_message scope inside the same coroutine). Not skipped, because the validator globs the wildcard child: _span_name_matches() matches via fnmatch.fnmatchcase, so any rpc.command. under the parent satisfies the contract and the command mix does not matter. A validator that instead collapsed the wildcard to one literal name -- child_name.replace(\"*\", \"server_info\") -- would make this check depend on which command the sampled traces happened to carry: server_info is 25/100 of rpc_load_generator.py's DEFAULT_WEIGHTS, so a healthy run could sample three non-server_info traces and fail." }, { "parent": "rpc.process", "child": "rpc.command.*", - "description": "Processing span contains the per-command span, on the HTTP/JSON-RPC path. Un-skipped 2026-08-26 for the same reason as the WebSocket pair above: the validator globs a wildcard child via _span_name_matches() and has done since d059f21bf3, so the 'resolves the wildcard to one literal probe' claim this entry carried was describing code deleted two weeks earlier. That claim was not inherited here by accident -- it was copied from the stale WS entry while correcting a DIFFERENT error in this same reason, without checking it. Both ends emit: rpc.process reports 5 traces on a normal run, not from the WebSocket-only load generator but because run-full-validation.sh polls each node's HTTP port with curl for readiness and validated-ledger progress (:449, :502), and every such request runs a command." + "description": "Processing span contains the per-command span, on the HTTP/JSON-RPC path. Not skipped, for the same reason as the WebSocket pair above: the validator globs a wildcard child via _span_name_matches(), so no single literal command has to be sampled. Both ends emit: rpc.process reports 5 traces on a normal run, not from the WebSocket-only load generator but because run-full-validation.sh polls each node's HTTP port with curl for readiness and validated-ledger progress (:449, :502), and every such request runs a command." }, { "parent": "ledger.build", @@ -517,7 +517,7 @@ "child": "pathfind.compute", "description": "Pathfind request contains the compute sub-span", "skip": true, - "skip_reason": "Real relationship (pathfind.compute is created inside PathRequest::doUpdate at PathRequest.cpp:749-750, under the pathfind.request scope), but the child never exists on the harness because pathfinding is disabled on every node: Config.cpp:725-726 zeroes pathSearchMax whenever a [validation_seed] or [validator_token] section is present, run-full-validation.sh writes [validation_seed] for all five nodes (:308) with no [path_search*] override, and doRipplePathFind returns rpcNOT_SUPPORTED at RipplePathFind.cpp:48-49 before constructing a PathRequest. The parent used to appear anyway, because its ScopedSpanGuard is created at RipplePathFind.cpp:35, above that guard; since 2026-08-25 not even the parent appears, the ripple_path_find load having been removed from rpc_load_generator.py, so both ends of this relationship are now absent. Liquidity has nothing to do with it — the earlier 'no liquidity, returns before computing' reason was wrong, because no path search is attempted at all. Asserting this relationship needs the load restored AND a [path_search_max] override (or a non-validator node) in run-full-validation.sh." + "skip_reason": "Real relationship (pathfind.compute is created inside PathRequest::doUpdate at PathRequest.cpp:749-750, under the pathfind.request scope), but the child never exists on the harness because pathfinding is disabled on every node: Config.cpp:725-726 zeroes pathSearchMax whenever a [validation_seed] or [validator_token] section is present, run-full-validation.sh writes [validation_seed] for all five nodes (:308) with no [path_search*] override, and doRipplePathFind returns rpcNOT_SUPPORTED at RipplePathFind.cpp:48-49 before constructing a PathRequest. The parent would appear anyway if the RPC were issued, because its ScopedSpanGuard is created at RipplePathFind.cpp:35, above that guard; but rpc_load_generator.py carries no ripple_path_find weight, so not even the parent appears and both ends of this relationship are absent. Liquidity has nothing to do with it — the earlier 'no liquidity, returns before computing' reason was wrong, because no path search is attempted at all. Asserting this relationship needs the load restored AND a [path_search_max] override (or a non-validator node) in run-full-validation.sh." }, { "parent": "ledger.acquire", @@ -540,15 +540,15 @@ "description": "The RPC command span contains the path-finding request span.", "skip": true, "skip_reason": "Real relationship, and the one skip here caused by a WILDCARD PARENT rather than by a missing span. _validate_parent_child builds its Tempo query as name=\"\" with the contract string inserted literally (validate_telemetry.py:801), so a parent of rpc.command.* searches for a span literally named that and finds nothing. Note the asymmetry: the ancestry check globs both sides through _span_name_matches, which is why rpc.ws_message -> rpc.command.* is asserted, but the Tempo query that selects the candidate traces is literal on the parent, so no trace is ever fetched to run it on. Asserting this needs the parent query to accept a glob -- a TraceQL name=~ regex, or resolving the glob to the concrete names Tempo reports first. Independently of that, both ends are absent today anyway: the harness issues no path-finding RPC, see the pathfind.compute entry above.", - "added": "2026-08-26 to close the declared-but-unlisted gap" + "added": "Closes the declared-but-unlisted gap" }, { "parent": "pathfind.compute", "child": "pathfind.discover", "description": "The path computation contains the discovery pass.", "skip": true, - "skip_reason": "Real relationship with BOTH ends absent, for the reason given in full on the pathfind.compute entry above: pathfinding is disabled on every harness node because Config.cpp:725-726 zeroes pathSearchMax whenever a [validation_seed] section is present, run-full-validation.sh writes one for all five nodes (:308) with no [path_search_max] override, so doRipplePathFind returns rpcNOT_SUPPORTED before any PathRequest is constructed -- and since 2026-08-25 the harness sends no path-finding RPC at all either. Asserting this needs both blockers lifted, which is a workload and node-config change rather than a harness one. Listed here so that the pathfinding family is fully accounted for rather than partly silent.", - "added": "2026-08-26 to close the declared-but-unlisted gap" + "skip_reason": "Real relationship with BOTH ends absent, for the reason given in full on the pathfind.compute entry above: pathfinding is disabled on every harness node because Config.cpp:725-726 zeroes pathSearchMax whenever a [validation_seed] section is present, run-full-validation.sh writes one for all five nodes (:308) with no [path_search_max] override, so doRipplePathFind returns rpcNOT_SUPPORTED before any PathRequest is constructed -- and the harness sends no path-finding RPC at all either. Asserting this needs both blockers lifted, which is a workload and node-config change rather than a harness one. Listed here so that the pathfinding family is fully accounted for rather than partly silent.", + "added": "Closes the declared-but-unlisted gap" }, { "parent": "rpc.http_request", @@ -570,12 +570,12 @@ "child": "txq.batch_clear", "description": "Queue admission contains the batch-clear pass that drops an account's superseded queued transactions.", "skip": true, - "skip_reason": "Real relationship, still skipped but for ONE reason now rather than two. The child never fires at all under this workload -- the run reports \"span.txq.batch_clear: optional span not emitted under this workload\" -- because it is created in TxQ::tryClearAccountQueueUpThruTx (TxQ.cpp:550), which needs one account holding several queued transactions AND an arriving transaction that supersedes the whole batch. Nothing in txq-burst arranges that shape. The second reason this entry used to carry, that newest-N parent sampling would miss it anyway, no longer applies: the hierarchy check now queries Tempo for traces containing both parent and child. So this is now purely a workload gap, and un-skipping it needs the workload to produce a supersedable batch -- nothing further from the validator." + "skip_reason": "Real relationship, skipped for one reason: the child never fires at all under this workload -- the run reports \"span.txq.batch_clear: optional span not emitted under this workload\" -- because it is created in TxQ::tryClearAccountQueueUpThruTx (TxQ.cpp:550), which needs one account holding several queued transactions AND an arriving transaction that supersedes the whole batch. Nothing in txq-burst arranges that shape. Sampling is not a second reason here: the hierarchy check queries Tempo for traces containing both parent and child, so it would find the pair wherever it occurred. This is purely a workload gap, and un-skipping it needs the workload to produce a supersedable batch -- nothing further from the validator." }, { "parent": "txq.accept", "child": "txq.accept_tx", - "description": "The queue's accept pass contains the per-transaction accept span. Un-skipped once the hierarchy check stopped sampling only the newest parent traces. The child is created inside the loop over queued transactions and behind `if (feeLevelPaid >= requiredFeeLevel)` (TxQ.cpp:1530), so it exists only for a close whose queue held a fee-clearing transaction, while the parent fires on every close (:1499) -- which is precisely the shape newest-N sampling gets wrong. The check now asks Tempo for traces containing both, so co-occurrence is found wherever it happened rather than only in the three most recent closes." + "description": "The queue's accept pass contains the per-transaction accept span. Not skipped, because the hierarchy check asks Tempo for traces containing both spans rather than sampling the newest parent traces. That matters here: the child is created inside the loop over queued transactions and behind `if (feeLevelPaid >= requiredFeeLevel)` (TxQ.cpp:1530), so it exists only for a close whose queue held a fee-clearing transaction, while the parent fires on every close (:1499) -- exactly the shape newest-N sampling gets wrong. Searching for co-occurrence finds it wherever it happened, not only in the most recent closes." }, { "parent": "consensus.round", diff --git a/docker/telemetry/workload/regression-metrics.json b/docker/telemetry/workload/regression-metrics.json index 4b07a17512..d53396e755 100644 --- a/docker/telemetry/workload/regression-metrics.json +++ b/docker/telemetry/workload/regression-metrics.json @@ -4,7 +4,7 @@ "_excluded_spans": "rpc.process is deliberately absent from spans.names. It is created only in ServerHandler::processRequest() on the HTTP/JSON-RPC path, which the workload load generators, being WebSocket-only, never reach, so its quantiles were captured as null every run and could never gate. (The harness shell scripts do issue a few HTTP JSON-RPC health polls, far too few to produce a meaningful quantile.) See baselines/README.md.", "_excluded_ledger_store": "ledger.store is deliberately absent from spans.names too, for a different reason: it is below the ladder's resolution. The 2026-08-24 capture returned p50/p95/p99 of exactly 0.005/0.0095/0.0099 ms, which is 0.5/0.95/0.99 x the ladder's first edge of 0.01 ms — the signature of every sample landing in the first bucket, so the numbers are interpolation arithmetic on the bucket floor rather than latencies. That is physically plausible: LedgerMaster.cpp:463 wraps an in-memory ledgerHistory_.insert, which completes in single-digit microseconds. While all mass stays under 10 us the reported quantile cannot move materially, so NO absolute bound can gate it — every ledger.store slowing from 2 us to 9 us, 4.5x, leaves the reported value unchanged. Three keys that read as covered but cannot fire are worse than no keys (the same argument that excluded rpc.process), so they were removed rather than left in with a bound that looks derived. Restoring the key needs sub-10us edges on the collector's spanmetrics ladder (for example 0.001ms and 0.005ms) plus the matching entries in HistogramBuckets.h — that is the ladder's branch, not this file. ledger.store presence is still asserted by expected_spans.json and docker/telemetry/integration-test.sh, and its rate is still on the ledger-operations dashboard; only the latency gate drops it.", "_excluded_quantiles": "A THIRD KIND OF EXCLUSION, and the only one that deleting a name cannot express. spans.names lists span NAMES while _quantiles is shared across all of them, so the declared surface is the names x quantiles product and dropping ONE quantile of ONE span needs a subtraction. excluded_keys below is that subtraction: a flat {category}.{name}.p{quantile} key, exactly as _key_format defines it, mapped to the reason it is not gated. It can only ever remove a key, never add one, so a typo cannot silently start gating something new -- and check_regression_bounds.py rule F rejects an entry that would not otherwise be declared, an entry with an empty reason, and an entry that still carries a threshold override or a baseline value, so the exclusion cannot rot into dead config. Both prom_queries.py (which builds the capture plan) and check_regression_bounds.py (rule A) subtract it, so an excluded key is not queried, never reaches timings.json, and is not expected in the baseline. NOTHING ELSE CHANGES: the quantile is still computable from Prometheus with the _query_template above, the span is still asserted by expected_spans.json, and its rate is still on the ledger-operations dashboard. Only the latency gate drops it.", - "_excluded_shape": "ALL FIVE ENTRIES BELOW SHARE ONE SHAPE, and it is worth naming because it will recur: the observed maximum across CI runs exceeds (baseline + bound), so an ordinary run clears the trip point with nothing having regressed. Two mechanisms produce that, and both are visible here. (1) A baseline that lands in the ladder's LOW buckets gets a tiny derived bound, because the bound IS the distance to the next edge up -- span.tx.apply.p50 at 0.0060 ms sits in the first bucket (0, 0.01] and gets 0.0440 ms of headroom, against a metric that has been measured at 2.3378 ms. (2) A spread so large that no bucket of headroom could absorb it -- span.ledger.validate.p99's 66.8x range reaches 25.8750 ms against a 10 ms trip point even though its bound is a comparatively generous 8.94 ms. The first mechanism is the one that bit three keys on the 2026-08-26 refresh, and it is a property of WHERE THE CAPTURED RUN LANDED rather than of the metric: the same span.tx.apply.p50 read 0.7917 ms in the previous baseline, mid-distribution, where the identical rule produced a 4.21 ms bound that absorbed the whole range. Whether the gate functioned was therefore decided by luck of the draw. THE FOLLOW-UP THAT WOULD RESTORE COVERAGE, stated so it is not left implied: a baseline captured from a SINGLE run cannot support these keys, because one sample carries no information about spread and the bound is derived from that one sample alone. What would let them be gated again is a multi-run baseline -- or a spread measurement captured alongside the baseline, so a bound can be sized against observed variance instead of against the ladder only. That is not implemented; it is the design change these five exclusions are waiting on. Until then, do NOT re-gate any of them by re-baselining until a run happens to land favourably, which is the failure this note exists to prevent.", + "_excluded_shape": "ALL FIVE ENTRIES BELOW SHARE ONE SHAPE, and it is worth naming because it will recur: the observed maximum across CI runs exceeds (baseline + bound), so an ordinary run clears the trip point with nothing having regressed. Two mechanisms produce that, and both are visible here. (1) A baseline that lands in the ladder's LOW buckets gets a tiny derived bound, because the bound IS the distance to the next edge up -- span.tx.apply.p50 at 0.0060 ms sits in the first bucket (0, 0.01] and gets 0.0440 ms of headroom, against a metric that has been measured at 2.3378 ms. (2) A spread so large that no bucket of headroom could absorb it -- span.ledger.validate.p99's 66.8x range reaches 25.8750 ms against a 10 ms trip point even though its bound is a comparatively generous 8.94 ms. The first mechanism is the one that excludes three keys here, and it is a property of WHERE THE CAPTURED RUN LANDED rather than of the metric: the same span.tx.apply.p50 has read 0.7917 ms, mid-distribution, where the identical rule produces a 4.21 ms bound that absorbs the whole range. Whether the gate functioned was therefore decided by luck of the draw. THE FOLLOW-UP THAT WOULD RESTORE COVERAGE, stated so it is not left implied: a baseline captured from a SINGLE run cannot support these keys, because one sample carries no information about spread and the bound is derived from that one sample alone. What would let them be gated again is a multi-run baseline -- or a spread measurement captured alongside the baseline, so a bound can be sized against observed variance instead of against the ladder only. That is not implemented; it is the design change these five exclusions are waiting on. Until then, do NOT re-gate any of them by re-baselining until a run happens to land favourably, which is the failure this note exists to prevent.", "excluded_keys": { "span.consensus.ledger_close.p50": "Run-to-run variance exceeds the bound this ladder can derive, the same limit as the ledger.validate pair and the same mechanism as the two sibling p50 keys excluded alongside it. Baseline 0.0387 ms sits in the low bucket (0.01, 0.05], so hi_next is 0.1 ms and the derived bound is 0.0613 ms -- a 2.58x trip point. Measured across three CI runs the value spans 0.0387 to 0.2377 ms, a 6.1x spread (5.9x over four runs), and run 32867433073 read 0.2377 ms, 2.38x the trip point, on the SAME post-path-finding-removal workload as this baseline. So a healthy run reddens CI. This is a variance limit, not a defect and not a missing bound: widening is unavailable, because a bound tolerating 0.2377 ms would reach past the 0.25 ms edge and gate almost nothing. Do NOT re-gate by widening, and do NOT re-baseline until a run lands higher -- see _excluded_shape.", "span.ledger.build.p50": "The same mechanism as span.consensus.ledger_close.p50, one bucket up. Baseline 0.1151 ms sits in (0.1, 0.25], so hi_next is 0.5 ms and the bound is 0.3849 ms -- a 4.34x trip point. Across three CI runs the value spans 0.1151 to 2.3826 ms, a 20.7x spread (25.3x over four runs), and the observed maximum is 4.77x the trip point. Note what the previous baseline hid: at 1.0612 ms the same rule gave a 8.94 ms bound and a 10 ms trip point, which absorbed the entire range, so this key read as gated purely because that capture landed mid-distribution. Ledger construction is the hot path this gate most wants to guard, which makes the loss real and worth fixing properly -- with a baseline that carries spread information, not with a wider bound.", diff --git a/docker/telemetry/workload/regression-thresholds.json b/docker/telemetry/workload/regression-thresholds.json index b31fa1cf71..ff50363116 100644 --- a/docker/telemetry/workload/regression-thresholds.json +++ b/docker/telemetry/workload/regression-thresholds.json @@ -1,9 +1,9 @@ { "_description": "Per-metric regression thresholds. A metric regresses when current - baseline exceeds BOTH the percentage and absolute bounds (AND, not OR \u2014 this tolerates small-value noise). Defaults apply unless a per-metric override exists.", - "_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). Second-scale consensus spans have 2s/3s/4s boundaries, so their quantiles quantize to ~1s widths there \u2014 the ladder is NOT uniformly 2x-or-coarser, which matters for _percentage_bound_note. The native job_queue histograms are microsecond-valued on the ladder [1,2,5,10,25,50,100,250,500,1000,5000,25000,100000,500000]us then [1,5,10,30,60]s (19 edges; include/xrpl/telemetry/HistogramBuckets.h is authoritative). NOTE: BOTH ladders were re-cut, and a baseline captured before its own ladder changed is an interpolation artefact, not a latency. The job_queue floor moved 100us \u2192 1us. The span ladder was re-cut on 2026-08-04 in 3860c93db2, moving the floor 1ms \u2192 0.01ms; so any sub-millisecond span quantile captured before that date is equally void \u2014 a p95 reading 0.95ms is 0.95 \u00d7 the old 1ms first edge, not a measurement. An earlier note asserted that the surviving span baselines were unaffected by the ladder work; that is wrong for every span quantile below 1ms. Only the band from 1ms to 1s is safe: those edges are byte-identical across the two ladders. The re-cut also ADDED edges above 1s (2s/3s/4s/10s/30s), so a span whose quantiles land in the second-scale range \u2014 consensus.round ~3.9s, consensus.establish ~1.9s, the ledger.acquire tail \u2014 is distorted just as much, and any pre-2026-08-04 baseline for it is equally void. Do not read this note as licensing a stale second-scale baseline.", - "_absolute_bound_derivation": "HOW EVERY max_abs_increase_* NUMBER BELOW WAS OBTAINED. Rule: locate the baseline value in the half-open bucket (lo, hi] of its own ladder, take hi_next = the next edge above hi, and set the bound to (hi_next - baseline). The trip point is therefore exactly hi_next: the gate fires only when the reported value EXCEEDS the top of the bucket above the baseline's own bucket. WHY THAT AND NOT A MULTIPLE OF THE BUCKET WIDTH: histogram_quantile returns a value interpolated inside whichever bucket the true quantile falls in, so a reading taken while the true quantile sits anywhere in the baseline's bucket OR anywhere in the one immediately above is at most hi_next and cannot fire. Firing requires the true quantile to have moved at least two buckets up. A multiple of the ENCLOSING width cannot deliver that, because once the quantile crosses hi the interpolation happens across the NEXT bucket, which on this ladder is up to 8x wider \u2014 (0.5,1] has width 0.5 and (1,5] has width 4 \u2014 so the reading's excursion is not bounded by any multiple of the enclosing width. Worked example: span.tx.process.p99 has baseline 2.7588ms in bucket (1, 5], hi_next = 10, so its bound is 7.2412ms and the gate fires only above 10ms. Bounds are stored as exact doubles rather than rounded figures so that rounding cannot break the guarantee and so check_regression_bounds.py can assert each one against the ladder to within a 1e-12 relative tolerance -- tight enough that a bound rounded for readability, such as 7.2412 for 7.241212121212123, is rejected; _derivation_table below shows the arithmetic for each one. Measured over the committed baseline this rule yields a detection floor of 2.21x to 16.28x of baseline, per key. WHAT THIS RULE DOES NOT COVER, AND THE ONE CHECK TO RUN BEFORE GATING ANY KEY: hi_next - baseline is derived from the LADDER, so it budgets for QUANTIZATION noise -- one bucket of interpolation headroom -- and for nothing else. It knows nothing about how much the metric itself moves between runs on identical code. Where run-to-run workload variance is the larger term the bound is simply the wrong size, and the gate reddens on a healthy run. So before adding a key here, capture it over several runs and check its OBSERVED MAXIMUM against its trip point (baseline + bound); gate it only if the observed maximum stays below that trip point with margin. Spread on its own proves nothing -- it is spread RELATIVE TO THE TRIP POINT that decides, and a baseline that lands at the LOW end of a metric's own range shrinks that trip point even though nothing about the metric changed. THREE KEYS FAILED THIS TEST ON THE 2026-08-26 BASELINE AND ARE NOW EXCLUDED, all of them p50: span.tx.apply.p50 (bound 0.0440ms, trips at 0.05ms, observed max 2.3378ms = 46.76x its trip point), span.ledger.build.p50 (bound 0.3849ms, trips at 0.5ms, observed max 2.3826ms = 4.77x) and span.consensus.ledger_close.p50 (bound 0.0613ms, trips at 0.1ms, observed max 0.2377ms = 2.38x). Their spreads across three runs are 391.8x, 20.7x and 6.1x. This is the general rule above being APPLIED, not a new exception: a key is gateable only when its run-to-run spread fits inside its bound, and these three do not. The evidence that settles it is span.tx.apply.p50's own history -- it read 0.7917ms in the previous baseline and 0.00597ms in this one, a 132x difference between two runs of the SAME workload. At the old value the identical rule produced a 4.21ms bound whose 5ms trip point absorbed the whole range; at the new one it produces 0.0440ms and cannot. Whether the gate functioned was therefore decided by where in its distribution the captured run happened to land, which is not a threshold needing tuning but a key that cannot be gated from a single-run baseline at all. Before the exclusion, replaying the two preceding CI runs 32862589645 and 32867433073 against this baseline reported exactly those three and nothing else on BOTH runs, and 32867433073 carries the same post-path-finding-removal workload as the baseline itself -- so the movement was metric variance, not a workload difference. After it, both runs replay clean. The remaining 20 keys sit at or below 0.58 of their trip points, the worst being span.consensus.accept.p50. See _excluded_shape in regression-metrics.json for what all five excluded keys have in common and for the multi-run-baseline work that would let them be gated again. A key that fails this test is not fixed by widening its bound: see excluded_keys in regression-metrics.json. WHAT THIS REPLACED, IN TWO GENERATIONS: (1) a single flat pair of bounds (10ms for span p50/p95, 15ms for span p99, 20000us for job_queue p95) justified as 'roughly two bucket widths in the 5-25ms band where most span quantiles actually sit'. The 2026-08-24 capture falsifies that premise \u2014 18 of the 28 quantiles gated at that time sat below 1ms \u2014 so the absolute bound sat 1.15x to 2000x above the metric it guarded and, because the rule is an AND, the percentage bound could never carry a regression on its own; a 10x regression injected into each key in turn was caught on only 5 of 28, and a 100x regression injected into span.ledger.store.p95 produced 0 regressions and exit 0. (2) a first correction to 2 \u00d7 the ENCLOSING bucket width, which caught 10x on 28 of 28 but placed the trip point INSIDE the adjacent bucket -- and so left a single-crossing false positive reachable -- on 21 of the 25 keys gated at the time, 4 of them tripping on a tail-mass shift under 1.5% of samples. That is the assumption this rule removes. RE-DERIVE THESE NUMBERS whenever baseline-timings.json is refreshed or either ladder changes: a refreshed baseline can land in a different bucket, which changes hi_next. .github/scripts/telemetry/check_regression_bounds.py enforces the rule in CI so a stale bound cannot survive a baseline refresh. LIMITATION \u2014 WHICH KEYS ARE ONLY WEAKLY GUARDED: the guarantee costs sensitivity wherever the ladder is coarse, and the detection floor is hi_next/baseline, so a baseline sitting just above an edge is guarded loosely. job.acceptLedger.running.p95 (baseline 6142.86us, fires at 100000us, 16.28x) is NOT meaningfully guarded, and it is now the one key a 10x regression does NOT catch: measured, 10x reaches 61429us and passes, and the gate first fires at 16.28x. It sits just above the 5000us edge while hi_next is 100000us, two steps up. Its floor moved there in this refresh, from 5.74x, because its baseline fell 17428.57us to 6142.86us while hi_next stayed at 100000us -- it does NOT fire on any observed run, so it stays gated, but the weak floor is recorded here so it is visible rather than surprising. span.consensus.accept.p50 (9.46x), job.transaction.running.p95 (8.33x), span.tx.process.p95 (8.20x), span.rpc.ws_message.p95 (7.17x), span.consensus.ledger_close.p95 (6.39x) and span.rpc.ws_message.p99 (5.12x) are also weak. Four of the seven are limited by the 1ms\u21925ms step; the rest by 1000us\u21925000us (job.transaction.running.p95) and 25000us\u2192100000us (job.acceptLedger.running.p95). The fix is a 2ms edge (and ideally 3ms) in the collector's spanmetrics ladder plus the matching edges in kMillisecondBuckets, and 2000us plus 50000us edges in kMicrosecondBuckets \u2014 that work belongs to the branch that owns the ladders, not here. Until then do not read these keys as guarded. span.ledger.store is absent from the overrides below because it was removed from the gated surface entirely: its quantiles were the ladder floor times the quantile, so no bound could gate it. See _excluded_ledger_store in regression-metrics.json.", - "_percentage_bound_note": "For every key gated today the absolute bound is the binding half of the AND and the percentage bound never decides the outcome: measured, (bound / baseline) ranges from 121% (span.ledger.build.p95) to 1528% (job.acceptLedger.running.p95), all above the 50% and 5% percentage bounds configured here, and the minimum trip multiple of all 20 keys is set by the absolute bound. THIS IS NOT A GENERAL GUARANTEE, and an earlier version of this note wrongly claimed it was, on the false premise that 'every step of both ladders is at least a factor of 2'. The span ladder breaks that three times at the top: 2s->3s is 1.5x, 3s->4s is 1.33x, 4s->5s is 1.25x, so second-scale consensus quantiles quantize to ~1s widths there. Because the bound is (hi_next - baseline), a baseline between about 2667ms and 3000ms, or between about 3334ms and 4000ms, gets an absolute bound worth less than 50% of itself and the PERCENTAGE bound becomes the operative one -- at which point the metric fires on a 50% move that is smaller than one bucket width, and the single-crossing guarantee in _absolute_bound_derivation is lost. That band is not hypothetical: the collector config names consensus.round (~3.9s) as a reason those edges exist, and 3900ms sits in the second sub-band with an absolute bound of 5000 - 3900 = 1100, only 28.2% of baseline. Whoever gates a key whose baseline lands in either sub-band MUST lower its max_pct_increase below (bound / baseline) for that key, or state explicitly that the metric is percentage-gated and the bucket guarantee does not hold for it. check_regression_bounds.py enforces this as rule D so the trap cannot be walked into silently. The percentage entries are required and still meaningful regardless: compare_to_baseline.py treats a missing max_pct_increase as 'no threshold configured' and would stop gating the metric entirely; they record the intended relative tolerance (consensus spans 5%, everything else 50%); and they are the operative bound on the defaults path (see _defaults_note).", - "_defaults_note": "A MISSING OVERRIDE IS DETECTED BY CI, NOT BY THESE DEFAULTS. .github/scripts/telemetry/check_regression_bounds.py fails the build at lint time, naming the key and the exact value its bound should have, before the workload ever runs. That is the mechanism; the defaults below are only a runtime backstop for the case where that check is bypassed. The defaults carry the FLOOR of each ladder as their absolute bound \u2014 0.01ms for spans, 1us for job_queue \u2014 deliberately too small to bind for any real metric, which leaves max_pct_increase (50%) as the operative bound on this path. Measured: a metric with no override and a baseline of 3900ms passes at +49% and fires at +51%; a job metric with a baseline of 5000us behaves the same. The backstop is honestly imperfect and the earlier version of this note oversold it. At 50% relative it CAN false-fire: a metric whose baseline is 1.06ms inside the 4ms-wide (1,5] bucket fires on a single-bucket-width move (measured: 1.06 \u2192 5.06ms, +377%, regressed). An earlier note called that 'the intended signal that the override is missing', which was wrong \u2014 CI prints REGRESSION and a reader cannot tell it from a real one, and rejecting a tighter alternative for exactly that cries-wolf risk while shipping it here would be inconsistent. The check is what makes the signal legible. The backstop is kept only because a metric silently not gated at all is the worse of the two failures.", + "_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). Second-scale consensus spans have 2s/3s/4s boundaries, so their quantiles quantize to ~1s widths there \u2014 the ladder is NOT uniformly 2x-or-coarser, which matters for _percentage_bound_note. The native job_queue histograms are microsecond-valued on the ladder [1,2,5,10,25,50,100,250,500,1000,5000,25000,100000,500000]us then [1,5,10,30,60]s (19 edges; include/xrpl/telemetry/HistogramBuckets.h is authoritative). NOTE: BOTH ladders were re-cut, and a baseline captured before its own ladder changed is an interpolation artefact, not a latency. The job_queue floor moved 100us \u2192 1us. The span floor is 0.01ms; a span baseline captured against a 1ms floor is void below 1ms \u2014 a p95 reading 0.95ms there is 0.95 \u00d7 that 1ms first edge, not a measurement. Do not assume a surviving span baseline is unaffected by ladder work: every span quantile below 1ms is affected. Only the band from 1ms to 1s is safe: those edges are byte-identical across the two ladders. The re-cut also ADDED edges above 1s (2s/3s/4s/10s/30s), so a span whose quantiles land in the second-scale range \u2014 consensus.round ~3.9s, consensus.establish ~1.9s, the ledger.acquire tail \u2014 is distorted just as much, and any pre-2026-08-04 baseline for it is equally void. Do not read this note as licensing a stale second-scale baseline.", + "_absolute_bound_derivation": "HOW EVERY max_abs_increase_* NUMBER BELOW WAS OBTAINED. Rule: locate the baseline value in the half-open bucket (lo, hi] of its own ladder, take hi_next = the next edge above hi, and set the bound to (hi_next - baseline). The trip point is therefore exactly hi_next: the gate fires only when the reported value EXCEEDS the top of the bucket above the baseline's own bucket. WHY THAT AND NOT A MULTIPLE OF THE BUCKET WIDTH: histogram_quantile returns a value interpolated inside whichever bucket the true quantile falls in, so a reading taken while the true quantile sits anywhere in the baseline's bucket OR anywhere in the one immediately above is at most hi_next and cannot fire. Firing requires the true quantile to have moved at least two buckets up. A multiple of the ENCLOSING width cannot deliver that, because once the quantile crosses hi the interpolation happens across the NEXT bucket, which on this ladder is up to 8x wider \u2014 (0.5,1] has width 0.5 and (1,5] has width 4 \u2014 so the reading's excursion is not bounded by any multiple of the enclosing width. Worked example: span.tx.process.p99 has baseline 2.7588ms in bucket (1, 5], hi_next = 10, so its bound is 7.2412ms and the gate fires only above 10ms. Bounds are stored as exact doubles rather than rounded figures so that rounding cannot break the guarantee and so check_regression_bounds.py can assert each one against the ladder to within a 1e-12 relative tolerance -- tight enough that a bound rounded for readability, such as 7.2412 for 7.241212121212123, is rejected; _derivation_table below shows the arithmetic for each one. Measured over the committed baseline this rule yields a detection floor of 2.21x to 16.28x of baseline, per key. WHAT THIS RULE DOES NOT COVER, AND THE ONE CHECK TO RUN BEFORE GATING ANY KEY: hi_next - baseline is derived from the LADDER, so it budgets for QUANTIZATION noise -- one bucket of interpolation headroom -- and for nothing else. It knows nothing about how much the metric itself moves between runs on identical code. Where run-to-run workload variance is the larger term the bound is simply the wrong size, and the gate reddens on a healthy run. So before adding a key here, capture it over several runs and check its OBSERVED MAXIMUM against its trip point (baseline + bound); gate it only if the observed maximum stays below that trip point with margin. Spread on its own proves nothing -- it is spread RELATIVE TO THE TRIP POINT that decides, and a baseline that lands at the LOW end of a metric's own range shrinks that trip point even though nothing about the metric changed. THREE KEYS FAILED THIS TEST ON THE 2026-08-26 BASELINE AND ARE NOW EXCLUDED, all of them p50: span.tx.apply.p50 (bound 0.0440ms, trips at 0.05ms, observed max 2.3378ms = 46.76x its trip point), span.ledger.build.p50 (bound 0.3849ms, trips at 0.5ms, observed max 2.3826ms = 4.77x) and span.consensus.ledger_close.p50 (bound 0.0613ms, trips at 0.1ms, observed max 0.2377ms = 2.38x). Their spreads across three runs are 391.8x, 20.7x and 6.1x. This is the general rule above being APPLIED, not a new exception: a key is gateable only when its run-to-run spread fits inside its bound, and these three do not. The evidence that settles it is span.tx.apply.p50's own history -- it read 0.7917ms in the previous baseline and 0.00597ms in this one, a 132x difference between two runs of the SAME workload. At the old value the identical rule produced a 4.21ms bound whose 5ms trip point absorbed the whole range; at the new one it produces 0.0440ms and cannot. Whether the gate functioned was therefore decided by where in its distribution the captured run happened to land, which is not a threshold needing tuning but a key that cannot be gated from a single-run baseline at all. Before the exclusion, replaying the two preceding CI runs 32862589645 and 32867433073 against this baseline reported exactly those three and nothing else on BOTH runs, and 32867433073 carries the same post-path-finding-removal workload as the baseline itself -- so the movement was metric variance, not a workload difference. After it, both runs replay clean. The remaining 20 keys sit at or below 0.58 of their trip points, the worst being span.consensus.accept.p50. See _excluded_shape in regression-metrics.json for what all five excluded keys have in common and for the multi-run-baseline work that would let them be gated again. A key that fails this test is not fixed by widening its bound: see excluded_keys in regression-metrics.json. WHAT THIS REPLACED, IN TWO GENERATIONS: (1) a single flat pair of bounds (10ms for span p50/p95, 15ms for span p99, 20000us for job_queue p95) justified as 'roughly two bucket widths in the 5-25ms band where most span quantiles actually sit'. The 2026-08-24 capture falsifies that premise \u2014 18 of the 28 quantiles gated at that time sat below 1ms \u2014 so the absolute bound sat 1.15x to 2000x above the metric it guarded and, because the rule is an AND, the percentage bound could never carry a regression on its own; a 10x regression injected into each key in turn was caught on only 5 of 28, and a 100x regression injected into span.ledger.store.p95 produced 0 regressions and exit 0. (2) a first correction to 2 \u00d7 the ENCLOSING bucket width, which caught 10x on 28 of 28 but placed the trip point INSIDE the adjacent bucket -- and so left a single-crossing false positive reachable -- on 21 of the 25 keys gated at the time, 4 of them tripping on a tail-mass shift under 1.5% of samples. That is the assumption this rule removes. RE-DERIVE THESE NUMBERS whenever baseline-timings.json is refreshed or either ladder changes: a refreshed baseline can land in a different bucket, which changes hi_next. .github/scripts/telemetry/check_regression_bounds.py enforces the rule in CI so a stale bound cannot survive a baseline refresh. LIMITATION \u2014 WHICH KEYS ARE ONLY WEAKLY GUARDED: the guarantee costs sensitivity wherever the ladder is coarse, and the detection floor is hi_next/baseline, so a baseline sitting just above an edge is guarded loosely. job.acceptLedger.running.p95 (baseline 6142.86us, fires at 100000us, 16.28x) is NOT meaningfully guarded, and it is now the one key a 10x regression does NOT catch: measured, 10x reaches 61429us and passes, and the gate first fires at 16.28x. It sits just above the 5000us edge while hi_next is 100000us, two steps up. Its floor moved there in this refresh, from 5.74x, because its baseline fell 17428.57us to 6142.86us while hi_next stayed at 100000us -- it does NOT fire on any observed run, so it stays gated, but the weak floor is recorded here so it is visible rather than surprising. span.consensus.accept.p50 (9.46x), job.transaction.running.p95 (8.33x), span.tx.process.p95 (8.20x), span.rpc.ws_message.p95 (7.17x), span.consensus.ledger_close.p95 (6.39x) and span.rpc.ws_message.p99 (5.12x) are also weak. Four of the seven are limited by the 1ms\u21925ms step; the rest by 1000us\u21925000us (job.transaction.running.p95) and 25000us\u2192100000us (job.acceptLedger.running.p95). The fix is a 2ms edge (and ideally 3ms) in the collector's spanmetrics ladder plus the matching edges in kMillisecondBuckets, and 2000us plus 50000us edges in kMicrosecondBuckets \u2014 that work belongs to the branch that owns the ladders, not here. Until then do not read these keys as guarded. span.ledger.store is absent from the overrides below because it is excluded from the gated surface entirely: its quantiles are the ladder floor times the quantile, so no bound can gate it. See _excluded_ledger_store in regression-metrics.json.", + "_percentage_bound_note": "For every key gated today the absolute bound is the binding half of the AND and the percentage bound never decides the outcome: measured, (bound / baseline) ranges from 121% (span.ledger.build.p95) to 1528% (job.acceptLedger.running.p95), all above the 50% and 5% percentage bounds configured here, and the minimum trip multiple of all 20 keys is set by the absolute bound. THIS IS NOT A GENERAL GUARANTEE. Do not reason from 'every step of both ladders is at least a factor of 2' -- that premise is false. The span ladder breaks it three times at the top: 2s->3s is 1.5x, 3s->4s is 1.33x, 4s->5s is 1.25x, so second-scale consensus quantiles quantize to ~1s widths there. Because the bound is (hi_next - baseline), a baseline between about 2667ms and 3000ms, or between about 3334ms and 4000ms, gets an absolute bound worth less than 50% of itself and the PERCENTAGE bound becomes the operative one -- at which point the metric fires on a 50% move that is smaller than one bucket width, and the single-crossing guarantee in _absolute_bound_derivation is lost. That band is not hypothetical: the collector config names consensus.round (~3.9s) as a reason those edges exist, and 3900ms sits in the second sub-band with an absolute bound of 5000 - 3900 = 1100, only 28.2% of baseline. Whoever gates a key whose baseline lands in either sub-band MUST lower its max_pct_increase below (bound / baseline) for that key, or state explicitly that the metric is percentage-gated and the bucket guarantee does not hold for it. check_regression_bounds.py enforces this as rule D so the trap cannot be walked into silently. The percentage entries are required and still meaningful regardless: compare_to_baseline.py treats a missing max_pct_increase as 'no threshold configured' and would stop gating the metric entirely; they record the intended relative tolerance (consensus spans 5%, everything else 50%); and they are the operative bound on the defaults path (see _defaults_note).", + "_defaults_note": "A MISSING OVERRIDE IS DETECTED BY CI, NOT BY THESE DEFAULTS. .github/scripts/telemetry/check_regression_bounds.py fails the build at lint time, naming the key and the exact value its bound should have, before the workload ever runs. That is the mechanism; the defaults below are only a runtime backstop for the case where that check is bypassed. The defaults carry the FLOOR of each ladder as their absolute bound \u2014 0.01ms for spans, 1us for job_queue \u2014 deliberately too small to bind for any real metric, which leaves max_pct_increase (50%) as the operative bound on this path. Measured: a metric with no override and a baseline of 3900ms passes at +49% and fires at +51%; a job metric with a baseline of 5000us behaves the same. The backstop is honestly imperfect and should not be oversold. At 50% relative it CAN false-fire: a metric whose baseline is 1.06ms inside the 4ms-wide (1,5] bucket fires on a single-bucket-width move (measured: 1.06 \u2192 5.06ms, +377%, regressed). That false fire is NOT to be read as 'the intended signal that the override is missing' \u2014 CI prints REGRESSION and a reader cannot tell it from a real one, and rejecting a tighter alternative for exactly that cries-wolf risk while shipping it here would be inconsistent. The check is what makes the signal legible. The backstop is kept only because a metric silently not gated at all is the worse of the two failures.", "_derivation_table": { "_format": "override key: in -> hi_next - baseline = ", "job.acceptLedger.queued": "p95 166.13636363636323 in (100,250] -> hi_next 500 - baseline = 333.8636363636368", diff --git a/docker/telemetry/workload/run-full-validation.sh b/docker/telemetry/workload/run-full-validation.sh index a9b90c647f..f3c399440c 100755 --- a/docker/telemetry/workload/run-full-validation.sh +++ b/docker/telemetry/workload/run-full-validation.sh @@ -964,7 +964,7 @@ fold_exit "$VALIDATION_EXIT" # were never measured. The messages below say incomplete, never missing. # # That thin file also says so itself, in the "capture" block capture_timings.py -# writes into it, so the CAPTURE_EXIT below is no longer the only record of the +# writes into it, so the CAPTURE_EXIT below is not the only record of the # capture's health: both paste-me paths read the flag and withhold the JSON # rather than offering an artifact this run has already called unusable. # @@ -972,7 +972,7 @@ fold_exit "$VALIDATION_EXIT" # exploration), and with it out of the gate's verdict: a capture failure is # reported loudly and shown in the step-status table, but does not fail a run # whose caller asked not to be gated. With the gate active, a capture failure is -# an infrastructure error (exit 2) exactly as before. +# an infrastructure error (exit 2). # # When the comparison does run it either prints the paste-me JSON for a # placeholder baseline, or enforces thresholds and fails the run on regression. diff --git a/docker/telemetry/workload/tx_submitter.py b/docker/telemetry/workload/tx_submitter.py index da9b2659ca..807c44a702 100644 --- a/docker/telemetry/workload/tx_submitter.py +++ b/docker/telemetry/workload/tx_submitter.py @@ -787,10 +787,10 @@ async def submit_transaction( if not success: # First occurrence of each distinct result at WARNING, the rest at - # DEBUG. A run where every transaction failed previously produced - # no diagnostics at all, because DEBUG is off in CI; logging every - # failure instead would bury the run in thousands of identical - # lines. + # DEBUG. DEBUG is off in CI, so a run where every transaction fails + # would otherwise produce no diagnostics at all; logging every + # failure at WARNING instead would bury the run in thousands of + # identical lines. _log_first_failure( "result:%s" % engine_result, "%s result: %s (%s)", diff --git a/docker/telemetry/workload/workload_orchestrator.py b/docker/telemetry/workload/workload_orchestrator.py index f17a33eef5..35ca4ded55 100755 --- a/docker/telemetry/workload/workload_orchestrator.py +++ b/docker/telemetry/workload/workload_orchestrator.py @@ -59,7 +59,7 @@ PROFILES_FILE = SCRIPT_DIR / "workload-profiles.json" # trips) and then waits a fixed 10s for those funding transactions to # validate, and both generators drain in-flight requests while shutting down. # A generator that outruns this is killed and the phase records the timeout as -# an error, so one wedged process can no longer stall the whole profile. +# an error, so one wedged process cannot stall the whole profile. SUBPROCESS_GRACE_SEC = 90.0 # How long to keep reading a killed process's output before giving up on it. diff --git a/docker/telemetry/xrpld-telemetry.cfg b/docker/telemetry/xrpld-telemetry.cfg index 325e195b95..76800019a7 100644 --- a/docker/telemetry/xrpld-telemetry.cfg +++ b/docker/telemetry/xrpld-telemetry.cfg @@ -121,7 +121,7 @@ endpoint=http://localhost:4318/v1/metrics [telemetry] enabled=1 service_instance_id=xrpld-devnet -endpoint=http://localhost:4318/v1/traces +traces_endpoint=http://localhost:4318/v1/traces metrics_endpoint=http://localhost:4318/v1/metrics batch_size=512 batch_delay_ms=5000 diff --git a/docs/telemetry-runbook.md b/docs/telemetry-runbook.md index 959048f755..541f974a9e 100644 --- a/docs/telemetry-runbook.md +++ b/docs/telemetry-runbook.md @@ -76,7 +76,7 @@ Add to your `xrpld.cfg`: ```ini [telemetry] enabled=1 -endpoint=http://localhost:4318/v1/traces +traces_endpoint=http://localhost:4318/v1/traces ``` ### 3. Build with telemetry support @@ -129,7 +129,7 @@ curl -s http://localhost:5015 -d '{"method":"server_info"}' | | Option | Default | Description | | -------------------------- | --------------------------------- | ------------------------------------------------------------ | | `enabled` | `0` | Master switch for telemetry | -| `endpoint` | `http://localhost:4318/v1/traces` | OTLP/HTTP endpoint | +| `traces_endpoint` | `http://localhost:4318/v1/traces` | OTLP/HTTP endpoint | | `service_name` | `xrpld` | OpenTelemetry service name resource attribute | | `service_instance_id` | node public key | OpenTelemetry service instance ID resource attribute | | `trace_rpc` | `1` | Enable RPC request tracing | @@ -1569,6 +1569,8 @@ The OTel Collector's spanmetrics connector automatically derives RED (Rate, Erro ### Generated Metric Names +These names are deliberately generic: the connector emits **one** metric family covering every span, not a metric per span. Which span a series belongs to comes from the `span_name` label, and the rest of the breakdown from the `dimensions` list in `otel-collector-config.yaml`. So a query always names the span in a label selector rather than in the metric name — `span_calls_total{span_name="ledger.build"}`, never a `ledger_build_calls_total`. + | Prometheus Metric | Type | Description | | ----------------------------------- | --------- | ---------------------------- | | `span_calls_total` | Counter | Total span invocations | @@ -1576,6 +1578,19 @@ The OTel Collector's spanmetrics connector automatically derives RED (Rate, Erro | `span_duration_milliseconds_count` | Histogram | Latency observation count | | `span_duration_milliseconds_sum` | Histogram | Cumulative latency | +Only one part of those names is ours to choose. Reading a name left to right: + +| Part | Set by | +| ------------------------------------- | ------------------------------------------------------------------------------------ | +| `span_` | the connector's `namespace: "span"` in `otel-collector-config.yaml` — **our choice** | +| `calls`, `duration` | the spanmetrics connector's own metric names | +| `_milliseconds` | the Prometheus exporter, expanding the metric's declared unit | +| `_total`, `_bucket`, `_count`, `_sum` | Prometheus conventions for counters and histograms | + +`_milliseconds` rather than `_ms` is therefore not a style decision taken here. The config declares the histogram in milliseconds (`buckets: [1ms, 5ms, ...]`) and never contains the string `milliseconds`; the exporter writes the unit out in full when it translates OTLP to Prometheus. Shortening it would mean renaming the series after export, which would break every dashboard and leave the exported name and the queried name disagreeing. + +Drop the `namespace` setting and these become `traces_span_metrics_*` instead — the connector's default. Any query, dashboard panel or test that names one of these metrics has to move with that setting. + ### Metric Labels Every metric carries these standard labels: @@ -3264,7 +3279,7 @@ Then read the answer off the pair: | Expensive | Depth over ~1.2 | **Both paths queueing.** Rarer, and neither fix on its own will be enough. Treat the larger of the two costs as the lead. | **Why the rule is shaped this way.** Three points about the thresholds, each -learned from a dataset that an earlier version of this table got wrong: +grounded in a measured dataset rather than a round number: - **Read cost is a relative judgement, so the band has a floor and a ceiling, not one cut.** A cold read on our box measured 31.8 µs mean; a cold read on the @@ -4773,23 +4788,23 @@ Key properties: the limiting ladder step for each, and the edges that would fix them. - **A baseline refresh can silently move sensitivity in either direction.** The trip point is derived from the baseline, so a refresh that lands at the low end - of a metric's range tightens the gate and one that lands high loosens it. The - 2026-08-26 refresh took `job.acceptLedger.running.p95` from a 5.74x floor to - 16.28x — it does not fire on any observed run, so it stays gated, but the weak - floor is recorded rather than left to surprise someone. The same refresh put - three `p50` keys below the spread they need, and they are now excluded (below). - `baselines/README.md` carries the measurements. + of a metric's range tightens the gate and one that lands high loosens it. + `job.acceptLedger.running.p95` has been measured with a 5.74x detection floor + on one baseline and 16.28x on another — it does not fire on any observed run, + so it stays gated, but the weak floor is recorded rather than left to surprise + someone. The same effect puts three `p50` keys below the spread they need, and + those are excluded (below). `baselines/README.md` carries the measurements. - **The bound covers quantization noise only, so a key whose run-to-run variance exceeds it cannot be gated. Five keys are excluded for that reason**, leaving 20 gated. `span.ledger.validate.p95` and `.p99` came first — spreads of 5.9x and 66.8x across four CI runs, both reaching past their trip points on healthy runs, because the span's duration follows peer-validation arrival timing rather - than code speed. The 2026-08-26 refresh added `span.tx.apply.p50`, - `span.ledger.build.p50` and `span.consensus.ledger_close.p50`, whose observed - maxima sit 46.76x, 4.77x and 2.38x above their new trip points. That is the - same rule applied, not a new exception: the decisive evidence is that - `span.tx.apply.p50` read 0.7917 ms in the previous baseline and 0.00597 ms in - this one — 132x apart on the same workload — so whether the gate worked was + than code speed. `span.tx.apply.p50`, `span.ledger.build.p50` and + `span.consensus.ledger_close.p50` join them on this baseline, with observed + maxima 46.76x, 4.77x and 2.38x above their trip points. That is the same rule + applied, not a new exception: the decisive evidence is that + `span.tx.apply.p50` has read 0.7917 ms and 0.00597 ms on the same workload + — 132x apart — so whether the gate worked was decided by where in its own distribution the captured run fell, not by the code. All five share one shape: the observed maximum exceeds `baseline + bound`, four of them because a low-bucket baseline yields a tiny diff --git a/include/xrpl/beast/insight/Collector.h b/include/xrpl/beast/insight/Collector.h index c4ba20e3f4..e95d805cc2 100644 --- a/include/xrpl/beast/insight/Collector.h +++ b/include/xrpl/beast/insight/Collector.h @@ -116,9 +116,8 @@ public: * @param unit What the samples measure. */ virtual Event - makeEvent(std::string const& name, Unit unit) + makeEvent(std::string const& name, [[maybe_unused]] Unit unit) { - (void)unit; return makeEvent(name); } @@ -130,7 +129,7 @@ public: return makeEvent(prefix + "." + name); } - Event + [[nodiscard]] Event makeEvent(std::string const& prefix, std::string const& name, Unit unit) { if (prefix.empty()) diff --git a/include/xrpl/beast/insight/OTelCollector.h b/include/xrpl/beast/insight/OTelCollector.h index 46d103dc90..ffa3fe5072 100644 --- a/include/xrpl/beast/insight/OTelCollector.h +++ b/include/xrpl/beast/insight/OTelCollector.h @@ -39,14 +39,27 @@ #include #include +#include namespace beast::insight { +/** + * Instrumentation scope this collector fetches its Meter under. + * + * Must equal xrpl::telemetry::kMeterName and kMeterVersion, or instruments land + * on a different scope than the views. Duplicated because beast sits below the + * telemetry module and cannot include its header; Telemetry.cpp static_asserts + * the two agree. + */ +inline constexpr std::string_view kOTelMeterName{"xrpld"}; +inline constexpr std::string_view kOTelMeterVersion{"1.0.0"}; + /** * @brief A Collector that exports metrics via OpenTelemetry OTLP/HTTP. * - * Replaces StatsD-based metric collection with native OTel Metrics SDK - * instruments. Each beast::insight instrument maps to an OTel equivalent: + * Selected by `[insight] server=otel`, as an alternative to StatsDCollector: + * it exports through the native OTel Metrics SDK rather than the StatsD wire + * format. Each beast::insight instrument maps to an OTel equivalent: * * - Counter -> OTel Counter * - Gauge -> OTel ObservableGauge (async callback) @@ -126,7 +139,7 @@ public: * @param journal Journal for logging. * @return Shared pointer to the created Collector. */ - static std::shared_ptr + [[nodiscard]] static std::shared_ptr // NOLINTNEXTLINE(readability-identifier-naming) New(std::string const& endpoint, std::string const& prefix, diff --git a/include/xrpl/beast/insight/Unit.h b/include/xrpl/beast/insight/Unit.h index cd9c863d1e..5697155ec5 100644 --- a/include/xrpl/beast/insight/Unit.h +++ b/include/xrpl/beast/insight/Unit.h @@ -7,24 +7,24 @@ 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: + * `Event` carries "a millisecond time, or other integral value", so the unit + * cannot be inferred from the sample. Naming it 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. + * Without an explicit unit every instrument declares `ms`, so a size metric + * exports under a `_milliseconds` name and inherits a latency bucket ladder. + * For RPC response sizes that ladder censors about a quarter of the samples + * and pins the p95 to a constant. + * + * The StatsD backend deliberately ignores this and emits `|ms` for every + * Event. That path is out of service -- 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 an external protocol + * 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 @@ -53,7 +53,7 @@ enum class Unit : std::uint8_t { * @param unit The unit to translate. * @return A static, null-terminated UCUM code. */ -constexpr char const* +[[nodiscard]] constexpr char const* otelUnitCode(Unit unit) noexcept { switch (unit) @@ -78,7 +78,7 @@ otelUnitCode(Unit unit) noexcept * @param unit The unit to describe. * @return A static, null-terminated description. */ -constexpr char const* +[[nodiscard]] constexpr char const* otelUnitDescription(Unit unit) noexcept { switch (unit) diff --git a/include/xrpl/consensus/Consensus.h b/include/xrpl/consensus/Consensus.h index 78750656a4..aced7555ea 100644 --- a/include/xrpl/consensus/Consensus.h +++ b/include/xrpl/consensus/Consensus.h @@ -1689,8 +1689,9 @@ Consensus::updateOurPositions(std::unique_ptr const& // NOLINTBEGIN(bugprone-unchecked-optional-access) assert above using namespace telemetry; // Child of the establish span via its captured context (establishSpan_ is - // a thread-free SpanGuard, so parent explicitly via its context). Null - // context (establish not started) yields a null guard, same as before. + // a thread-free SpanGuard, so parent explicitly via its context). A null + // context — the establish phase has not started — yields a null guard, so + // the setAttribute calls below are no-ops. auto span = SpanGuard::childSpan(consensus::span::updatePositions, establishSpanContext_); span.setAttribute( consensus::span::attr::convergePercent, static_cast(convergePercent_)); diff --git a/include/xrpl/consensus/ConsensusSpanLabels.h b/include/xrpl/consensus/ConsensusSpanLabels.h index cc66639c41..21b867d128 100644 --- a/include/xrpl/consensus/ConsensusSpanLabels.h +++ b/include/xrpl/consensus/ConsensusSpanLabels.h @@ -3,10 +3,11 @@ /** * Enum-to-label mappings for consensus span attribute values. * - * Split from ConsensusSpanNames.h so that header stays dependency-free like - * its siblings: the span-name and attribute-key constants are included by - * overlay and app translation units that have no use for the consensus - * enums, while these mappings are needed only by Consensus.h. + * These mappings live in their own header so ConsensusSpanNames.h stays + * dependency-free like its siblings: the span-name and attribute-key + * constants are included by overlay and app translation units that have no + * use for the consensus enums, while these mappings are needed only by + * Consensus.h. * * ConsensusSpanNames.h (constants only, no domain deps) * ^ diff --git a/include/xrpl/consensus/ConsensusSpanNames.h b/include/xrpl/consensus/ConsensusSpanNames.h index 897df7c662..d9ff5aab7a 100644 --- a/include/xrpl/consensus/ConsensusSpanNames.h +++ b/include/xrpl/consensus/ConsensusSpanNames.h @@ -59,10 +59,10 @@ * | | * | +-- consensus.accept.apply [jtACCEPT thread, child of accept] * | Created: Adaptor::doAccept() - * | Attrs: ledger_seq, close_time, close_time_correct, + * | Attrs: ledger_seq, close_time_ripple_epoch_s, close_time_correct, * | close_resolution_ms, consensus_state, proposing, round_time_ms, - * | parent_close_time, close_time_self, close_time_vote_bins, - * | resolution_direction, tx_count + * | parent_close_time_ripple_epoch_s, close_time_self_ripple_epoch_s, + * | close_time_vote_bins, resolution_direction, tx_count * | Events: tx.included (per tx, attrs: tx_id) * | * +~~~ consensus.validation.send [jtACCEPT thread, linked] @@ -169,8 +169,8 @@ namespace attr { * concept, same key, distinguished by span name (not an emitter prefix). */ using ::xrpl::telemetry::attr::closeResolutionMs; -using ::xrpl::telemetry::attr::closeTime; using ::xrpl::telemetry::attr::closeTimeCorrect; +using ::xrpl::telemetry::attr::closeTimeRippleEpochS; using ::xrpl::telemetry::attr::fullValidation; using ::xrpl::telemetry::attr::ledgerHash; using ::xrpl::telemetry::attr::ledgerSeq; @@ -276,8 +276,20 @@ inline constexpr auto positionHashPrefix = makeStr("position_hash_prefix"); * "consensus_state" — domain-qualified (collides with other domains' state). */ inline constexpr auto consensusState = makeStr("consensus_state"); -inline constexpr auto parentCloseTime = makeStr("parent_close_time"); -inline constexpr auto closeTimeSelf = makeStr("close_time_self"); +/** + * Close-time instants, both NetClock readings in whole seconds since the XRP + * Ledger epoch (2000-01-01T00:00:00Z) — see `closeTimeRippleEpochS` in + * SpanNames.h for why the epoch is spelled into the key. + * + * `parentCloseTimeRippleEpochS` is the previous ledger's close time; + * `closeTimeSelfRippleEpochS` is this node's own close-time vote for the round, + * so the pair shows how far the node's position sat from the ledger it built on. + * + * `closeTimeVoteBins` is not a time: it holds the number of distinct close-time + * positions seen from peers this round. + */ +inline constexpr auto parentCloseTimeRippleEpochS = makeStr("parent_close_time_ripple_epoch_s"); +inline constexpr auto closeTimeSelfRippleEpochS = makeStr("close_time_self_ripple_epoch_s"); inline constexpr auto closeTimeVoteBins = makeStr("close_time_vote_bins"); inline constexpr auto resolutionDirection = makeStr("resolution_direction"); inline constexpr auto convergePercent = makeStr("converge_percent"); @@ -319,6 +331,14 @@ inline constexpr auto disputesCount = makeStr("disputes_count"); */ inline constexpr auto proposalTrusted = makeStr("proposal_trusted"); inline constexpr auto validationTrusted = makeStr("validation_trusted"); + +/** + * "validation_status" — which exit the inbound validation took. Set once per + * exit, so a dropped validation (microseconds) is separable from a queued one + * (job wait plus checkValidation). Without it the span name reports two + * unrelated latency distributions and every quantile over it is meaningless. + */ +inline constexpr auto validationStatus = makeStr("validation_status"); } // namespace attr // ===== Event names =========================================================== @@ -402,6 +422,10 @@ inline constexpr auto closeAnomaly = makeStr("anomaly"); inline constexpr auto closeOthersClosed = makeStr("others_closed"); inline constexpr auto closeIdle = makeStr("idle"); inline constexpr auto closeNormal = makeStr("normal"); +// validation_status values, one per exit of the inbound validation path. +inline constexpr auto validationQueued = makeStr("queued"); +inline constexpr auto validationDroppedDiverged = makeStr("dropped_diverged"); +inline constexpr auto validationDroppedLoad = makeStr("dropped_load"); } // namespace val // ===== Value rules =========================================================== diff --git a/include/xrpl/telemetry/HistogramBuckets.h b/include/xrpl/telemetry/HistogramBuckets.h index 6a00417961..73dac9c2c7 100644 --- a/include/xrpl/telemetry/HistogramBuckets.h +++ b/include/xrpl/telemetry/HistogramBuckets.h @@ -11,10 +11,8 @@ 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. + * One header owns every ladder, so a reviewer sees all of them together and + * a test can assert their invariants. * * 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 @@ -68,11 +66,10 @@ namespace xrpl::telemetry::buckets { * **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. + * histogram panel be read on the same scale. Drop an edge the collector + * carries and every quantile above it reads back as the top edge instead of + * failing. `check_bucket_parity.py` 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 @@ -82,12 +79,12 @@ namespace xrpl::telemetry::buckets { * * 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. + * averaging about 60 s, so a 30 s ceiling would censor its quantiles. 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. + * The 2, 3 and 4 s edges resolve second-scale work, which a single + * four-second-wide bucket can only interpolate across. */ inline constexpr std::array kMillisecondBuckets{ 1.0, @@ -209,7 +206,7 @@ inline constexpr std::array * @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 +[[nodiscard]] constexpr bool isAscendingNonNegative(std::span ladder) noexcept { if (ladder.empty() || ladder.front() < 0.0) @@ -235,7 +232,7 @@ static_assert(isAscendingNonNegative(kChargeBuckets)); * @param ladder Bucket upper bounds. * @return A vector holding the same edges in the same order. */ -inline std::vector +[[nodiscard]] inline std::vector toVector(std::span ladder) { return std::vector(ladder.begin(), ladder.end()); diff --git a/include/xrpl/telemetry/Recording.h b/include/xrpl/telemetry/Recording.h index 9c8f8bfac1..12a8d8203c 100644 --- a/include/xrpl/telemetry/Recording.h +++ b/include/xrpl/telemetry/Recording.h @@ -6,12 +6,12 @@ * Each type below holds real state when telemetry is compiled in and is an * empty type with no-op methods when it is not. The member is declared in * both configurations, so a class's member set and public API never differ - * between builds -- a difference that has previously made a test mock - * abstract. The compiled-out forms are empty types, so such a member costs a - * byte of padding rather than nothing. `[[no_unique_address]]` would remove - * even that, but MSVC ignores the standard spelling for ABI compatibility, so - * it is deliberately not used. What these types buy is work not being done, - * not a smaller struct. + * between builds -- a difference that leaves a test mock complete in one + * configuration and abstract in the other, where it then fails to compile. + * The compiled-out forms are empty types, so such a member costs a byte of + * padding rather than nothing. `[[no_unique_address]]` would remove even that, but MSVC ignores + * the standard spelling for ABI compatibility, so it is deliberately not + * used. What these types buy is work not being done, not a smaller struct. * * kEnabled ---- if constexpr ---- telemetry-only blocks * | @@ -176,12 +176,10 @@ public: * @param n How much to add; defaults to 1. */ void - add(T const n = 1) noexcept + add([[maybe_unused]] T const n = 1) noexcept { #ifdef XRPL_ENABLE_TELEMETRY value_.fetch_add(n, std::memory_order_relaxed); -#else - (void)n; #endif } diff --git a/include/xrpl/telemetry/SpanGuard.h b/include/xrpl/telemetry/SpanGuard.h index 95c471f677..9ccfcca607 100644 --- a/include/xrpl/telemetry/SpanGuard.h +++ b/include/xrpl/telemetry/SpanGuard.h @@ -410,8 +410,10 @@ public: * follows-from link. Use to stitch sequential * top-level spans (e.g. consecutive consensus * rounds). Ignored if nullptr or invalid. + * @return An active guard, or a null guard when the category is + * disabled or hashSize is under 16. */ - static SpanGuard + [[nodiscard]] static SpanGuard hashSpan( TraceCategory const cat, std::string_view const name, @@ -431,8 +433,10 @@ public: * @param parentSpanId Pointer to 8 bytes of parent span ID. * @param parentSpanSize Size of parent span ID buffer (must be 8). * @param traceFlags Trace flags from remote context. + * @return An active guard, or a null guard when the category is + * disabled, hashSize is under 16, or parentSpanSize is not 8. */ - static SpanGuard + [[nodiscard]] static SpanGuard hashSpan( TraceCategory const cat, std::string_view const name, diff --git a/include/xrpl/telemetry/SpanNames.h b/include/xrpl/telemetry/SpanNames.h index d9f2fb0f0b..d0fc7791b9 100644 --- a/include/xrpl/telemetry/SpanNames.h +++ b/include/xrpl/telemetry/SpanNames.h @@ -144,8 +144,19 @@ inline constexpr auto ledgerSeq = makeStr("ledger_seq"); /** * Shared close-time attrs — bare names, reused by consensus and ledger. + * + * `closeTimeRippleEpochS` carries a NetClock reading: whole seconds since the + * XRP Ledger epoch (2000-01-01T00:00:00Z), never the Unix epoch. The key names + * both the unit and the epoch because neither is recoverable from the value. + * A consumer rendering it as wall-clock time must first add kEpochOffset + * (946684800 seconds, see basics/chrono.h); read as a Unix timestamp instead, + * it lands roughly 30 years early. + * + * `closeResolutionMs` is a duration, not an instant — the granularity the + * close time is rounded to. NetClock resolution is whole seconds, so this + * value is always a multiple of 1000. */ -inline constexpr auto closeTime = makeStr("close_time"); +inline constexpr auto closeTimeRippleEpochS = makeStr("close_time_ripple_epoch_s"); inline constexpr auto closeTimeCorrect = makeStr("close_time_correct"); inline constexpr auto closeResolutionMs = makeStr("close_resolution_ms"); /** diff --git a/include/xrpl/telemetry/Telemetry.h b/include/xrpl/telemetry/Telemetry.h index bb95298c98..f808d65f7b 100644 --- a/include/xrpl/telemetry/Telemetry.h +++ b/include/xrpl/telemetry/Telemetry.h @@ -149,7 +149,7 @@ public: * Get the global Telemetry instance. * @return Pointer to the active instance, or nullptr if not started. */ - static Telemetry* + [[nodiscard]] static Telemetry* getInstance() { return instance.load(std::memory_order_acquire); @@ -205,9 +205,10 @@ public: std::string nodeId; /** - * OTLP/HTTP endpoint URL where spans are sent. + * Full OTLP/HTTP URL where spans are sent, including the signal path. + * Used verbatim: no other endpoint is derived from it. */ - std::string exporterEndpoint = "http://localhost:4318/v1/traces"; + std::string tracesEndpoint = "http://localhost:4318/v1/traces"; /** * Whether to use TLS for the exporter connection. @@ -318,10 +319,9 @@ public: * @param id The node's base58-encoded public key or custom identifier. */ virtual void - setServiceInstanceId(std::string const& id) + setServiceInstanceId([[maybe_unused]] std::string const& id) { // Default no-op for NullTelemetry implementations. - (void)id; } /** @@ -336,10 +336,9 @@ public: * @param id The node's base58-encoded public key. */ virtual void - setNodeId(std::string const& id) + setNodeId([[maybe_unused]] std::string const& id) { // Default no-op for NullTelemetry implementations. - (void)id; } /** @@ -405,7 +404,7 @@ public: * @param name Tracer name used to identify the instrumentation library. * @return A shared pointer to the Tracer. */ - virtual opentelemetry::nostd::shared_ptr + [[nodiscard]] virtual opentelemetry::nostd::shared_ptr getTracer(std::string_view name = kTracerName) = 0; /** @@ -420,7 +419,7 @@ public: * @param name Meter name used to identify the instrumentation scope. * @return A shared pointer to the Meter. */ - virtual opentelemetry::nostd::shared_ptr + [[nodiscard]] virtual opentelemetry::nostd::shared_ptr getMeter(std::string_view name = kMeterName) = 0; /** @@ -438,7 +437,7 @@ public: * - kConsumer: async message receive * @return A shared pointer to the new Span. */ - virtual opentelemetry::nostd::shared_ptr + [[nodiscard]] virtual opentelemetry::nostd::shared_ptr startSpan( std::string_view name, opentelemetry::trace::SpanKind kind = opentelemetry::trace::SpanKind::kInternal) = 0; @@ -454,7 +453,7 @@ public: * @param kind The span kind (defaults to kInternal). * @return A shared pointer to the new Span. */ - virtual opentelemetry::nostd::shared_ptr + [[nodiscard]] virtual opentelemetry::nostd::shared_ptr startSpan( std::string_view name, opentelemetry::context::Context const& parentContext, @@ -513,7 +512,7 @@ makeTelemetrySetup( * @param networkId The network identifier from [network_id] config. * @return "mainnet" (0), "testnet" (1), "devnet" (2), or "unknown". */ -std::string +[[nodiscard]] std::string networkTypeFromId(std::uint32_t networkId); } // namespace xrpl::telemetry diff --git a/include/xrpl/telemetry/TraceContextPropagator.h b/include/xrpl/telemetry/TraceContextPropagator.h index d2282665a3..9deec892cd 100644 --- a/include/xrpl/telemetry/TraceContextPropagator.h +++ b/include/xrpl/telemetry/TraceContextPropagator.h @@ -43,7 +43,7 @@ namespace xrpl::telemetry { * @return An OTel Context with the extracted parent span, or an empty * context if the protobuf fields are missing or invalid. */ -inline opentelemetry::context::Context +[[nodiscard]] inline opentelemetry::context::Context extractFromProtobuf(protocol::TraceContext const& proto) { namespace trace = opentelemetry::trace; diff --git a/include/xrpl/telemetry/TraceContextValidation.h b/include/xrpl/telemetry/TraceContextValidation.h index e69b2d17ca..c299ba6cf9 100644 --- a/include/xrpl/telemetry/TraceContextValidation.h +++ b/include/xrpl/telemetry/TraceContextValidation.h @@ -57,7 +57,7 @@ namespace xrpl::telemetry { * @param traceId The raw trace_id bytes from a protobuf TraceContext. * @return true if usable as a trace identifier, false otherwise. */ -inline bool +[[nodiscard]] inline bool isValidTraceId(std::string const& traceId) { return traceId.size() == 16 && std::ranges::any_of(traceId, [](char c) { return c != 0; }); @@ -69,7 +69,7 @@ isValidTraceId(std::string const& traceId) * @param spanId The raw span_id bytes from a protobuf TraceContext. * @return true if usable as a span identifier, false otherwise. */ -inline bool +[[nodiscard]] inline bool isValidSpanId(std::string const& spanId) { return spanId.size() == 8 && std::ranges::any_of(spanId, [](char c) { return c != 0; }); @@ -86,7 +86,7 @@ isValidSpanId(std::string const& spanId) * @param tc The protobuf TraceContext received from a peer. * @return true if both ids are present and valid, false otherwise. */ -inline bool +[[nodiscard]] inline bool isValidTraceContext(protocol::TraceContext const& tc) { return tc.has_trace_id() && isValidTraceId(tc.trace_id()) && tc.has_span_id() && diff --git a/src/libxrpl/beast/insight/OTelCollector.cpp b/src/libxrpl/beast/insight/OTelCollector.cpp index 1d12dd0422..3f898bcc57 100644 --- a/src/libxrpl/beast/insight/OTelCollector.cpp +++ b/src/libxrpl/beast/insight/OTelCollector.cpp @@ -4,10 +4,9 @@ * * Compiled only when XRPL_ENABLE_TELEMETRY is defined (via CMake * telemetry=ON). Maps beast::insight instruments to OTel SDK instruments - * created on the GLOBAL Meter published by the telemetry module. This class - * is an adapter only: it owns no export pipeline. The MeterProvider, - * PeriodicExportingMetricReader, OTLP exporter and histogram view all live in - * xrpl::telemetry::Telemetry. + * created on the GLOBAL Meter published by the telemetry module. It owns no + * export pipeline of its own: the MeterProvider, PeriodicExportingMetricReader, + * OTLP exporter and histogram view all live in xrpl::telemetry::Telemetry. * * When XRPL_ENABLE_TELEMETRY is not defined, OTelCollector::New() returns * a NullCollector so the build succeeds without OTel dependencies. @@ -43,6 +42,7 @@ #include #include #include +#include #include #include @@ -61,9 +61,12 @@ #include #include #include +#include #include #include +#include #include +#include #include #include @@ -175,11 +178,10 @@ private: * 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. + * ladder. The edges themselves live in xrpl/telemetry/HistogramBuckets.h, + * which is their single owner -- do not restate them here. An edge list copied + * into a comment reads as authoritative and goes stale the moment the + * collector's SpanMetrics ladder is extended, with nothing to flag the drift. * * Thread safety: OTel Histogram::Record() is thread-safe by specification. */ @@ -271,7 +273,7 @@ public: * @brief Return the current gauge value for the OTel callback. * @return The most recently set/incremented value. */ - int64_t + [[nodiscard]] int64_t currentValue() const; OTelGaugeImpl& @@ -284,10 +286,13 @@ public: gaugeCallback(opentelemetry::metrics::ObserverResult result, void* state); /** - * Create the observable instrument and register the callback, once. + * Create the observable instrument and register the callback. * * Called when the collector is told collection is ready, because the * callback reads live application state. + * + * Idempotent. Arming twice would register the callback twice, so callers + * need not check; onCollectionReady() iterates a snapshot and may re-arm. */ void arm(); @@ -379,7 +384,7 @@ private: //------------------------------------------------------------------------------ /** - * @brief Main OTel Collector implementation (adapter over the global Meter). + * @brief Main OTel Collector implementation. * * Obtains its Meter from the GLOBAL MeterProvider owned and published by the * telemetry module (xrpl::telemetry::Telemetry), rather than building its own @@ -388,7 +393,7 @@ private: * * The metrics pipeline (MeterProvider + PeriodicExportingMetricReader + OTLP * HTTP exporter + histogram view) lives in the telemetry module. This class is - * a thin adapter kept for beast::insight callers during deprecation. + * the thin adapter that lets beast::insight callers reach it. * * Class diagram: * @@ -444,14 +449,12 @@ public: /** * @brief Construct the OTel collector over the global MeterProvider. * - * @param endpoint OTLP/HTTP metrics endpoint URL, recorded in the - * collector's startup log line. Export uses the - * endpoint configured on the global telemetry - * pipeline. - * @param prefix Label for the collector's startup log line - * (e.g. "xrpld"). Exported metric names come from - * formatName(); the service is identified by the - * service.name resource attribute. + * @param endpoint OTLP/HTTP metrics endpoint URL. Informational only: + * the global telemetry pipeline is authoritative for + * the actual export endpoint. Used only in the startup + * log line. + * @param prefix Metric-name prefix. Not applied to metric names; + * used only in the startup log line. * @param instanceId Value for the service.instance.id resource attribute. * When empty, the attribute is omitted. * @param serviceName Value for the service.name resource attribute. @@ -555,7 +558,7 @@ public: * @brief The shared Meter, for gauges creating their instrument in arm(). * @return The Meter this collector resolved at construction. */ - opentelemetry::nostd::shared_ptr const& + [[nodiscard]] opentelemetry::nostd::shared_ptr const& otelMeter() const; /** @@ -570,8 +573,8 @@ public: * @param name Raw metric name from beast::insight callers. * @return Fully-qualified metric name. */ - static std::string - formatName(std::string const& name); + [[nodiscard]] static std::string + formatName(std::string_view name); private: /** @@ -655,8 +658,10 @@ OTelCounterImpl::OTelCounterImpl( void OTelCounterImpl::increment(value_type amount) { - // OTel counters require non-negative values. beast::insight CounterImpl - // uses int64_t, so clamp negative values to 0 and cast to uint64_t. + // OTel counters take unsigned deltas only. Assert to catch a decrementing + // caller; skip the Add so a release build under-counts instead of wrapping. + XRPL_ASSERT( + amount >= 0, "beast::insight::detail::OTelCounterImpl::increment : non-negative amount"); if (amount > 0) counter_->Add(static_cast(amount)); } @@ -743,20 +748,25 @@ OTelGaugeImpl::~OTelGaugeImpl() void OTelGaugeImpl::set(value_type value) { - value_.store(static_cast(value), std::memory_order_relaxed); + // value_type is uint64_t, the gauge reports int64_t. Clamp instead of + // wrapping to a negative, which increment() would then floor to 0. + constexpr auto kMax = static_cast(std::numeric_limits::max()); + value_.store(static_cast(std::min(value, kMax)), std::memory_order_relaxed); } void OTelGaugeImpl::increment(difference_type amount) { - // Use compare-exchange loop to safely clamp to [0, MAX]. + // Saturate in [0, INT64_MAX]. Signed overflow is UB, so check the headroom + // before adding. A negative amount cannot underflow: current is never + // negative, so the lowest sum is 0 + INT64_MIN. + constexpr auto kMax = std::numeric_limits::max(); int64_t current = value_.load(std::memory_order_relaxed); int64_t desired = 0; do { - desired = current + amount; - // Clamp to 0 on underflow. - desired = std::max(desired, int64_t{0}); + desired = + (amount > 0 && current > kMax - amount) ? kMax : std::max(current + amount, int64_t{0}); } while (!value_.compare_exchange_weak(current, desired, std::memory_order_relaxed)); } @@ -790,23 +800,19 @@ OTelMeterImpl::increment(value_type amount) OTelCollectorImp::OTelCollectorImp( std::string const& endpoint, std::string prefix, - std::string const& instanceId, - std::string const& serviceName, - std::string const& networkType, + // instanceId/serviceName/networkType are accepted so the New() signature + // stays uniform for callers, but they are not read here: the telemetry + // module owns the resource attributes for the shared metrics pipeline. + [[maybe_unused]] std::string const& instanceId, + [[maybe_unused]] std::string const& serviceName, + [[maybe_unused]] std::string const& networkType, Journal journal) : journal_(journal), prefix_(std::move(prefix)) { - // instanceId/serviceName/networkType are accepted but unused here: the - // telemetry module owns the resource attributes for the shared metrics - // pipeline, so setting them from this collector would have no effect. - (void)instanceId; - (void)serviceName; - (void)networkType; - if (journal_.info()) { - // endpoint is logged for diagnostics only: the global telemetry - // pipeline owns the exporter that actually sends the metrics. + // endpoint is informational: the global telemetry pipeline owns the + // real exporter. It is logged here purely as a startup diagnostic. journal_.info() << "OTelCollector starting: endpoint=" << endpoint << " prefix=" << prefix_; } @@ -815,14 +821,10 @@ OTelCollectorImp::OTelCollectorImp( // periodic reader, histogram view, resource attributes) and registers it // via metrics::Provider::SetMeterProvider() during start(). beast metrics // ride that shared pipeline, so both direct-API and beast-sourced metrics - // export under one resource identity. - // - // The name/version literals MUST match the telemetry module's kMeterName - // ("xrpld") and kMeterVersion ("1.0.0"). They are written as literals (not - // referenced from Telemetry.h) because beast/insight sits below the - // telemetry module in the layering and cannot include its header. + // export under one resource identity. The scope must match the telemetry + // module's; see kOTelMeterName in the header. otelMeter_ = metrics_api::Provider::GetMeterProvider()->GetMeter( - std::string{"xrpld"}, std::string{"1.0.0"}); + std::string{kOTelMeterName}, std::string{kOTelMeterVersion}); if (journal_.info()) { @@ -832,12 +834,8 @@ OTelCollectorImp::OTelCollectorImp( OTelCollectorImp::~OTelCollectorImp() { - if (journal_.info()) - { - journal_.info() << "OTelCollector shutting down"; - } - // No pipeline teardown here: the telemetry module owns the global - // MeterProvider lifecycle (ForceFlush/Shutdown happen in Telemetry::stop()). + // Nothing to tear down: the telemetry module owns the global MeterProvider, + // so ForceFlush and Shutdown happen in Telemetry::stop(). if (journal_.info()) { journal_.info() << "OTelCollector stopped"; @@ -1003,25 +1001,16 @@ OTelCollectorImp::otelMeter() const } std::string -OTelCollectorImp::formatName(std::string const& name) +OTelCollectorImp::formatName(std::string_view name) { - // Produce a lowercase, Prometheus-compatible metric name: dots and - // spaces become underscores. Service identity travels in the - // service.name resource attribute, not in the metric name. - std::string result; - result.reserve(name.size()); - for (char const c : name) - { - if (c == '.' || c == ' ') - { - result += '_'; - } - else - { - result += static_cast(std::tolower(static_cast(c))); - } - } - return result; + // Lowercase, with '.' and ' ' mapped to '_'. No prefix: the service.name + // resource attribute identifies the service. + return name | std::views::transform([](char c) { + return (c == '.' || c == ' ') + ? '_' + : static_cast(std::tolower(static_cast(c))); + }) | + std::ranges::to(); } } // namespace detail diff --git a/src/libxrpl/beast/insight/StatsDCollector.cpp b/src/libxrpl/beast/insight/StatsDCollector.cpp index bc2640ca77..55d8c48e86 100644 --- a/src/libxrpl/beast/insight/StatsDCollector.cpp +++ b/src/libxrpl/beast/insight/StatsDCollector.cpp @@ -167,6 +167,9 @@ private: std::string name_; GaugeImpl::value_type lastValue_{0}; GaugeImpl::value_type value_{0}; + // Start dirty so the initial value (0) is emitted on the first flush. + // Without this, gauges whose value never changes from 0 would never + // appear in downstream metric stores (e.g. Prometheus via StatsD). bool dirty_{true}; }; @@ -599,9 +602,6 @@ StatsDEventImpl::doNotify(EventImpl::value_type const& value) StatsDGaugeImpl::StatsDGaugeImpl(std::string name, std::shared_ptr impl) : impl_(std::move(impl)), name_(std::move(name)) { - // Start dirty so the initial value (0) is emitted on the first flush. - // Without this, gauges whose value never changes from 0 would never - // appear in downstream metric stores (e.g. Prometheus via StatsD). impl_->add(*this); } diff --git a/src/libxrpl/telemetry/NullTelemetry.cpp b/src/libxrpl/telemetry/NullTelemetry.cpp index baa418b19a..e0f00ab3bf 100644 --- a/src/libxrpl/telemetry/NullTelemetry.cpp +++ b/src/libxrpl/telemetry/NullTelemetry.cpp @@ -116,7 +116,7 @@ public: } #ifdef XRPL_ENABLE_TELEMETRY - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr getTracer(std::string_view) override { static auto noopTracer = opentelemetry::nostd::shared_ptr( @@ -124,14 +124,14 @@ public: return noopTracer; } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr startSpan(std::string_view, opentelemetry::trace::SpanKind) override { return opentelemetry::nostd::shared_ptr( new opentelemetry::trace::NoopSpan(nullptr)); } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr startSpan( std::string_view, opentelemetry::context::Context const&, diff --git a/src/libxrpl/telemetry/Telemetry.cpp b/src/libxrpl/telemetry/Telemetry.cpp index 30c9a22b50..e135b37bc7 100644 --- a/src/libxrpl/telemetry/Telemetry.cpp +++ b/src/libxrpl/telemetry/Telemetry.cpp @@ -19,6 +19,7 @@ #include #include +#include #include #include #include @@ -77,6 +78,24 @@ namespace xrpl::telemetry { +// beast cannot include this header, so it duplicates the meter scope. Fail the +// build if the copies drift: instruments would land off the views' scope. +static_assert(kMeterName == beast::insight::kOTelMeterName); +static_assert(kMeterVersion == beast::insight::kOTelMeterVersion); + +/** + * OTLP/HTTP path per signal, appended by signalEndpoint(). + */ +constexpr std::string_view kTracesPath{"/v1/traces"}; +constexpr std::string_view kMetricsPath{"/v1/metrics"}; + +/** + * Metric export cadence. The interval matches the 1 s scrape the dashboards + * assume; the timeout bounds a stalled collector. + */ +constexpr auto kMetricExportInterval = std::chrono::milliseconds{1000}; +constexpr auto kMetricExportTimeout = std::chrono::milliseconds{500}; + namespace { namespace trace_api = opentelemetry::trace; @@ -244,7 +263,7 @@ public: return setup_.consensusTraceStrategy; } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr getTracer(std::string_view) override { static auto noopTracer = @@ -252,7 +271,7 @@ public: return noopTracer; } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr getMeter(std::string_view name) override { // Serve a meter from a process-wide noop provider, mirroring the @@ -262,13 +281,13 @@ public: return noopProvider->GetMeter(std::string(name), std::string(kMeterVersion)); } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr startSpan(std::string_view, trace_api::SpanKind) override { return opentelemetry::nostd::shared_ptr(new trace_api::NoopSpan(nullptr)); } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr startSpan(std::string_view, opentelemetry::context::Context const&, trace_api::SpanKind) override { @@ -370,12 +389,12 @@ public: void start() override { - JLOG(journal_.info()) << "Telemetry starting: endpoint=" << setup_.exporterEndpoint + JLOG(journal_.info()) << "Telemetry starting: traces_endpoint=" << setup_.tracesEndpoint << " sampling=" << setup_.samplingRatio; // Configure OTLP HTTP exporter otlp_http::OtlpHttpExporterOptions exporterOpts; - exporterOpts.url = setup_.exporterEndpoint; + exporterOpts.url = signalEndpoint(setup_.tracesEndpoint, kTracesPath); if (setup_.useTls) { exporterOpts.ssl_ca_cert_path = setup_.tlsCertPath; @@ -518,7 +537,7 @@ public: // Derive the metrics endpoint from the trace endpoint by swapping // the trailing "/v1/traces" path for "/v1/metrics". Any other URL // shape is used as-is. - std::string metricsEndpoint = setup_.exporterEndpoint; + std::string metricsEndpoint = setup_.tracesEndpoint; constexpr std::string_view tracesPath{"/v1/traces"}; if (metricsEndpoint.ends_with(tracesPath)) { @@ -690,7 +709,7 @@ public: return setup_.consensusTraceStrategy; } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr getTracer(std::string_view name = kTracerName) override { if (!sdkProvider_) @@ -700,7 +719,7 @@ public: return sdkProvider_->GetTracer(std::string(name)); } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr getMeter(std::string_view name = kMeterName) override { if (!meterProvider_) @@ -711,7 +730,7 @@ public: return meterProvider_->GetMeter(std::string(name), std::string(kMeterVersion)); } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr startSpan(std::string_view name, trace_api::SpanKind kind) override { auto tracer = getTracer(); @@ -720,7 +739,7 @@ public: return tracer->StartSpan(std::string(name), opts); } - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr startSpan( std::string_view name, opentelemetry::context::Context const& parentContext, diff --git a/src/libxrpl/telemetry/TelemetryConfig.cpp b/src/libxrpl/telemetry/TelemetryConfig.cpp index be97045332..142b86b317 100644 --- a/src/libxrpl/telemetry/TelemetryConfig.cpp +++ b/src/libxrpl/telemetry/TelemetryConfig.cpp @@ -35,7 +35,7 @@ namespace key { constexpr char const* enabled = "enabled"; constexpr char const* serviceName = "service_name"; constexpr char const* serviceInstanceId = "service_instance_id"; -constexpr char const* endpoint = "endpoint"; +constexpr char const* tracesEndpoint = "traces_endpoint"; constexpr char const* useTls = "use_tls"; constexpr char const* tlsCaCert = "tls_ca_cert"; constexpr char const* tlsClientCert = "tls_client_cert"; @@ -60,7 +60,7 @@ constexpr char const* traceLedger = "trace_ledger"; */ namespace dflt { constexpr char const* serviceName = "xrpld"; -constexpr char const* endpoint = "http://localhost:4318/v1/traces"; +constexpr char const* tracesEndpoint = "http://localhost:4318/v1/traces"; constexpr std::uint32_t batchSize = 512u; constexpr std::uint32_t batchDelayMs = 5000u; constexpr std::uint32_t maxQueueSize = 2048u; @@ -136,7 +136,7 @@ makeTelemetrySetup( setup.serviceVersion = version; setup.serviceInstanceId = section.valueOr(key::serviceInstanceId, nodePublicKey); - setup.exporterEndpoint = section.valueOr(key::endpoint, dflt::endpoint); + setup.tracesEndpoint = section.valueOr(key::tracesEndpoint, dflt::tracesEndpoint); setup.useTls = section.valueOr(key::useTls, 0) != 0; setup.tlsCertPath = section.valueOr(key::tlsCaCert, ""); diff --git a/src/libxrpl/tx/Transactor.cpp b/src/libxrpl/tx/Transactor.cpp index 4eb43d1596..4e6dbf33b2 100644 --- a/src/libxrpl/tx/Transactor.cpp +++ b/src/libxrpl/tx/Transactor.cpp @@ -49,6 +49,7 @@ #include #include #include +#include #include #include #include @@ -1624,126 +1625,140 @@ Transactor::operator()() trapTransaction(*trap); } - auto result = ctx_.preclaimResult; - if (isTesSuccess(result)) - result = apply(); - - // No transaction can return temUNKNOWN from apply, - // and it can't be passed in from a preclaim. - XRPL_ASSERT(result != temUNKNOWN, "xrpl::Transactor::operator() : result is not temUNKNOWN"); - - if (auto stream = j_.trace()) - stream << "preclaim result: " << transToken(result); - - auto fee = ctx_.tx.getFieldAmount(sfFee).xrp(); - bool const canApply = std::invoke([&result, &fee, this] { - bool canApplyTmp = isTesSuccess(result); - - if (ctx_.size() > kOversizeMetaDataCap) - result = tecOVERSIZE; - - if (isTecClaim(result) && ((view().flags() & TapFailHard) != 0u)) - { - // If the TapFailHard flag is set, a tec result - // must not do anything - ctx_.discard(); - canApplyTmp = false; - } - else if ( - (result == tecOVERSIZE) || (result == tecKILLED) || (result == tecINCOMPLETE) || - (result == tecEXPIRED) || (isTecClaimHardFail(result, view().flags()))) - { - // This is and must remain the only place where `canApplyTmp` can change from false to - // true. Changing from true to false is no problem. - std::tie(result, fee, canApplyTmp) = processPersistentChanges(result, fee); - } - return canApplyTmp; - }); - - // Every exit from this function funnels through here, so this is also where - // the apply span records its outcome: each return path reports the engine - // result and whether the transaction was applied. - auto const logger = [this, &span]( - TER result, - bool canApply, - std::optional&& metadata = std::nullopt) -> ApplyResult { - JLOG(j_.trace()) << (canApply ? "applied " : "not applied ") << transToken(result); - - // Also guarded: transToken() is a lookup returning a string, and this - // funnel runs on every exit path. - if (span) - { - span.setAttribute( - telemetry::tx_apply_span::attr::terResult, transToken(result).c_str()); - span.setAttribute(telemetry::tx_apply_span::attr::applied, canApply); - // Mark the span as errored when the transaction was not applied or - // the engine result is not a success, so failed applies surface in - // span-status error counts alongside preflight and preclaim. - if (!canApply || !isTesSuccess(result)) - span.setError(transToken(result)); - } - - return {result, canApply, std::move(metadata)}; - }; - - if (!canApply) - return logger(result, canApply); - - // First invariant pass: both protocol and transaction-specific - // checks run against the transaction's tentative outcome. If it - // does not return tecINVARIANT_FAILED, we can proceed to apply the - // tx. - result = checkInvariants(result, fee, InvariantScope::Full); - if (result == tecINVARIANT_FAILED) + try { - // Fee-claim reset: roll the transaction's effects back so that - // only the fee deduction remains. This is the reset referenced - // by InvariantScope::ProtocolOnly. - auto const resetResult = reset(fee); - if (!isTesSuccess(resetResult.first)) - result = resetResult.first; + auto result = ctx_.preclaimResult; + if (isTesSuccess(result)) + result = apply(); - fee = resetResult.second; + // No transaction can return temUNKNOWN from apply, + // and it can't be passed in from a preclaim. + XRPL_ASSERT( + result != temUNKNOWN, "xrpl::Transactor::operator() : result is not temUNKNOWN"); - // Re-check invariants against the post-reset (fee-claim only) - // state. The transaction's effects are gone, so the - // transaction-specific invariants no longer apply and only the - // protocol invariants are re-run. A failure here escalates to - // tefINVARIANT_FAILED and excludes the tx from the ledger. - if (isTesSuccess(result) || isTecClaim(result)) - result = checkInvariants(result, fee, InvariantScope::ProtocolOnly); + if (auto stream = j_.trace()) + stream << "preclaim result: " << transToken(result); + + auto fee = ctx_.tx.getFieldAmount(sfFee).xrp(); + bool const canApply = std::invoke([&result, &fee, this] { + bool canApplyTmp = isTesSuccess(result); + + if (ctx_.size() > kOversizeMetaDataCap) + result = tecOVERSIZE; + + if (isTecClaim(result) && ((view().flags() & TapFailHard) != 0u)) + { + // If the TapFailHard flag is set, a tec result + // must not do anything + ctx_.discard(); + canApplyTmp = false; + } + else if ( + (result == tecOVERSIZE) || (result == tecKILLED) || (result == tecINCOMPLETE) || + (result == tecEXPIRED) || (isTecClaimHardFail(result, view().flags()))) + { + // This is and must remain the only place where `canApplyTmp` can change from false + // to true. Changing from true to false is no problem. + std::tie(result, fee, canApplyTmp) = processPersistentChanges(result, fee); + } + return canApplyTmp; + }); + + // Each return path funnels through here, so this is also where the apply + // span records its outcome: the engine result and whether the transaction + // was applied. A throw bypasses it and ends the span with no outcome. + auto const logger = [this, &span]( + TER result, + bool canApply, + std::optional&& metadata = std::nullopt) -> ApplyResult { + JLOG(j_.trace()) << (canApply ? "applied " : "not applied ") << transToken(result); + + // Also guarded: transToken() is a lookup returning a string, and this + // funnel runs on every return path. + if (span) + { + span.setAttribute( + telemetry::tx_apply_span::attr::terResult, transToken(result).c_str()); + span.setAttribute(telemetry::tx_apply_span::attr::applied, canApply); + // Mark the span as errored when the engine result is not a success, + // so failed applies surface alongside preflight and preclaim. Not + // keyed on `canApply`: a dry run reports tesSUCCESS with canApply + // false, and that is not a failure. + if (!isTesSuccess(result)) + span.setError(transToken(result)); + } + + return {result, canApply, std::move(metadata)}; + }; + + if (!canApply) + return logger(result, canApply); + + // First invariant pass: both protocol and transaction-specific + // checks run against the transaction's tentative outcome. If it + // does not return tecINVARIANT_FAILED, we can proceed to apply the + // tx. + result = checkInvariants(result, fee, InvariantScope::Full); + if (result == tecINVARIANT_FAILED) + { + // Fee-claim reset: roll the transaction's effects back so that + // only the fee deduction remains. This is the reset referenced + // by InvariantScope::ProtocolOnly. + auto const resetResult = reset(fee); + if (!isTesSuccess(resetResult.first)) + result = resetResult.first; + + fee = resetResult.second; + + // Re-check invariants against the post-reset (fee-claim only) + // state. The transaction's effects are gone, so the + // transaction-specific invariants no longer apply and only the + // protocol invariants are re-run. A failure here escalates to + // tefINVARIANT_FAILED and excludes the tx from the ledger. + if (isTesSuccess(result) || isTecClaim(result)) + result = checkInvariants(result, fee, InvariantScope::ProtocolOnly); + } + + // We ran through the invariant checker, which can, in some cases, + // return a tef error code. Don't apply the transaction in that case. + if (!isTecClaim(result) && !isTesSuccess(result)) + return logger(result, false); + + std::optional metadata; + + // Transaction succeeded fully or (retries are not allowed and the + // transaction could claim a fee) + + // The transactor and invariant checkers guarantee that this will + // *never* trigger but if it, somehow, happens, don't allow a tx + // that charges a negative fee. + if (fee < beast::kZero) + Throw("fee charged is negative!"); + + // Charge whatever fee they specified. The fee has already been + // deducted from the balance of the account that issued the + // transaction. We just need to account for it in the ledger + // header. + if (!view().open() && fee != beast::kZero) + ctx_.destroyXRP(fee); + + // Once we call apply, we will no longer be able to look at view() + metadata = ctx_.apply(result); + + if ((ctx_.flags() & TapDryRun) != 0u) + return logger(result, false, std::move(metadata)); + + return logger(result, canApply, std::move(metadata)); + } + catch (std::exception const& e) + { + // The caller's doApply() maps this to tefEXCEPTION. Record it on the + // span before unwinding so per-stage error counts include exceptions. + span.setAttribute( + telemetry::tx_apply_span::attr::terResult, transToken(tefEXCEPTION).c_str()); + span.recordException(e); + throw; } - - // We ran through the invariant checker, which can, in some cases, - // return a tef error code. Don't apply the transaction in that case. - if (!isTecClaim(result) && !isTesSuccess(result)) - return logger(result, false); - - std::optional metadata; - - // Transaction succeeded fully or (retries are not allowed and the - // transaction could claim a fee) - - // The transactor and invariant checkers guarantee that this will - // *never* trigger but if it, somehow, happens, don't allow a tx - // that charges a negative fee. - if (fee < beast::kZero) - Throw("fee charged is negative!"); - - // Charge whatever fee they specified. The fee has already been - // deducted from the balance of the account that issued the - // transaction. We just need to account for it in the ledger - // header. - if (!view().open() && fee != beast::kZero) - ctx_.destroyXRP(fee); - - // Once we call apply, we will no longer be able to look at view() - metadata = ctx_.apply(result); - - if ((ctx_.flags() & TapDryRun) != 0u) - return logger(result, false, std::move(metadata)); - - return logger(result, canApply, std::move(metadata)); } } // namespace xrpl diff --git a/src/libxrpl/tx/applySteps.cpp b/src/libxrpl/tx/applySteps.cpp index 45758bf616..3ec6c25aa8 100644 --- a/src/libxrpl/tx/applySteps.cpp +++ b/src/libxrpl/tx/applySteps.cpp @@ -314,6 +314,10 @@ invokePreclaim(PreclaimContext const& ctx) { span.setAttribute( telemetry::tx_apply_span::attr::terResult, transToken(preclaimTer).c_str()); + // Mark the span as errored when preclaim rejects the transaction so + // failed stages surface in span-status error counts. + if (!isTesSuccess(preclaimTer)) + span.setError(transToken(preclaimTer)); } return preclaimTer; } diff --git a/src/test/overlay/TMGetObjectByHash_test.cpp b/src/test/overlay/TMGetObjectByHash_test.cpp index 7bb2854ca4..eae3b0904a 100644 --- a/src/test/overlay/TMGetObjectByHash_test.cpp +++ b/src/test/overlay/TMGetObjectByHash_test.cpp @@ -725,9 +725,9 @@ class TMGetObjectByHash_test : public beast::unit_test::Suite * One pricing case: inputs, the derived expectation, and the literal. * * Both expectations are kept. `derived` is written from the Tuning - * constants so a deliberate re-pricing needs one edit; `literal` is the - * number as of this branch so a re-pricing cannot pass unnoticed by - * being self-consistently wrong. + * constants so a deliberate re-pricing needs one edit; `literal` pins the + * number those constants currently produce, so a re-pricing cannot pass + * unnoticed by being self-consistently wrong. */ struct FeeCase { diff --git a/src/tests/libxrpl/telemetry/MetricsRegistry.cpp b/src/tests/libxrpl/telemetry/MetricsRegistry.cpp index 889247805a..222c4bada1 100644 --- a/src/tests/libxrpl/telemetry/MetricsRegistry.cpp +++ b/src/tests/libxrpl/telemetry/MetricsRegistry.cpp @@ -1,7 +1,7 @@ /** * GTest unit tests for MetricsRegistry. * - * Three independent groups, split by what they can link: + * Four independent groups, split by what they can link: * * 1. sanitiseHandler() — the `handler` label sanitiser. Runs in **both** * builds. sanitiseHandler() is a public static constexpr defined inline @@ -14,7 +14,13 @@ * on the nodestore_state gauge. Also a public static constexpr inline, * so it runs in both builds for the same reason. * - * 3. The no-op / telemetry-disabled path — construction, the two-phase + * 3. parseLedgerRange() — reads one segment of the complete-ledger range + * string the complete_ledgers gauge publishes. A public static inline, so + * it runs in both builds for the same reason. The last case drives the + * real producer, xrpl::to_string(RangeSet), rather than restating its + * format. + * + * 4. The no-op / telemetry-disabled path — construction, the two-phase * start() / startAsyncGauges() / stop() lifecycle, and the synchronous * record*() methods. Guarded, because * when XRPL_ENABLE_TELEMETRY is defined MetricsRegistry.cpp is not @@ -60,6 +66,8 @@ #include +#include + #include #include @@ -69,7 +77,10 @@ #include #include #include +#include #include +#include +#include namespace { @@ -240,9 +251,9 @@ allFoldToOther() static_assert(allPassThroughUnchanged()); static_assert(allFoldToOther()); -// The verified size of the pass-through set as of this branch: 43 all-letter -// job-name literals. Pinned so that adding or removing a job name without -// revisiting the label-cardinality budget fails the build here. +// The pass-through set is every all-letter job-name literal in the tree: 43 +// of them. Pinned so that adding or removing a job name without revisiting +// the label-cardinality budget fails the build here. static_assert(kPassThroughHandlers.size() == 43); /** @@ -453,6 +464,155 @@ TEST(MetricsRegistryScaledMean, default_scale_is_one) EXPECT_EQ(Registry::scaledMean(360, 8), 45); } +namespace { + +/** + * Segments the producer can emit, paired with the range each denotes. + * + * Both shapes come from xrpl::to_string(ClosedInterval): `first-last`, and a + * bare number when first equals last. + */ +constexpr std::array>, 6> + kProducibleSegments{{ + {"32570-50000", {32570, 50000}}, + {"50005-75891421", {50005, 75891421}}, + {"0-1", {0, 1}}, + {"5000", {5000, 5000}}, + {"0", {0, 0}}, + {"1-1", {1, 1}}, + }}; + +/** + * Segments no producer emits and the parser must refuse. + * + * `5-6 ` and `0x10` are the two that pin the consumed-everything check: they + * start with digits from_chars can read, so only the `ptr != end` test rejects + * them. from_chars refuses the other ten on its own. Keep those two. + */ +constexpr std::array kUnreadableSegments{ + "", + "-", + "-5", + "5-", + "abc", + "5-a", + "a-5", + "5--6", + " 5-6", + "5-6 ", + "+5", + "0x10", +}; + +} // namespace + +TEST(MetricsRegistryParseLedgerRange, dashed_segment_yields_both_bounds) +{ + // The ordinary shape. Both bounds must survive, because the gauge publishes + // them as separate `start` and `end` series and a dashboard subtracts them. + EXPECT_EQ( + Registry::parseLedgerRange("32570-50000"), + (std::pair{32570, 50000})); + EXPECT_EQ( + Registry::parseLedgerRange("50005-75891421"), + (std::pair{50005, 75891421})); +} + +TEST(MetricsRegistryParseLedgerRange, single_ledger_segment_is_a_range_not_a_reject) +{ + // A node holding exactly one complete ledger renders as a bare number, so + // treating a dashless segment as malformed reports nothing at all for that + // node -- the reading an operator most needs while a node is catching up. + auto const one = Registry::parseLedgerRange("5000"); + ASSERT_TRUE(one.has_value()); + EXPECT_EQ(one->first, 5000u); + EXPECT_EQ(one->second, 5000u); + + // Cause, not just state: acceptance is specific to an all-digit segment. + // These two prove the dashless branch is not simply accepting everything, + // so the test above would still fail if the guard were removed outright. + EXPECT_FALSE(Registry::parseLedgerRange("abc").has_value()); + EXPECT_FALSE(Registry::parseLedgerRange("5-").has_value()); +} + +TEST(MetricsRegistryParseLedgerRange, every_producible_segment_parses_exactly) +{ + for (auto const& [segment, expected] : kProducibleSegments) + { + auto const parsed = Registry::parseLedgerRange(segment); + ASSERT_TRUE(parsed.has_value()) << "rejected a producible segment: " << segment; + EXPECT_EQ(*parsed, expected) << "wrong bounds for segment: " << segment; + } +} + +TEST(MetricsRegistryParseLedgerRange, unreadable_segments_are_refused) +{ + for (auto const segment : kUnreadableSegments) + { + EXPECT_FALSE(Registry::parseLedgerRange(segment).has_value()) + << "accepted an unreadable segment: [" << segment << "]"; + } +} + +TEST(MetricsRegistryParseLedgerRange, bounds_are_exact_at_the_sequence_limits) +{ + // The width comes from the function's own return type, so widening the + // sequence cannot leave this asserting against a stale boundary. + using Seq = decltype(Registry::parseLedgerRange("0"))::value_type::first_type; + constexpr auto kMaxSeq = std::numeric_limits::max(); + auto const maxText = std::to_string(kMaxSeq); + + auto const atLimit = Registry::parseLedgerRange(maxText); + ASSERT_TRUE(atLimit.has_value()) << "rejected the largest representable sequence"; + EXPECT_EQ(atLimit->first, kMaxSeq); + EXPECT_EQ(atLimit->second, kMaxSeq); + + // One past the limit does not wrap to a small, believable sequence. + auto const pastLimit = std::to_string(static_cast(kMaxSeq) + 1); + EXPECT_FALSE(Registry::parseLedgerRange(pastLimit).has_value()) + << "overflowed instead of refusing: " << pastLimit; +} + +TEST(MetricsRegistryParseLedgerRange, reads_back_what_the_real_producer_wrote) +{ + // Drives the actual producer rather than a restatement of its format, so a + // change to to_string() fails here instead of silently changing what the + // gauge reports. The middle interval is one ledger wide on purpose: that is + // the shape that renders without a dash. + xrpl::RangeSet ledgers; + ledgers.insert(xrpl::range(32570, 50000)); + ledgers.insert(xrpl::range(60000, 60000)); + ledgers.insert(xrpl::range(70000, 75891421)); + + auto const rendered = xrpl::to_string(ledgers); + + std::vector> recovered; + std::string_view rest{rendered}; + while (!rest.empty()) + { + auto const comma = rest.find(','); + auto const segment = rest.substr(0, comma); + + auto const parsed = Registry::parseLedgerRange(segment); + ASSERT_TRUE(parsed.has_value()) << "producer emitted a segment the parser refuses: [" + << segment << "] from " << rendered; + recovered.push_back(*parsed); + + rest = (comma == std::string_view::npos) ? std::string_view{} : rest.substr(comma + 1); + } + + std::vector> const expected{ + {32570, 50000}, + {60000, 60000}, + {70000, 75891421}, + }; + EXPECT_EQ(recovered, expected) << "rendered as: " << rendered; + + // Cause, not just state: every interval survived the round trip, so none + // was dropped and no later index shifted down to fill a gap. + EXPECT_EQ(recovered.size(), ledgers.iterative_size()); +} + // When telemetry is globally enabled, MetricsRegistry.cpp requires xrpld // link dependencies we cannot satisfy in a standalone GTest binary. #ifndef XRPL_ENABLE_TELEMETRY diff --git a/src/tests/libxrpl/telemetry/SpanGuardFactory.cpp b/src/tests/libxrpl/telemetry/SpanGuardFactory.cpp index 36ab40b1b6..6cec7a5c86 100644 --- a/src/tests/libxrpl/telemetry/SpanGuardFactory.cpp +++ b/src/tests/libxrpl/telemetry/SpanGuardFactory.cpp @@ -99,7 +99,7 @@ TEST(SpanGuardFactory, consensus_close_time_attributes) auto span = telemetry::SpanGuard::span( telemetry::TraceCategory::Consensus, telemetry::seg::consensus, "accept.apply"); span.setAttribute("ledger_seq", static_cast(42)); - span.setAttribute("close_time", static_cast(780000000)); + span.setAttribute("close_time_ripple_epoch_s", static_cast(780000000)); span.setAttribute("close_time_correct", true); span.setAttribute("close_resolution_ms", static_cast(30000)); span.setAttribute("consensus_state", std::string("finished")); diff --git a/src/tests/libxrpl/telemetry/TelemetryConfig.cpp b/src/tests/libxrpl/telemetry/TelemetryConfig.cpp index 3510478daa..355092e644 100644 --- a/src/tests/libxrpl/telemetry/TelemetryConfig.cpp +++ b/src/tests/libxrpl/telemetry/TelemetryConfig.cpp @@ -116,7 +116,7 @@ TEST(TelemetryConfig, setup_defaults) EXPECT_TRUE(s.serviceVersion.empty()); EXPECT_TRUE(s.serviceInstanceId.empty()); EXPECT_TRUE(s.nodeId.empty()); - EXPECT_EQ(s.exporterEndpoint, "http://localhost:4318/v1/traces"); + EXPECT_EQ(s.tracesEndpoint, "http://localhost:4318/v1/traces"); EXPECT_FALSE(s.useTls); EXPECT_TRUE(s.tlsCertPath.empty()); EXPECT_DOUBLE_EQ(s.samplingRatio, 1.0); @@ -160,7 +160,7 @@ TEST(TelemetryConfig, parse_full_section) section.set("service_name", "my-rippled"); section.set("service_instance_id", "custom-id"); section.set("exporter", "otlp_http"); - section.set("endpoint", "http://collector:4318/v1/traces"); + section.set("traces_endpoint", "http://collector:4318/v1/traces"); section.set("use_tls", "1"); section.set("tls_ca_cert", caCert); section.set("batch_size", "256"); @@ -177,7 +177,7 @@ TEST(TelemetryConfig, parse_full_section) EXPECT_TRUE(setup.enabled); EXPECT_EQ(setup.serviceName, "my-rippled"); EXPECT_EQ(setup.serviceInstanceId, "custom-id"); - EXPECT_EQ(setup.exporterEndpoint, "http://collector:4318/v1/traces"); + EXPECT_EQ(setup.tracesEndpoint, "http://collector:4318/v1/traces"); EXPECT_TRUE(setup.useTls); EXPECT_EQ(setup.tlsCertPath, caCert); EXPECT_EQ(setup.batchSize, 256u); diff --git a/src/xrpld/app/consensus/RCLConsensus.cpp b/src/xrpld/app/consensus/RCLConsensus.cpp index 83d0cc56f5..2f1563940f 100644 --- a/src/xrpld/app/consensus/RCLConsensus.cpp +++ b/src/xrpld/app/consensus/RCLConsensus.cpp @@ -664,7 +664,8 @@ RCLConsensus::Adaptor::doAccept( : telemetry::SpanGuard::childSpan(cs::acceptApply, roundSpanContext_); doAcceptSpan.setAttribute(cs::attr::ledgerSeq, static_cast(prevLedger.seq()) + 1); doAcceptSpan.setAttribute( - cs::attr::closeTime, static_cast(consensusCloseTime.time_since_epoch().count())); + cs::attr::closeTimeRippleEpochS, + static_cast(consensusCloseTime.time_since_epoch().count())); doAcceptSpan.setAttribute(cs::attr::closeTimeCorrect, closeTimeCorrect); doAcceptSpan.setAttribute( cs::attr::closeResolutionMs, @@ -677,10 +678,10 @@ RCLConsensus::Adaptor::doAccept( doAcceptSpan.setAttribute( cs::attr::roundTimeMs, static_cast(result.roundTime.read().count())); doAcceptSpan.setAttribute( - cs::attr::parentCloseTime, + cs::attr::parentCloseTimeRippleEpochS, static_cast(prevLedger.closeTime().time_since_epoch().count())); doAcceptSpan.setAttribute( - cs::attr::closeTimeSelf, + cs::attr::closeTimeSelfRippleEpochS, static_cast(rawCloseTimes.self.time_since_epoch().count())); doAcceptSpan.setAttribute( cs::attr::closeTimeVoteBins, static_cast(rawCloseTimes.peers.size())); diff --git a/src/xrpld/app/ledger/detail/BuildLedger.cpp b/src/xrpld/app/ledger/detail/BuildLedger.cpp index 482721bf6a..e2433f9c1a 100644 --- a/src/xrpld/app/ledger/detail/BuildLedger.cpp +++ b/src/xrpld/app/ledger/detail/BuildLedger.cpp @@ -188,6 +188,12 @@ applyTransactions( // If there are any transactions left, we must have // tried them in at least one final pass XRPL_ASSERT(txns.empty() || !certainRetry, "xrpl::applyTransactions : retry transactions"); + // Repeated from the parent ledger.build span on purpose: TraceQL cannot + // reach a parent's attributes from a child, so without it no query can + // select this span by ledger. `view` is the accumulator over the ledger + // being built and copies its header, so this is the same sequence number + // the parent reports. + applySpan.setAttribute(ledger_span::attr::ledgerSeq, static_cast(view.seq())); applySpan.setAttribute(ledger_span::attr::txCount, static_cast(count)); applySpan.setAttribute(ledger_span::attr::txFailed, static_cast(failed.size())); return count; diff --git a/src/xrpld/overlay/detail/PeerImp.cpp b/src/xrpld/overlay/detail/PeerImp.cpp index ef9c4f0679..e0a9350c36 100644 --- a/src/xrpld/overlay/detail/PeerImp.cpp +++ b/src/xrpld/overlay/detail/PeerImp.cpp @@ -2041,10 +2041,12 @@ PeerImp::onMessage(std::shared_ptr const& m) { using namespace telemetry; // root: inbound peer message entry point (kConsumer); must not inherit - // any span left active on this peer thread. - auto span = + // any span left active on this peer thread. Named after the span it holds, + // peer.proposal.receive, to keep it distinct from `proposalSpan` below, + // which holds the consensus-level span handed to the job worker. + auto proposalReceiveSpan = ScopedSpanGuard::freshRoot(TraceCategory::Peer, seg::peer, peer_span::op::proposalReceive); - span.setAttribute(peer_span::attr::peerId, static_cast(id_)); + proposalReceiveSpan.setAttribute(peer_span::attr::peerId, static_cast(id_)); protocol::TMProposeSet const& set = *m; @@ -2072,7 +2074,7 @@ PeerImp::onMessage(std::shared_ptr const& m) // every time a spam packet is received PublicKey const publicKey{makeSlice(set.nodepubkey())}; auto const isTrusted = app_.getValidators().trusted(publicKey); - span.setAttribute(peer_span::attr::proposalTrusted, isTrusted); + proposalReceiveSpan.setAttribute(peer_span::attr::proposalTrusted, isTrusted); // If the operator has specified that untrusted proposals be dropped then // this happens here I.e. before further wasting CPU verifying the signature @@ -2646,10 +2648,12 @@ PeerImp::onMessage(std::shared_ptr const& m) { using namespace telemetry; // root: inbound peer message entry point (kConsumer); must not inherit - // any span left active on this peer thread. - auto valSpan = ScopedSpanGuard::freshRoot( + // any span left active on this peer thread. Named after the span it holds, + // peer.validation.receive, to keep it distinct from the consensus-level + // span handed to the job worker below. + auto validationReceiveSpan = ScopedSpanGuard::freshRoot( TraceCategory::Peer, seg::peer, peer_span::op::validationReceive); - valSpan.setAttribute(peer_span::attr::peerId, static_cast(id_)); + validationReceiveSpan.setAttribute(peer_span::attr::peerId, static_cast(id_)); if (m->validation().size() < 50) { @@ -2690,11 +2694,11 @@ PeerImp::onMessage(std::shared_ptr const& m) // false when telemetry is compiled out, switched off in the config, or // the Peer trace category is disabled; a span that exists but was // sampled out still pays. - if (valSpan) + if (validationReceiveSpan) { - valSpan.setAttribute( + validationReceiveSpan.setAttribute( peer_span::attr::ledgerHash, to_string(val->getLedgerHash()).c_str()); - valSpan.setAttribute(peer_span::attr::fullValidation, val->isFull()); + validationReceiveSpan.setAttribute(peer_span::attr::fullValidation, val->isFull()); } if (!isCurrent( @@ -2712,7 +2716,7 @@ PeerImp::onMessage(std::shared_ptr const& m) // suppression for 30 seconds to avoid doing a relatively expensive // lookup every time a spam packet is received auto const isTrusted = app_.getValidators().trusted(val->getSignerPublic()); - valSpan.setAttribute(peer_span::attr::validationTrusted, isTrusted); + validationReceiveSpan.setAttribute(peer_span::attr::validationTrusted, isTrusted); // If the operator has specified that untrusted validations be // dropped then this happens here I.e. before further wasting CPU @@ -2781,12 +2785,29 @@ PeerImp::onMessage(std::shared_ptr const& m) static_cast(val->getSignTime().time_since_epoch().count())); } + // validation_status is set once on each exit below, not as a default + // here, to avoid OTel SDK attribute duplication. It is what separates + // the microsecond drop paths from the queued path, which also covers + // job wait and checkValidation. if (!isTrusted && (tracking_.load() == Tracking::Diverged)) { + if (span && *span) + { + span->setAttribute( + telemetry::consensus::span::attr::validationStatus, + telemetry::consensus::span::val::validationDroppedDiverged); + } JLOG(pJournal_.debug()) << "Dropping untrusted validation from diverged peer"; } else if (isTrusted || !app_.getFeeTrack().isLoadedLocal()) { + // Set before the handle is moved into the job below. + if (span && *span) + { + span->setAttribute( + telemetry::consensus::span::attr::validationStatus, + telemetry::consensus::span::val::validationQueued); + } std::string const name = isTrusted ? "ChkTrust" : "ChkUntrust"; std::weak_ptr const weak = shared_from_this(); @@ -2800,6 +2821,12 @@ PeerImp::onMessage(std::shared_ptr const& m) } else { + if (span && *span) + { + span->setAttribute( + telemetry::consensus::span::attr::validationStatus, + telemetry::consensus::span::val::validationDroppedLoad); + } JLOG(pJournal_.debug()) << "Dropping untrusted validation for load"; } } diff --git a/src/xrpld/overlay/detail/PeerImp.h b/src/xrpld/overlay/detail/PeerImp.h index 02a58dc7c2..5073491f87 100644 --- a/src/xrpld/overlay/detail/PeerImp.h +++ b/src/xrpld/overlay/detail/PeerImp.h @@ -814,10 +814,10 @@ private: /** * Record the OTel metrics for one completed `TMGetObjectByHash` request. * - * Extracted from `processGetObjectByHash()` purely to keep that method - * within the 80-line limit; it holds no logic of its own beyond deriving - * the hit/miss split from `requested` and `found`. Called once per - * request, after the fetch loop and the `charge()` call. + * Called once per request from `processGetObjectByHash()`, after the fetch + * loop and the `charge()` call. A separate method so that one stays within + * the 80-line limit; it holds no logic of its own beyond deriving the + * hit/miss split from `requested` and `found`. * * Records `getobject_request_objects`, `getobject_lookup_us`, * `getobject_charge`, and both label values of diff --git a/src/xrpld/overlay/detail/PeerSpanNames.h b/src/xrpld/overlay/detail/PeerSpanNames.h index 535424ff45..2a2fbd8960 100644 --- a/src/xrpld/overlay/detail/PeerSpanNames.h +++ b/src/xrpld/overlay/detail/PeerSpanNames.h @@ -52,7 +52,14 @@ using ::xrpl::telemetry::attr::ledgerHash; using ::xrpl::telemetry::attr::peerId; /** - * Trust flag qualified by message type, shared with consensus.*.receive. + * Trust flag qualified by message type — whether the sending key is on this + * node's UNL. + * + * The literals match consensus::span::attr::proposalTrusted and + * ::validationTrusted, so the peer and consensus receive spans report on one + * spanmetrics dimension instead of two. Unlike the constants above these are + * declared here rather than re-exported from SpanNames.h, so the two spellings + * are only kept equal by hand: change one and the dimension splits silently. */ inline constexpr auto proposalTrusted = makeStr("proposal_trusted"); inline constexpr auto validationTrusted = makeStr("validation_trusted"); diff --git a/src/xrpld/rpc/detail/PathRequest.cpp b/src/xrpld/rpc/detail/PathRequest.cpp index 827393b071..1154109fc9 100644 --- a/src/xrpld/rpc/detail/PathRequest.cpp +++ b/src/xrpld/rpc/detail/PathRequest.cpp @@ -596,8 +596,8 @@ PathRequest::findPaths( // One `pathfind.discover` span wraps the entire per-source-asset loop so // that a single RPC call produces one discover span instead of N (one per // candidate source asset). Trade-off: per-asset discovery/ranking timing - // is no longer split into individual spans — span count and Tempo storage - // are bounded per RPC at the cost of per-asset visibility. + // is not measured separately — span count and Tempo storage are bounded + // per RPC at the cost of per-asset visibility. // // This is an unscoped guard: it takes the ambient span as its own parent, // but does not itself become the ambient parent. Adding per-asset child diff --git a/src/xrpld/telemetry/MetricsRegistry.cpp b/src/xrpld/telemetry/MetricsRegistry.cpp index 4d930a3225..84ab73a553 100644 --- a/src/xrpld/telemetry/MetricsRegistry.cpp +++ b/src/xrpld/telemetry/MetricsRegistry.cpp @@ -30,11 +30,12 @@ // The app and overlay includes below are why // .github/scripts/levelization/results/loops.txt records -// `xrpld.app <-> xrpld.telemetry` and `xrpld.overlay <-> xrpld.telemetry`, where -// ordering.txt previously had telemetry strictly below both. The observable -// gauges are pull-model: their callbacks sample live state when the reader -// thread fires, so they need the concrete types to call getJqTransOverflow(), -// size(), getPeerDisconnectCharges(), foreach() and txMetrics(). +// `xrpld.app <-> xrpld.telemetry` and `xrpld.overlay <-> xrpld.telemetry` as +// cycles, rather than an acyclic ordering.txt entry placing telemetry strictly +// below both. The observable gauges are pull-model: their callbacks sample live +// state when the reader thread fires, so they need the concrete types to call +// getJqTransOverflow(), size(), getPeerDisconnectCharges(), foreach() and +// txMetrics(). // // The cycle is confined to this translation unit. No telemetry header includes // app or overlay (MetricsRegistry.h forward-declares what it needs and takes a @@ -252,9 +253,9 @@ MetricsRegistry::~MetricsRegistry() void MetricsRegistry::start( - std::string const& endpoint, - std::string const& instanceId, - std::string const& nodeId) + [[maybe_unused]] std::string const& endpoint, + [[maybe_unused]] std::string const& instanceId, + [[maybe_unused]] std::string const& nodeId) { #ifdef XRPL_ENABLE_TELEMETRY if (!enabled_) @@ -275,11 +276,6 @@ MetricsRegistry::start( initSyncInstruments(); JLOG(journal_.info()) << "MetricsRegistry: provider and instruments ready"; -#else - (void)endpoint; - (void)instanceId; - (void)nodeId; - (void)enabled_; #endif // XRPL_ENABLE_TELEMETRY } @@ -302,8 +298,6 @@ MetricsRegistry::startAsyncGauges() registerAsyncGauges(); JLOG(journal_.info()) << "MetricsRegistry: started successfully"; -#else - (void)enabled_; #endif // XRPL_ENABLE_TELEMETRY } @@ -525,20 +519,19 @@ MetricsRegistry::stop() // ----------------------------------------------------------------- void -MetricsRegistry::recordRpcStarted(std::string_view method) +MetricsRegistry::recordRpcStarted([[maybe_unused]] std::string_view method) { #ifdef XRPL_ENABLE_TELEMETRY if (!enabled_ || !rpcStartedCounter_) return; rpcStartedCounter_->Add(1, {{"method", std::string(method)}}); -#else - (void)method; - (void)enabled_; #endif } void -MetricsRegistry::recordRpcFinished(std::string_view method, std::int64_t durationUs) +MetricsRegistry::recordRpcFinished( + [[maybe_unused]] std::string_view method, + [[maybe_unused]] std::int64_t durationUs) { #ifdef XRPL_ENABLE_TELEMETRY if (!enabled_ || !rpcFinishedCounter_) @@ -551,15 +544,13 @@ MetricsRegistry::recordRpcFinished(std::string_view method, std::int64_t duratio {{"method", std::string(method)}}, opentelemetry::context::Context{}); } -#else - (void)method; - (void)durationUs; - (void)enabled_; #endif } void -MetricsRegistry::recordRpcErrored(std::string_view method, std::int64_t durationUs) +MetricsRegistry::recordRpcErrored( + [[maybe_unused]] std::string_view method, + [[maybe_unused]] std::int64_t durationUs) { #ifdef XRPL_ENABLE_TELEMETRY if (!enabled_ || !rpcErroredCounter_) @@ -572,10 +563,6 @@ MetricsRegistry::recordRpcErrored(std::string_view method, std::int64_t duration {{"method", std::string(method)}}, opentelemetry::context::Context{}); } -#else - (void)method; - (void)durationUs; - (void)enabled_; #endif } @@ -584,7 +571,9 @@ MetricsRegistry::recordRpcErrored(std::string_view method, std::int64_t duration // ----------------------------------------------------------------- void -MetricsRegistry::recordJobQueued(std::string_view jobType, std::string_view jobName) +MetricsRegistry::recordJobQueued( + [[maybe_unused]] std::string_view jobType, + [[maybe_unused]] std::string_view jobName) { #ifdef XRPL_ENABLE_TELEMETRY if (!enabled_ || !jobQueuedCounter_) @@ -602,9 +591,9 @@ MetricsRegistry::recordJobQueued(std::string_view jobType, std::string_view jobN void MetricsRegistry::recordJobStarted( - std::string_view jobType, - std::string_view jobName, - std::int64_t queuedDurUs) + [[maybe_unused]] std::string_view jobType, + [[maybe_unused]] std::string_view jobName, + [[maybe_unused]] std::int64_t queuedDurUs) { #ifdef XRPL_ENABLE_TELEMETRY if (!enabled_ || !jobStartedCounter_) @@ -624,19 +613,14 @@ MetricsRegistry::recordJobStarted( {{label::jobType, std::string(jobType)}, {label::handler, handler}}, opentelemetry::context::Context{}); } -#else - (void)jobType; - (void)jobName; - (void)queuedDurUs; - (void)enabled_; #endif } void MetricsRegistry::recordJobFinished( - std::string_view jobType, - std::string_view jobName, - std::int64_t runningDurUs) + [[maybe_unused]] std::string_view jobType, + [[maybe_unused]] std::string_view jobName, + [[maybe_unused]] std::int64_t runningDurUs) { #ifdef XRPL_ENABLE_TELEMETRY if (!enabled_ || !jobFinishedCounter_) @@ -651,11 +635,6 @@ MetricsRegistry::recordJobFinished( {{label::jobType, std::string(jobType)}, {label::handler, handler}}, opentelemetry::context::Context{}); } -#else - (void)jobType; - (void)jobName; - (void)runningDurUs; - (void)enabled_; #endif } @@ -1288,32 +1267,30 @@ MetricsRegistry::registerCompleteLedgersGauge() return; // Parse comma-separated ranges like - // "32570-50000,50005-75891421". + // "32570-50000,50005-75891421". A range of one ledger arrives + // as a bare sequence number, so parseLedgerRange() decides what + // a segment is; only genuinely unreadable ones are skipped. std::size_t rangeIndex = 0; std::istringstream stream(rangeStr); std::string segment; while (std::getline(stream, segment, ',')) { - auto const dashPos = segment.find('-'); - if (dashPos == std::string::npos || dashPos == 0 || - dashPos == segment.size() - 1) + auto const range = MetricsRegistry::parseLedgerRange(segment); + if (!range) continue; - auto const startStr = segment.substr(0, dashPos); - auto const endStr = segment.substr(dashPos + 1); - auto const idxStr = std::to_string(rangeIndex); opentelemetry::nostd::get>>(result) ->Observe( - static_cast(std::stoll(startStr)), + static_cast(range->first), {{"bound", "start"}, {"index", idxStr}}); opentelemetry::nostd::get>>(result) ->Observe( - static_cast(std::stoll(endStr)), + static_cast(range->second), {{"bound", "end"}, {"index", idxStr}}); ++rangeIndex; @@ -1655,7 +1632,7 @@ MetricsRegistry::registerStateTrackingGauge() // State value: 0-4 from OperatingMode, 5=validating, 6=proposing. auto const mode = app.getOPs().getOperatingMode(); - auto stateValue = static_cast(mode); + auto stateValue = static_cast(std::to_underlying(mode)); // If FULL, refine using consensus info for validating/proposing. if (mode == OperatingMode::FULL) diff --git a/src/xrpld/telemetry/MetricsRegistry.h b/src/xrpld/telemetry/MetricsRegistry.h index f61bf65347..236c8be217 100644 --- a/src/xrpld/telemetry/MetricsRegistry.h +++ b/src/xrpld/telemetry/MetricsRegistry.h @@ -109,7 +109,9 @@ * // before any metric-emitting code: * metricsRegistry_ = std::make_unique( * telemetry_->isEnabled(), app, journal); - * metricsRegistry_->start(setup.exporterEndpoint); + * // The endpoint comes from [telemetry] metrics_endpoint, read directly in + * // Application::setup() rather than through Telemetry::Setup. + * metricsRegistry_->start(endpoint, instanceId, nodeId); * * // Later in setup(), once overlay_ exists (the last of the services the * // callbacks read). Phase 2 registers the observable instruments: @@ -157,11 +159,13 @@ #include #include +#include #include #include #include #include #include +#include #ifdef XRPL_ENABLE_TELEMETRY #include @@ -567,6 +571,73 @@ public: return static_cast(scaled + fraction); } + /** + * Read one comma-separated segment of a complete-ledger range string. + * + * The producer is xrpl::to_string(RangeSet), documented in + * xrpl/basics/RangeSet.h. It renders an interval as `first-last`, and an + * interval whose first equals its last as a bare sequence number. A segment + * with no dash is therefore a range of one ledger, not a malformed one. + * + * Defined inline for the same reason as sanitiseHandler(): in a + * telemetry-enabled build MetricsRegistry.cpp is not compiled into the + * unit-test binary, so an out-of-line definition would be untestable. + * + * @param segment One segment, already split on ','. Leading or trailing + * whitespace is rejected, because the producer emits none. + * @return The inclusive first and last sequence of the range. The two are + * equal for a single-ledger range. std::nullopt when @p segment is not + * something this producer can emit. + * + * @note Pure and reentrant: holds no state, performs no I/O, and is safe to + * call concurrently from any thread. + * @note Reports malformed input instead of throwing, so one unreadable + * segment costs its own range and not every range after it. + * @note A reversed range such as "9-4" is returned as given. RangeSet + * cannot emit one. + * + * Example: + * @code + * parseLedgerRange("32570-50000"); // {32570, 50000} + * parseLedgerRange("5000"); // {5000, 5000} -- one ledger + * parseLedgerRange("5-"); // nullopt + * @endcode + */ + [[nodiscard]] static std::optional> + parseLedgerRange(std::string_view segment) noexcept + { + auto const parseSeq = [](std::string_view text) -> std::optional { + std::uint32_t value = 0; + auto const* const begin = text.data(); + auto const* const end = begin + text.size(); + auto const [ptr, ec] = std::from_chars(begin, end, value); + + // from_chars stops at the first character it cannot use, so the + // whole segment counts as read only when it consumed all of it. + if (ec != std::errc{} || ptr != end) + return std::nullopt; + + return value; + }; + + auto const dash = segment.find('-'); + if (dash == std::string_view::npos) + { + auto const only = parseSeq(segment); + if (!only) + return std::nullopt; + + return std::pair{*only, *only}; + } + + auto const first = parseSeq(segment.substr(0, dash)); + auto const last = parseSeq(segment.substr(dash + 1)); + if (!first || !last) + return std::nullopt; + + return std::pair{*first, *last}; + } + /** * Record a job enqueued event. * @param jobType The job type name (e.g. "ledgerData"). @@ -672,7 +743,7 @@ public: * into it is not free: each call takes its lock and inserts an entry. * @return Reference to the internal ValidationTracker instance. */ - ValidationTracker& + [[nodiscard]] ValidationTracker& getValidationTracker() { return validationTracker_; @@ -686,7 +757,7 @@ public: * start() has run or when disabled. * @return The shared Meter, or empty if not yet started. */ - opentelemetry::nostd::shared_ptr + [[nodiscard]] opentelemetry::nostd::shared_ptr meter() const noexcept { return meter_; diff --git a/src/xrpld/telemetry/TxTracing.h b/src/xrpld/telemetry/TxTracing.h index 5baf01df2d..682f482f1b 100644 --- a/src/xrpld/telemetry/TxTracing.h +++ b/src/xrpld/telemetry/TxTracing.h @@ -32,8 +32,12 @@ namespace xrpl::telemetry { * trace_id is derived from txID[0:16]. If the incoming message carries * a protobuf TraceContext with a valid span_id, it is used as the * parent to preserve relay ordering. + * @param txID Transaction id; its first 16 bytes become the trace_id. + * @param msg The received message, read only for its trace context. + * @return An active guard, or a null guard when the Transactions category + * is disabled. Bind it: a discarded guard ends the span immediately. */ -inline SpanGuard +[[nodiscard]] inline SpanGuard txReceiveSpan(uint256 const& txID, [[maybe_unused]] protocol::TMTransaction const& msg) { #ifdef XRPL_ENABLE_TELEMETRY @@ -63,8 +67,11 @@ txReceiveSpan(uint256 const& txID, [[maybe_unused]] protocol::TMTransaction cons /** * Create a "tx.process" span for transaction processing in NetworkOPs. * trace_id is derived from txID[0:16]. + * @param txID Transaction id; its first 16 bytes become the trace_id. + * @return An active guard, or a null guard when the Transactions category + * is disabled. Bind it: a discarded guard ends the span immediately. */ -inline SpanGuard +[[nodiscard]] inline SpanGuard txProcessSpan(uint256 const& txID) { return SpanGuard::hashSpan( diff --git a/src/xrpld/telemetry/ValidationTracker.h b/src/xrpld/telemetry/ValidationTracker.h index 973ab0fe4d..a5b048780e 100644 --- a/src/xrpld/telemetry/ValidationTracker.h +++ b/src/xrpld/telemetry/ValidationTracker.h @@ -138,21 +138,21 @@ public: * Agreement percentage over the last 1 hour. * @return Percentage [0.0, 100.0], or 0.0 if no data. */ - double + [[nodiscard]] double agreementPct1h() const; /** * Agreement percentage over the last 24 hours. * @return Percentage [0.0, 100.0], or 0.0 if no data. */ - double + [[nodiscard]] double agreementPct24h() const; /** * Agreement percentage over the last 7 days. * @return Percentage [0.0, 100.0], or 0.0 if no data. */ - double + [[nodiscard]] double agreementPct7d() const; /** @} */ @@ -165,37 +165,37 @@ public: /** * Number of agreements in the 1-hour window. */ - uint64_t + [[nodiscard]] uint64_t agreements1h() const; /** * Number of misses in the 1-hour window. */ - uint64_t + [[nodiscard]] uint64_t missed1h() const; /** * Number of agreements in the 24-hour window. */ - uint64_t + [[nodiscard]] uint64_t agreements24h() const; /** * Number of misses in the 24-hour window. */ - uint64_t + [[nodiscard]] uint64_t missed24h() const; /** * Number of agreements in the 7-day window. */ - uint64_t + [[nodiscard]] uint64_t agreements7d() const; /** * Number of misses in the 7-day window. */ - uint64_t + [[nodiscard]] uint64_t missed7d() const; /** @} */ @@ -208,13 +208,13 @@ public: /** * Total agreements since process start. */ - uint64_t + [[nodiscard]] uint64_t totalAgreements() const; /** * Total misses since process start. */ - uint64_t + [[nodiscard]] uint64_t totalMissed() const; /** @@ -226,7 +226,7 @@ public: * counter validation_agreements_total. See the counting-semantics * note in detail/ValidationTracker.cpp. */ - uint64_t + [[nodiscard]] uint64_t totalAgreementsEver() const; /** @@ -238,19 +238,19 @@ public: * counter validation_missed_total. See the counting-semantics note * in detail/ValidationTracker.cpp. */ - uint64_t + [[nodiscard]] uint64_t totalMissedEver() const; /** * Total validations this node sent. */ - uint64_t + [[nodiscard]] uint64_t totalValidationsSent() const; /** * Total network validations observed for comparison. */ - uint64_t + [[nodiscard]] uint64_t totalValidationsChecked() const; /** diff --git a/src/xrpld/telemetry/detail/ValidationTracker.cpp b/src/xrpld/telemetry/detail/ValidationTracker.cpp index 5f709c66b6..06a94e1f64 100644 --- a/src/xrpld/telemetry/detail/ValidationTracker.cpp +++ b/src/xrpld/telemetry/detail/ValidationTracker.cpp @@ -180,19 +180,11 @@ void ValidationTracker::evictOldPending(TimePoint now) { auto const cutoff = now - kLateRepairWindow; - for (auto it = pending_.begin(); it != pending_.end();) - { - if (it->second.reconciled && it->second.recordTime < cutoff) - { - it = pending_.erase(it); - } - else - { - ++it; - } - } + std::erase_if(pending_, [cutoff](auto const& entry) { + return entry.second.reconciled && entry.second.recordTime < cutoff; + }); - // Hard trim if still over limit. The loop above already removed every + // Hard trim if still over limit. The pass above already removed every // reconciled entry older than the late-repair window, so here we drop // any remaining reconciled entry as a last resort. if (pending_.size() > kMaxPendingEvents) @@ -219,7 +211,7 @@ ValidationTracker::agreementPct1h() const if (window1h_.empty()) return 0.0; auto const agreed = static_cast( - std::count_if(window1h_.begin(), window1h_.end(), [](auto const& e) { return e.agreed; })); + std::ranges::count_if(window1h_, [](auto const& e) { return e.agreed; })); return (agreed / static_cast(window1h_.size())) * 100.0; } @@ -229,8 +221,8 @@ ValidationTracker::agreementPct24h() const std::scoped_lock const lock(mutex_); if (window24h_.empty()) return 0.0; - auto const agreed = static_cast(std::count_if( - window24h_.begin(), window24h_.end(), [](auto const& e) { return e.agreed; })); + auto const agreed = static_cast( + std::ranges::count_if(window24h_, [](auto const& e) { return e.agreed; })); return (agreed / static_cast(window24h_.size())) * 100.0; } @@ -239,7 +231,7 @@ ValidationTracker::agreements1h() const { std::scoped_lock const lock(mutex_); return static_cast( - std::count_if(window1h_.begin(), window1h_.end(), [](auto const& e) { return e.agreed; })); + std::ranges::count_if(window1h_, [](auto const& e) { return e.agreed; })); } uint64_t @@ -247,23 +239,23 @@ ValidationTracker::missed1h() const { std::scoped_lock const lock(mutex_); return static_cast( - std::count_if(window1h_.begin(), window1h_.end(), [](auto const& e) { return !e.agreed; })); + std::ranges::count_if(window1h_, [](auto const& e) { return !e.agreed; })); } uint64_t ValidationTracker::agreements24h() const { std::scoped_lock const lock(mutex_); - return static_cast(std::count_if( - window24h_.begin(), window24h_.end(), [](auto const& e) { return e.agreed; })); + return static_cast( + std::ranges::count_if(window24h_, [](auto const& e) { return e.agreed; })); } uint64_t ValidationTracker::missed24h() const { std::scoped_lock const lock(mutex_); - return static_cast(std::count_if( - window24h_.begin(), window24h_.end(), [](auto const& e) { return !e.agreed; })); + return static_cast( + std::ranges::count_if(window24h_, [](auto const& e) { return !e.agreed; })); } double @@ -273,7 +265,7 @@ ValidationTracker::agreementPct7d() const if (window7d_.empty()) return 0.0; auto const agreed = static_cast( - std::count_if(window7d_.begin(), window7d_.end(), [](auto const& e) { return e.agreed; })); + std::ranges::count_if(window7d_, [](auto const& e) { return e.agreed; })); return (agreed / static_cast(window7d_.size())) * 100.0; } @@ -282,7 +274,7 @@ ValidationTracker::agreements7d() const { std::scoped_lock const lock(mutex_); return static_cast( - std::count_if(window7d_.begin(), window7d_.end(), [](auto const& e) { return e.agreed; })); + std::ranges::count_if(window7d_, [](auto const& e) { return e.agreed; })); } uint64_t @@ -290,7 +282,7 @@ ValidationTracker::missed7d() const { std::scoped_lock const lock(mutex_); return static_cast( - std::count_if(window7d_.begin(), window7d_.end(), [](auto const& e) { return !e.agreed; })); + std::ranges::count_if(window7d_, [](auto const& e) { return !e.agreed; })); } uint64_t