From 22e440aee19749ccced5eee7aeaba79311884979 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Fri, 14 Aug 2026 12:34:33 +0100 Subject: [PATCH] fix(telemetry): correct the phase-10 validation harness against the code The harness manifests asserted things the code cannot produce and missed most of what it does. Two assertions were failing every run, and the metric set covered 16 of the ~41 emitted names. expected_spans.json: rpc.process was required with rpc.ws_message as its parent, but it is created only in ServerHandler::processRequest() on the HTTP path, so a WebSocket-only workload never produces it -- it is now optional and parented to rpc.http_request, and the rpc.process -> rpc.command.* edge is skipped with the real reason instead of a coroutine-context-loss diagnosis that was never the cause. Adds the missing rpc.ws_upgrade span, corrects four parents (consensus.mode_change, pathfind.request, and update_positions/check, which are children of consensus.establish rather than consensus.round), and demotes conditionally-set attributes out of required_attributes so a healthy run stops failing. Counts recomputed from the file: 41 span types, 62 unique required attributes. expected_metrics.json: 16 -> 52 asserted entries across the job-queue, RPC method, reduce-relay, overflow and validation families, plus the fifteenth dashboard uid. Metrics the harness workload cannot exercise -- erroring RPC, ledger-mismatch, TxQ overflow, and the lazily-created getobject_* instruments -- are listed in a not_asserted group the validator skips, rather than as assertions that would fail on a healthy node. The workflow's push trigger listed two globs matching nothing (include/xrpl/basics/Telemetry*.h, src/xrpld/app/misc/Telemetry*), so no C++ telemetry change ever triggered validation. Replaced with the paths the code actually lives in, including src/libxrpl/beast/insight/** for the insight export path the harness depends on. The four inert workflow_dispatch inputs are now labelled UNUSED rather than looking like working knobs. Docs: the workload README described a StatsD dirty-flag mechanism under a member name that does not exist, on a code path the harness never uses -- it sets [insight] server=otel, so gauges export through an observable-gauge callback every cycle. Adds the missing txq-burst phase, reconciles three different dashboard counts, and drops "posts summary to PR", which the workflow has no permission to do. The runbook's phase-10 section loses the last sampling_ratio reference (not a config key), gains a Regression Gate and CI subsection covering the gate that can fail CI, and its compose-logs command now names the workload compose file. cmake --preset default is left for a separate change: no CMakePresets.json is tracked, so it is wrong everywhere it appears. Also drops the dead exporter=otlp_http key the harness wrote into every node config, and stops capture_timings.py defaulting --profile to a profile that does not exist. --- .github/workflows/telemetry-validation.yml | 34 +++- OpenTelemetryPlan/06-implementation-phases.md | 85 +++++--- docker/telemetry/workload/README.md | 169 +++++++++++----- docker/telemetry/workload/baselines/README.md | 38 +++- docker/telemetry/workload/capture_timings.py | 13 +- .../telemetry/workload/expected_metrics.json | 58 +++++- docker/telemetry/workload/expected_spans.json | 89 +++++---- .../workload/regression-metrics.json | 2 +- .../telemetry/workload/run-full-validation.sh | 1 - .../telemetry/workload/workload-profiles.json | 2 +- docs/telemetry-runbook.md | 184 +++++++++++++++++- 11 files changed, 535 insertions(+), 140 deletions(-) diff --git a/.github/workflows/telemetry-validation.yml b/.github/workflows/telemetry-validation.yml index cff532c3fd..7e006bace4 100644 --- a/.github/workflows/telemetry-validation.yml +++ b/.github/workflows/telemetry-validation.yml @@ -26,25 +26,32 @@ name: Telemetry Validation on: workflow_dispatch: + # NOTE: rpc_rate / rpc_duration / tx_tps / tx_duration have NO effect. + # They are forwarded to run-full-validation.sh, which parses them into + # shell variables and never reads them again — load shape comes entirely + # from --profile and docker/telemetry/workload/workload-profiles.json. + # They are kept (and labelled) rather than removed so existing dispatch + # bookmarks and any saved input sets do not break. To change the load, + # edit or add a profile in workload-profiles.json. inputs: rpc_rate: - description: "RPC load rate (requests per second)" + description: "UNUSED — has no effect. Load shape comes from the workload profile." required: false default: "50" rpc_duration: - description: "RPC load duration (seconds)" + description: "UNUSED — has no effect. Load shape comes from the workload profile." required: false default: "120" tx_tps: - description: "Transaction submit rate (TPS)" + description: "UNUSED — has no effect. Load shape comes from the workload profile." required: false default: "5" tx_duration: - description: "Transaction submit duration (seconds)" + description: "UNUSED — has no effect. Load shape comes from the workload profile." required: false default: "120" run_benchmark: - description: "Run performance benchmarks" + description: "Run performance benchmarks (the only input that changes behaviour)" required: false type: boolean default: false @@ -54,11 +61,19 @@ on: - "pratik/otel-phase*" - "feature/otel-*" - "feature/telemetry-*" + # Keep these globs pointing at paths that actually exist. Two earlier + # entries (include/xrpl/basics/Telemetry*.h, src/xrpld/app/misc/Telemetry*) + # matched zero tracked files, so a pure C++ telemetry change never + # triggered this workflow on push — only edits under docker/telemetry/** + # or to this file did. The telemetry sources live in the three telemetry + # module directories below. paths: - ".github/workflows/telemetry-validation.yml" - "docker/telemetry/**" - - "include/xrpl/basics/Telemetry*.h" - - "src/xrpld/app/misc/Telemetry*" + - "include/xrpl/telemetry/**" + - "src/libxrpl/telemetry/**" + - "src/libxrpl/beast/insight/**" + - "src/xrpld/telemetry/**" concurrency: group: telemetry-validation-${{ github.ref }} @@ -206,6 +221,11 @@ jobs: TX_DURATION: ${{ github.event.inputs.tx_duration || '120' }} RUN_BENCHMARK: ${{ github.event.inputs.run_benchmark }} run: | + # The four rate/duration flags below are inert (see the + # workflow_dispatch inputs note): run-full-validation.sh parses them + # and never reads them. Load shape comes from the default + # --profile full-validation. They are still passed so the flags stay + # exercised if they are ever wired up. ARGS="--xrpld ${{ env.BUILD_DIR }}/xrpld --skip-loki" ARGS="$ARGS --rpc-rate $RPC_RATE" ARGS="$ARGS --rpc-duration $RPC_DURATION" diff --git a/OpenTelemetryPlan/06-implementation-phases.md b/OpenTelemetryPlan/06-implementation-phases.md index df8ec632eb..1fec8164b1 100644 --- a/OpenTelemetryPlan/06-implementation-phases.md +++ b/OpenTelemetryPlan/06-implementation-phases.md @@ -927,11 +927,13 @@ Alert Rules from External Dashboard**. Before the telemetry stack (Phases 1-9) can be considered production-ready, we need automated proof that all spans, attributes, metrics, Grafana dashboards, and log-trace correlation work correctly under realistic load. This phase establishes a reusable CI-integrated validation suite and performance benchmark baseline. > **Inventory note**: the "16 spans / 22 attributes / 10 dashboards" figures this -> section used to quote are stale. As of this branch there are **15 dashboards on -> disk** (`ls docker/telemetry/grafana/dashboards/*.json`), of which **14** are -> asserted by the Phase 10 harness — `log-derived-insights` is provisioned but -> unasserted. The span and attribute totals are computed dynamically by -> `validate_telemetry.py` from `expected_spans.json`; see +> section used to quote are stale. Do not re-quote fixed counts here — the +> harness hard-codes none of them. `validate_telemetry.py` iterates +> `expected_spans.json` and `expected_metrics.json`, so those two files are the +> only authority, and `grafana_dashboards.uids` in `expected_metrics.json` is the +> authority for dashboards. As of this branch all **15** dashboards on disk +> (`ls docker/telemetry/grafana/dashboards/*.json`) are listed in `uids`, +> `log-derived-insights` included. See > [Phase10_taskList.md](./Phase10_taskList.md) for the live figures. ### Architecture @@ -1037,7 +1039,10 @@ categories are: - **Span duration bounds** — all spans > 0 and < 60 s - **Metric existence** — every entry in `expected_metrics.json`, queried through the Prometheus `/api/v1/series` endpoint -- **Dashboard loads** — the 14 uids in `expected_metrics.json` +- **Dashboard loads** — every uid in `expected_metrics.json` under + `grafana_dashboards.uids` (currently all 15 provisioned dashboards). Note this + only asks Grafana for the dashboard and its panel count; it does not run the + panel queries. - **Log-trace correlation** — `trace_id` present in Loki plus a Tempo reverse lookup (skipped in CI via `--skip-loki`, not absent from the suite) @@ -1061,36 +1066,55 @@ See [Phase10_taskList.md](./Phase10_taskList.md) for the per-task breakdown. ### CI Deliverable (Task 10.6) The Phase 10 CI entry point is `.github/workflows/telemetry-validation.yml` -(348 lines, on the Phase 10 branch). It runs three jobs — `linux-image-tag`, +(367 lines, on the Phase 10 branch). It runs three jobs — `linux-image-tag`, `build-xrpld`, `validate-telemetry` — and is triggered by `workflow_dispatch` plus `push` on `pratik/otel-phase*`, `feature/otel-*` and `feature/telemetry-*`. **There is no cron schedule**, so nothing runs this workflow on a timer. -> **Caveat — the `push` trigger's `paths` filter excludes the C++ telemetry -> sources.** The branch filter is only half the trigger; `push` also carries: +> **Fixed — the `push` trigger's `paths` filter now covers the C++ telemetry +> sources.** The branch filter is only half the trigger; `push` also carries a +> `paths` filter, and it previously read: > > ```yaml > paths: > - ".github/workflows/telemetry-validation.yml" > - "docker/telemetry/**" -> - "include/xrpl/basics/Telemetry*.h" -> - "src/xrpld/app/misc/Telemetry*" +> - "include/xrpl/basics/Telemetry*.h" # 0 tracked paths +> - "src/xrpld/app/misc/Telemetry*" # 0 tracked paths > ``` > -> The last two globs match **nothing** on the Phase 10 branch — neither -> `include/xrpl/basics/Telemetry*.h` nor `src/xrpld/app/misc/Telemetry*` exists -> (0 tracked paths). The telemetry code actually lives in -> `src/xrpld/telemetry/**` (9 files, including `MetricsRegistry.cpp`) and -> `src/libxrpl/telemetry/**` (7 files), and **neither is listed**. Consequence: a -> pure C++ telemetry change — new instrument, renamed metric, changed span -> attribute — never triggers this workflow on push. Only edits under -> `docker/telemetry/**` or to the workflow file itself do. Fix: replace the two -> dead globs with `src/xrpld/telemetry/**`, `src/libxrpl/telemetry/**` and -> `include/xrpl/telemetry/**`. +> The last two globs matched **nothing** — neither +> `include/xrpl/basics/Telemetry*.h` nor `src/xrpld/app/misc/Telemetry*` exists. +> The telemetry code lives in `src/xrpld/telemetry/**` (9 files, including +> `MetricsRegistry.cpp`), `src/libxrpl/telemetry/**` (7 files) and +> `include/xrpl/telemetry/**` (10 files), none of which were listed. +> Consequence at the time: a pure C++ telemetry change — new instrument, +> renamed metric, changed span attribute — never triggered this workflow on +> push; only edits under `docker/telemetry/**` or to the workflow file itself +> did. +> +> The two dead globs have been replaced with the three real module directories, +> so the filter now reads: +> +> ```yaml +> paths: +> - ".github/workflows/telemetry-validation.yml" +> - "docker/telemetry/**" +> - "include/xrpl/telemetry/**" +> - "src/libxrpl/telemetry/**" +> - "src/libxrpl/beast/insight/**" +> - "src/xrpld/telemetry/**" +> ``` +> +> `src/libxrpl/beast/insight/**` is included because it holds `OTelCollector.cpp`, +> the `beast::insight` OTLP export path the harness depends on. Residual gap: the +> instrumented call sites scattered through `src/xrpld/app/` are not listed, so a +> change that only adds or moves a span at a call site does not trigger the +> workflow on push. Those are reachable by manual dispatch. -> **Caveat — four inert inputs.** The workflow declares five -> `workflow_dispatch` inputs, but only `run_benchmark` changes behaviour. +> **Caveat — four inert inputs (documented, not wired).** The workflow declares +> five `workflow_dispatch` inputs, but only `run_benchmark` changes behaviour. > `rpc_rate`, `rpc_duration`, `tx_tps` and `tx_duration` are forwarded as > `--rpc-rate` / `--rpc-duration` / `--tx-tps` / `--tx-duration` to > `run-full-validation.sh`, which parses them into shell variables and then @@ -1098,6 +1122,16 @@ workflow on a timer. > `--profile` / `workload-profiles.json` (the orchestrator is invoked with > `--profile` only). Changing those four inputs has no effect on the generated > workload. +> +> Resolution taken: each of the four now carries +> `description: "UNUSED — has no effect. Load shape comes from the workload +profile."`, and a comment above the `inputs:` block plus one at the +> ARGS-building step record why they are kept. They were **labelled, not +> wired**, because wiring them would be a behaviour change: the orchestrator is +> profile-driven, so honouring them means either synthesising a temporary +> profile or reintroducing the pre-profile single-phase load path. That belongs +> in its own change, not in a docs-accuracy pass. The alternative — deleting the +> inputs — would break saved dispatch input sets for no gain. ### Exit Criteria @@ -1108,8 +1142,9 @@ workflow on a timer. - [x] Validation suite confirms the full span / attribute / metric inventory (counts computed dynamically from `expected_spans.json` and `expected_metrics.json`) -- [x] All 14 harness-asserted Grafana dashboards render data (15 on disk; - `log-derived-insights` is provisioned but unasserted) +- [x] All 15 provisioned Grafana dashboards are asserted to load — every uid on + disk is now listed in `grafana_dashboards.uids`. Caveat: the check is + load-and-panel-count only, so it does not prove every panel returns data - [ ] Benchmark shows < 3% CPU overhead, < 5MB memory overhead — needs a measured run - [x] CI workflow runs validation on telemetry branch changes diff --git a/docker/telemetry/workload/README.md b/docker/telemetry/workload/README.md index eb926af6b9..44bbdf3aac 100644 --- a/docker/telemetry/workload/README.md +++ b/docker/telemetry/workload/README.md @@ -5,10 +5,14 @@ Synthetic workload generation and validation tools for xrpld's OpenTelemetry tel ## Quick Start ```bash -# Build xrpld with telemetry enabled -conan install . --build=missing -o telemetry=True -cmake --preset default -Dtelemetry=ON -cmake --build --preset default +# Build xrpld with telemetry enabled (see BUILD.md for the full flow) +mkdir -p .build && cd .build +conan install .. --output-folder . --build missing \ + --settings build_type=Release -o telemetry=True +cmake -DCMAKE_TOOLCHAIN_FILE:FILEPATH=build/generators/conan_toolchain.cmake \ + -DCMAKE_BUILD_TYPE=Release -Dtelemetry=ON .. +cmake --build . --parallel "$(nproc)" --target xrpld +cd .. # Run full validation (starts everything, runs load, validates) docker/telemetry/workload/run-full-validation.sh --xrpld .build/xrpld @@ -27,16 +31,19 @@ spans (proposals, validations), and all metric pipelines. run-full-validation.sh (shell orchestrator) | |-- docker-compose.workload.yaml - | |-- otel-collector (traces via OTLP + StatsD receiver) + | |-- otel-collector (otlp receiver: traces + beast::insight metrics; + | | filelog receiver: node debug.log -> Loki) | |-- tempo (trace backend + TraceQL search API) | |-- prometheus (metrics scraping) + | |-- loki (log aggregation for log-trace correlation) | |-- grafana (dashboards, provisioned automatically) | |-- generate-validator-keys.sh | -> validator-keys.json, validators.txt | |-- Nx xrpld nodes (local processes, full telemetry) - | - Each node: [telemetry] enabled=1, trace_rpc/consensus/transactions + | - Each node: [telemetry] enabled=1, all 5 trace_* categories on + | - [insight] server=otel (beast::insight metrics over OTLP, no StatsD) | - [signing_support] true (server-side signing for tx_submitter) | - Peer discovery via [ips] (not [ips_fixed]) for active peer counts | @@ -60,22 +67,27 @@ each phase, the RPC generator and TX submitter run concurrently. ### Available Profiles -| Profile | Phases | Duration | Purpose | -| ----------------- | ------ | ---------------------------- | ----------------------------------------------------------- | -| `full-validation` | 6 | ~5 min + 1 min propagation | Full 18-dashboard coverage with burst/idle/plateau patterns | -| `quick-smoke` | 1 | ~30s + 30s propagation | Fast CI smoke test | -| `stress` | 3 | ~3.5 min + 1 min propagation | Heavy sustained load for benchmarking | +| Profile | Phases | Duration | Purpose | +| ----------------- | ------ | --------------------------- | ------------------------------------------------------------------------------------------------ | +| `full-validation` | 7 | 4.5 min + 1 min propagation | Coverage for the full asserted span/metric/dashboard inventory, with burst/idle/plateau patterns | +| `quick-smoke` | 1 | 30s + 30s propagation | Fast CI smoke test | +| `stress` | 3 | 3.5 min + 1 min propagation | Heavy sustained load for benchmarking | + +Durations are the sum of the phase `duration_sec` values in +`workload-profiles.json` plus that profile's `propagation_wait_sec`; they exclude +cluster startup and the validation pass itself. ### full-validation Phases -| Phase | RPC Rate | TX TPS | Duration | Dashboard Coverage | -| ------------ | -------- | ------ | -------- | ----------------------------------------------- | -| warmup | 5 RPS | — | 30s | Node Health, Validator Health (baseline gauges) | -| steady-state | 30 RPS | 3 TPS | 60s | All dashboards (plateau data) | -| rpc-burst | 100 RPS | — | 30s | Job Queue, RPC Performance (latency spikes) | -| tx-flood | 5 RPS | 20 TPS | 30s | Fee Market & TxQ, Transaction Overview | -| mixed-peak | 50 RPS | 10 TPS | 60s | Consensus Health, Ledger Operations | -| cooldown | 5 RPS | — | 30s | Recovery patterns, state transitions | +| Phase | RPC Rate | TX TPS | Duration | Dashboard Coverage | +| ------------ | ------------------ | ------ | -------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ | +| warmup | 5 RPS | — | 30s | Node Health, Validator Health (baseline gauges) | +| steady-state | 30 RPS | 3 TPS | 60s | All dashboards (plateau data) | +| rpc-burst | 100 RPS | — | 30s | Job Queue, RPC Performance (latency spikes) | +| tx-flood | 5 RPS | 20 TPS | 30s | Fee Market & TxQ, Transaction Overview | +| txq-burst | 5 RPS (100% `fee`) | 60 TPS | 30s | Fee Market & TxQ — single-type Payment burst that forces open-ledger fee escalation and TxQ queueing, exercising the `txq.*` spans (`txq.enqueue`, `txq.accept`, `txq.accept_tx`, `txq.cleanup`) | +| mixed-peak | 50 RPS | 10 TPS | 60s | Consensus Health, Ledger Operations | +| cooldown | 5 RPS | — | 30s | Recovery patterns, state transitions | ### Custom Profiles @@ -198,12 +210,12 @@ python3 tx_submitter.py --endpoint ws://localhost:6006 \ ### validate_telemetry.py -Automated validation that all expected telemetry data exists. Every metric and span is required — if it doesn't fire, the validation fails. +Automated validation that all expected telemetry data exists. Every metric in `expected_metrics.json` is required — if it doesn't fire, the validation fails. Spans are required unless the entry carries `"optional": true`. -- **Span validation**: All span types from `expected_spans.json` with required attributes and parent-child hierarchies -- **Metric validation**: All metrics from `expected_metrics.json` — SpanMetrics, StatsD gauges/counters/histograms, Phase 9 OTLP metrics. Every listed metric must have > 0 series. Uses the Prometheus `/api/v1/series` endpoint (not instant queries) to avoid false negatives from stale gauges. +- **Span validation**: All span types from `expected_spans.json` with required attributes and parent-child hierarchies. Entries marked `"optional": true` only fire under traffic the harness may not produce (HTTP/JSON-RPC client, gRPC client, missing-ledger fetch, mode transitions); their absence is recorded as a passing skip, not a failure. +- **Metric validation**: All metrics from `expected_metrics.json` — SpanMetrics, `beast::insight` gauges/counters/histograms, Phase 9 OTLP metrics. Every listed metric must have > 0 series. Uses the Prometheus `/api/v1/series` endpoint (not instant queries), polled until the metric appears or the poll window elapses, so a late-populating or quiet series is not a false negative. - **Log-trace correlation**: trace_id/span_id in Loki logs (requires Loki) -- **Dashboard validation**: All 10 Grafana dashboards load with panels +- **Dashboard validation**: Every dashboard uid listed under `grafana_dashboards.uids` in `expected_metrics.json` loads with panels. That list currently covers **all 15** dashboards provisioned in `docker/telemetry/grafana/dashboards/`. Note the scope of this check: it asks the Grafana API whether the dashboard exists and returns a panel count — it does **not** run the panels' queries, so a dashboard can pass here while individual panels render empty. ```bash # Run all validations @@ -276,7 +288,9 @@ Thresholds (configurable via environment): ## Reading Validation Reports -The validation report (`validation-report.json`) is structured as: +The validation report (`validation-report.json`) is structured as follows. The +counts below are illustrative — the real total is the sum of the span, metric, +log, dashboard and parity checks for the run. ```json { @@ -304,46 +318,77 @@ Categories: - **metric**: Prometheus metric existence - **log**: Log-trace correlation checks - **dashboard**: Grafana dashboard accessibility +- **parity**: Span attributes required by the external-parity dashboard panels (validator-health, peer-quality, and friends) ## CI Integration The validation runs as a GitHub Actions workflow (`.github/workflows/telemetry-validation.yml`): -- Triggered manually or on pushes to telemetry branches +- Triggered manually (`workflow_dispatch`) or on pushes to telemetry branches. There is no cron schedule. - Builds xrpld, starts the full stack, runs load, validates -- Uploads reports as artifacts -- Posts summary to PR +- Uploads reports as artifacts (and node logs when validation did not succeed) +- Writes the validation summary and the regression-gate summary to the workflow **Step Summary** (`$GITHUB_STEP_SUMMARY`). It does **not** comment on the PR — the workflow declares no `permissions:` block and calls no GitHub API, so read the summary on the run page. + +Of the five `workflow_dispatch` inputs, only `run_benchmark` changes behaviour. +`rpc_rate`, `rpc_duration`, `tx_tps` and `tx_duration` are forwarded to +`run-full-validation.sh`, which parses them into shell variables and never reads +them again — load shape comes entirely from `--profile` and +`workload-profiles.json`. Their `description:` fields say so. ## Configuration Files -| File | Purpose | -| --------------------------------- | ------------------------------------------------------------- | -| `workload-profiles.json` | Named load profiles with phase definitions | -| `expected_spans.json` | Span inventory (names, attributes, hierarchies, config flags) | -| `expected_metrics.json` | Metric inventory — every listed metric must be present | -| `test_accounts.json` | Test account roles (keys generated at runtime) | -| `regression-metrics.json` | Metric surface for the OTel regression gate | -| `regression-thresholds.json` | Per-metric regression bounds (pct AND abs) | -| `baselines/baseline-timings.json` | Committed baseline — populated from first CI run | -| `requirements.txt` | Python dependencies | +| File | Purpose | +| --------------------------------- | ----------------------------------------------------------------------------------------------------------------------------- | +| `workload-profiles.json` | Named load profiles with phase definitions | +| `expected_spans.json` | Span inventory (names, attributes, hierarchies, config flags) | +| `expected_metrics.json` | Metric inventory — every listed metric must be present — plus the `grafana_dashboards.uids` list the dashboard check iterates | +| `test_accounts.json` | Test account roles (keys generated at runtime) | +| `regression-metrics.json` | Metric surface for the OTel regression gate | +| `regression-thresholds.json` | Per-metric regression bounds (pct AND abs) | +| `baselines/baseline-timings.json` | Committed baseline — populated from first CI run | +| `requirements.txt` | Python dependencies | ### expected_metrics.json Format ```json { + "description": "Top-level doc string — skipped by the validator.", "category_name": { "description": "Human-readable description.", "metrics": ["metric_1", "metric_2"] + }, + "grafana_dashboards": { + "uids": ["rpc-performance", "node-health"] + }, + "not_asserted": { + "description": "Why these are excluded.", + "metrics_excluded": { "metric_3": "reason" } } } ``` -Every metric listed must produce > 0 Prometheus series during the validation run. If a metric doesn't fire, the workload generators need to produce enough load to trigger it. +Every metric listed under a `metrics` array must produce > 0 Prometheus series during the validation run. If a metric doesn't fire, the workload generators need to produce enough load to trigger it. + +Three top-level keys are not metric categories: + +- `description` and `grafana_dashboards` are skipped explicitly by + `validate_metrics`. `grafana_dashboards.uids` drives the dashboard check, so + adding a dashboard to `docker/telemetry/grafana/dashboards/` does **not** put + it under the gate until its uid is added here too. +- `not_asserted` is skipped structurally: the loop reads + `category_data.get("metrics", [])`, and this group deliberately has no + `metrics` key — its entries live under `metrics_excluded` as a name-to-reason + map. It documents metrics that are emitted and dashboarded but left unasserted + because they are workload-gated or defect-gated (a check that fails on a + healthy run is worse than no check). Promote an entry into an asserted group + only after the workload is changed to guarantee it fires. ### expected_spans.json Format Each span entry defines its name, category, parent (for hierarchy validation), -required attributes, and the `config_flag` that must be enabled: +required attributes, and the `config_flag` that must be enabled. A trailing `*` +in `name` is a wildcard. The optional `"optional": true` field marks a span whose +absence is a skip rather than a failure: ```json { @@ -359,13 +404,47 @@ required attributes, and the `config_flag` that must be enabled: The orchestrator (`run-full-validation.sh`) generates node configs with: -- `[telemetry] enabled=1` with all trace categories (`trace_rpc`, `trace_consensus`, `trace_transactions`) +- `[telemetry] enabled=1` with all five trace categories: `trace_rpc`, `trace_transactions`, `trace_consensus`, `trace_peer`, `trace_ledger` +- `[insight] server=otel` with `endpoint=http://localhost:4318/v1/metrics` and `prefix=xrpld` — `beast::insight` metrics reach Prometheus over OTLP, because the collector declares no `statsd` receiver - `[signing_support] true` — required for `tx_submitter.py` to submit signed transactions via WebSocket -- `[ips]` (not `[ips_fixed]`) — ensures peer connections are counted in `Peer_Finder_Active_Inbound/Outbound_Peers` metrics (fixed peers are excluded from these counters by design) +- `[ips]` (not `[ips_fixed]`) — ensures peer connections are counted in the PeerFinder active-peer gauges, exported as `peer_finder_active_inbound_peers` / `peer_finder_active_outbound_peers` (fixed peers are excluded from these counters by design). The `beast::insight` group/name pair is `Peer_Finder` / `Active_Inbound_Peers`; `formatName()` lowercases it for export. -## StatsD Gauge Behaviour +## Gauge Export Behaviour -Beast::insight StatsD gauges only emit when their value _changes_ from the previous sample. This can cause two problems in the validation environment: +The harness configures each node with `[insight] server=otel` (see the +`[insight]` block generated by `run-full-validation.sh`), so `beast::insight` +gauges go through `OTelGaugeImpl` in +`src/libxrpl/beast/insight/OTelCollector.cpp`, not through the StatsD collector. +That matters for how the validator queries Prometheus. -1. **Initial-zero gauges** — if a gauge value is 0 from startup and never changes, the gauge would never emit. To address this, `StatsDGaugeImpl` initializes `m_dirty = true`, ensuring the first flush always emits the initial value. -2. **Stale gauges** — once a gauge stabilizes (e.g., peer count stays at 1), it stops emitting new data points. Prometheus marks it stale after ~5 minutes. The validation script uses the Prometheus `/api/v1/series` endpoint instead of instant queries to catch such gauges. +**How `OTelGaugeImpl` exports.** It wraps an OTel **observable** (asynchronous) +gauge. `set()` and `increment()` only store into an `std::atomic`; +nothing is exported at call time. The SDK's collection thread invokes +`gaugeCallback`, which runs the collector's hooks and then `Observe()`s whatever +the atomic currently holds. So the gauge reports **every collection cycle, +whether or not the value changed** — including a gauge that sits at 0 from +startup. There is no dirty flag on this path, and no first-flush special case is +needed. + +**Why the validator still uses `/api/v1/series`.** Two reasons survive the move +to OTLP: + +1. **Late-populating series.** A gauge or counter may not have completed the + export → collector → Prometheus-scrape pipeline by the time validation runs. + `_check_prometheus_metric` in `validate_telemetry.py` therefore polls + `/api/v1/series` (which returns anything that existed anywhere in the query + window) until the metric appears or the poll window elapses, instead of + racing a single instant query. +2. **Staleness robustness.** `/api/v1/series` does not care whether the newest + sample is inside Prometheus's ~5-minute staleness horizon, so the check + cannot be defeated by a quiet series. + +> **Note — the StatsD path is still in the tree but unused here.** If a node is +> configured with `server=statsd`, `StatsDGaugeImpl` (in +> `src/libxrpl/beast/insight/StatsDCollector.cpp`) does gate emission on a +> `dirty_` flag that is only set by `set()`/`increment()`, and it is +> initialised to `true` so the initial value is emitted on the first flush. The +> collector configs shipped in `docker/telemetry/` declare no `statsd` receiver +> (the metrics pipeline is `[otlp, spanmetrics]`) and the base +> `docker-compose.yml` keeps its StatsD UDP port commented out, so nothing in +> this harness can receive StatsD. diff --git a/docker/telemetry/workload/baselines/README.md b/docker/telemetry/workload/baselines/README.md index 515a3f561f..2f379ba713 100644 --- a/docker/telemetry/workload/baselines/README.md +++ b/docker/telemetry/workload/baselines/README.md @@ -56,17 +56,49 @@ should trace back to a real CI run so variance characteristics are preserved. "profile": "", "metrics": { "span.tx.process.p99": { "value": 12.4, "unit": "ms" }, - "rpc.server_info.p95": { "value": 850.0, "unit": "us" }, "job.transaction.queued.p95": { "value": 1500.0, "unit": "us" } } } ``` +Keys follow `{category}.{name}.p{quantile}`. Only two categories are actually +produced today — `span.*` and `job.*` — because `build_query_plan()` in +`prom_queries.py` reads the `spans` and `job_queue` groups of +`regression-metrics.json`, and that file defines only those two. + Placeholder baselines additionally include `"placeholder": true`. The comparator detects this field (or an empty `metrics` object) to switch into "populate" mode instead of enforcing thresholds. Remove the `placeholder` key when pasting real captured timings. -Missing metrics (value `null`) in a captured run do not count as regressions — they -are reported separately in `regression-report.json` under `missing_in_current`. +Missing metrics (value `null`) in a captured run do not count as regressions. In +`regression-report.json`, `summary.missing_in_current` is a **count** only; the +identities are in the `metrics[]` array, as the entries whose `note` is +`"not captured in current run"`. Filter for those to see which keys went missing: + +```bash +jq -r '.metrics[] | select(.note == "not captured in current run") | .key' \ + /tmp/xrpld-validation/reports/regression-report.json +``` + This keeps the gate robust when a profile doesn't exercise every span on every run. + +## Known gap: no `rpc.*` metric can gate (FU-4) + +Per-RPC-method timings are **not** gated, and would not gate even if they were +captured. Two independent blockers: + +1. **Nothing emits an `rpc.*` key.** `build_query_plan()` in `prom_queries.py` + builds `rpc.*` entries from `cfg.get("rpc_methods", {})`, and + `regression-metrics.json` has no `rpc_methods` block — so the group resolves + to empty and no `rpc.*` key ever reaches `timings.json` or this baseline. +2. **Even a captured `rpc.*` key would silently not gate.** `resolve_thresholds()` + in `compare_to_baseline.py` maps the `rpc` category to the threshold group + `rpc_method`, but `regression-thresholds.json` defines only + `defaults.span` and `defaults.job_queue`. With no `rpc_method` block the + lookup returns `(None, None)`, which the comparator treats as "no threshold + configured" — the metric is reported but can never fail the build. + +Closing this needs **both** an `rpc_methods` group in `regression-metrics.json` +and a `defaults.rpc_method` block in `regression-thresholds.json`. Adding only +the first produces metrics that look gated in the report but are not. diff --git a/docker/telemetry/workload/capture_timings.py b/docker/telemetry/workload/capture_timings.py index 6cba372d4b..4558631cb4 100644 --- a/docker/telemetry/workload/capture_timings.py +++ b/docker/telemetry/workload/capture_timings.py @@ -15,10 +15,10 @@ Output schema (stable — ``compare_to_baseline.py`` reads it verbatim):: "captured_at": "2026-04-24T17:30:00Z", "window": "3m", "git_sha": "", - "profile": "regression", + "profile": "full-validation", "metrics": { "span.tx.process.p99": {"value": 12.4, "unit": "ms"}, - "rpc.server_info.p95": {"value": 850.0, "unit": "us"}, + "job.transaction.queued.p95": {"value": 850.0, "unit": "us"}, ... } } @@ -128,8 +128,13 @@ def main() -> int: ) parser.add_argument( "--profile", - default="regression", - help="Workload profile used during capture (metadata only)", + default="full-validation", + help=( + "Workload profile used during capture, recorded as metadata in the " + "timings file (default: full-validation). Must name a profile in " + "workload-profiles.json; run-full-validation.sh always passes this " + "explicitly." + ), ) parser.add_argument( "--min-capture-ratio", diff --git a/docker/telemetry/workload/expected_metrics.json b/docker/telemetry/workload/expected_metrics.json index 8a5b2be439..5cf408dcfa 100644 --- a/docker/telemetry/workload/expected_metrics.json +++ b/docker/telemetry/workload/expected_metrics.json @@ -1,5 +1,5 @@ { - "description": "Expected metric inventory for xrpld telemetry validation. Metric names have no prefix (the xrpld_ prefix was removed). beast::insight metrics are lowercased by formatName. Sourced from the live Grafana dashboards and MetricsRegistry.cpp.", + "description": "Expected metric inventory for xrpld telemetry validation. Metric names have no prefix (the xrpld_ prefix was removed). beast::insight metrics are lowercased by formatName. Every name here was verified against its declaration in MetricsRegistry.cpp or include/xrpl/telemetry/GetObjectMetricNames.h and against a panel query under docker/telemetry/grafana/dashboards/. IMPORTANT: validate_telemetry.py has no notion of an optional metric — validate_metrics() iterates every group that has a \"metrics\" key and hard-fails any name with 0 Prometheus series after a 45 s poll. A metric is therefore listed only when the harness workload guarantees it will appear: observable gauges/counters whose callbacks Observe unconditionally (series exist at value 0), or push counters/histograms on a path every run exercises. Workload-gated and defect-gated names are recorded in the \"not_asserted\" group, which intentionally has no \"metrics\" key so the validator skips it. Only series existence is checked, never a value, except for the four bounds checks hardcoded in PARITY_VALUE_SANITY.", "spanmetrics": { "description": "SpanMetrics-derived RED metrics from the OTel Collector spanmetrics connector.", "metrics": [ @@ -68,8 +68,22 @@ "metrics": ["txq_metrics"] }, "phase9_rpc_method": { - "description": "Phase 9 per-RPC-method counters (MetricsRegistry via OTLP).", - "metrics": ["rpc_method_started_total"] + "description": "Phase 9 per-RPC-method counters and duration histogram (MetricsRegistry.cpp:351-357). rpc_method_errored_total is deliberately absent — see not_asserted below.", + "metrics": [ + "rpc_method_started_total", + "rpc_method_finished_total", + "rpc_method_us" + ] + }, + "phase9_job_queue": { + "description": "Phase 9 job-queue counters and latency histograms (MetricsRegistry.cpp:360-366). Every xrpld job passes through these, so they populate under any workload.", + "metrics": [ + "job_queued_total", + "job_started_total", + "job_finished_total", + "job_queued_us", + "job_running_us" + ] }, "rpc_in_flight": { "description": "In-flight RPC gauge via the XRPL_METRIC_UPDOWN_ADD call-site macro (PerfLogImp.cpp, +1 rpcStart / -1 rpcEnd). UpDownCounter: no _total suffix.", @@ -116,10 +130,11 @@ "metrics": ["state_tracking{metric=\"state_value\"}"] }, "parity_counters": { - "description": "External dashboard parity: monotonic counters (MetricsRegistry).", + "description": "External dashboard parity: monotonic counters (MetricsRegistry). validations_checked_total is incremented unconditionally at the top of NetworkOPsImp::recvValidation (NetworkOPs.cpp:2681), and run-full-validation.sh brings up a 5-node validator cluster, so inbound validations are guaranteed.", "metrics": [ "ledgers_closed_total", "validations_sent_total", + "validations_checked_total", "state_changes_total" ] }, @@ -127,8 +142,38 @@ "description": "External dashboard parity: storage detail metrics (MetricsRegistry).", "metrics": ["storage_detail{metric=\"stored_object_bytes\"}"] }, + "node_health_gauges": { + "description": "Node-health observable gauges (MetricsRegistry.cpp:997, :1081, :1102, :1161). All four are registered with callbacks that fire on every periodic export and Observe unconditionally (build_info observes a literal 1; server_info and db_metrics read live services; complete_ledgers observes the parsed ledger range, which is non-empty once the cluster has closed a ledger), so their series exist regardless of workload shape.", + "metrics": ["server_info", "build_info", "complete_ledgers", "db_metrics"] + }, + "overlay_reduce_relay": { + "description": "Transaction reduce-relay efficiency gauge (MetricsRegistry.cpp:1354, peer-network dashboard). Backed by Overlay::txMetrics(); TxMetrics::json() emits txr_selected_cnt / txr_suppressed_cnt / txr_not_enabled_cnt unconditionally (TxMetrics.cpp:121-127), so the gauge always reports at least the selected_peers series.", + "metrics": ["reduce_relay_metrics"] + }, + "overlay_overflow": { + "description": "Job-queue transaction overflow total (MetricsRegistry.cpp:609, job-queue dashboard). An ObservableCounter that reads Overlay::getJqTransOverflow() and Observes unconditionally, so the series exists at value 0 even when no overflow occurs.", + "metrics": ["jq_trans_overflow_total"] + }, + "validation_lifetime_counters": { + "description": "Lifetime validation agreement/miss ObservableCounters (MetricsRegistry.cpp:1636, :1658, validator-health dashboard). Both callbacks reconcile the tracker and Observe unconditionally, so the series exist even on a node that has not yet agreed or missed (value 0). Only existence is asserted, never the value — validation_missed_total legitimately dominates on a non-validating node.", + "metrics": ["validation_agreements_total", "validation_missed_total"] + }, + "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.", + "metrics_excluded": { + "rpc_method_errored_total": "MetricsRegistry.cpp:354, push counter — needs an RPC that returns an error. rpc_load_generator.py issues only well-formed server_info / fee / ledger / ripple_path_find calls, 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. Requires sustained fee escalation plus expiry; the CI job drives rpc_load_generator/tx_submitter directly with --rpc-rate/--tx-tps and never runs the workload-profiles.json txq-burst phase, so this is not reachable in CI.", + "txq_dropped_total": "MetricsRegistry.cpp:381, incremented only at TxQ.cpp:1302 / :1347 on queue-full admission refusal. Same reason as txq_expired_total.", + "getobject_rejected_total": "GetObjectMetricNames.h:81, emitted from PeerImp.cpp:2725/:2743 only for a TMGetObjectByHash message refused as oversize or malformed_ledgerhash. A cooperating cluster never sends one.", + "getobject_request_objects": "GetObjectMetricNames.h:86, emitted from PeerImp.cpp:2926 only while serving an inbound TMGetObjectByHash. The XRPL_METRIC_* macros create their instrument lazily on first use (MetricMacros.h:174-285), so no series exists until a peer actually requests objects by hash — which a 5-node cluster started at genesis and already in sync may never do.", + "getobject_lookup_us": "GetObjectMetricNames.h:95, PeerImp.cpp:2929. Same lazy-creation and same inbound-request gate as getobject_request_objects.", + "getobject_lookups_total": "GetObjectMetricNames.h:100, PeerImp.cpp:2949/:2956. Same gate.", + "getobject_charge": "GetObjectMetricNames.h:105, PeerImp.cpp:2931. Same gate." + } + }, "grafana_dashboards": { - "description": "All Grafana dashboards that must render data (UIDs as provisioned on disk under docker/telemetry/grafana/dashboards/).", + "description": "All 15 Grafana dashboards provisioned on disk under docker/telemetry/grafana/dashboards/ (UID == file stem for every one). validate_dashboards() checks that each UID resolves via GET /api/dashboards/uid/ and reports its panel count — it verifies provisioning and loadability, not panel data. log-derived-insights is included on that basis even though its panels are Loki-backed and CI runs with --skip-loki: the dashboard itself must still provision cleanly. Its panel data is not asserted anywhere.", "uids": [ "rpc-performance", "transaction-overview", @@ -143,7 +188,8 @@ "network-traffic", "rpc-pathfinding", "overlay-traffic-detail", - "ledger-data-sync" + "ledger-data-sync", + "log-derived-insights" ] } } diff --git a/docker/telemetry/workload/expected_spans.json b/docker/telemetry/workload/expected_spans.json index f663f303cf..fad53d1a24 100644 --- a/docker/telemetry/workload/expected_spans.json +++ b/docker/telemetry/workload/expected_spans.json @@ -1,5 +1,5 @@ { - "description": "Expected span inventory for xrpld telemetry validation. Attribute keys follow the 2026-05-13 span-attr naming redesign (bare/underscore form; dotted xrpl.* reserved for resource attributes). Sourced from the *SpanNames.h headers. Spans marked \"optional\": true are conditional — they only fire under traffic the harness may not produce (e.g. gRPC client, missing-ledger fetch, mode transitions) and are not failed when absent.", + "description": "Expected span inventory for xrpld telemetry validation. Attribute keys follow the 2026-05-13 span-attr naming redesign (bare/underscore form; dotted xrpl.* reserved for resource attributes). Sourced from the *SpanNames.h headers and verified against the emitting call sites. Spans marked \"optional\": true are conditional — they only fire under traffic the harness may not produce (e.g. gRPC client, missing-ledger fetch, mode transitions) and are not failed when absent. \"parent\" is documentation only (validate_telemetry.py asserts hierarchy from parent_child_relationships, not from this field) and records the parent as the code actually produces it: null means the span is a root or an explicit freshRoot. required_attributes lists only attributes set on EVERY code path that creates the span — attributes set after an early return are described in the span's note instead, because _validate_span_attributes_otlp samples a single trace and would fail on a legitimate short-circuit path. total_unique_attributes is the size of the union of all required_attributes; total_span_types is len(spans). Span EVENTS (consensus.round phase.*/outcome.*, consensus.update_positions dispute.resolve, consensus.accept.apply tx.included) are NOT represented: validate_telemetry.py reads only span name, attributes and timestamps from Tempo, so an \"events\" key would be silently ignored. They are documented in the relevant span notes until the validator gains event support.", "spans": [ { "name": "rpc.ws_message", @@ -9,20 +9,31 @@ "config_flag": "trace_rpc", "note": "WebSocket RPC root span. The load generator uses WS, so this is the RPC entry span (not rpc.http_request, which needs an HTTP/JSON-RPC client)." }, + { + "name": "rpc.ws_upgrade", + "category": "rpc", + "parent": null, + "required_attributes": [], + "config_flag": "trace_rpc", + "optional": true, + "note": "WebSocket handshake span (ServerHandler::onHandoff, ServerHandler.cpp:272-273). A freshRoot with no attributes — only setOk() on success or recordException() on an upgrade failure. Fires once per WS connection, so the load generator produces only a handful of these at connect time; by the time validation runs after the propagation wait they may fall outside the Tempo search window. Optional for that reason, not because the code path is conditional." + }, { "name": "rpc.process", "category": "rpc", - "parent": "rpc.ws_message", + "parent": "rpc.http_request", "required_attributes": [], - "config_flag": "trace_rpc" + "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 cannot appear under the WebSocket-only harness workload." }, { "name": "rpc.command.*", "category": "rpc", - "parent": "rpc.process", + "parent": "rpc.ws_message", "required_attributes": ["command", "version", "rpc_role", "rpc_status"], "config_flag": "trace_rpc", - "note": "Wildcard — matches rpc.command.server_info, rpc.command.ledger, etc." + "note": "Wildcard — matches rpc.command.server_info, rpc.command.ledger, etc. Created as an ambient (scoped) child in rpc::doCommand / rpc::callMethod (RPCHandler.cpp:168, :271), so its parent is whichever transport span is active on the thread: rpc.ws_message on the WebSocket path (the harness workload) and rpc.process on the HTTP/JSON-RPC path." }, { "name": "rpc.http_request", @@ -113,7 +124,7 @@ "required_attributes": ["queue_size", "ledger_changed"], "config_flag": "trace_transactions", "optional": true, - "note": "Ledger-close accept loop. Fires on the consensus thread; only meaningful when the queue is non-empty." + "note": "Ledger-close accept loop (TxQ::accept, TxQ.cpp:1499). Only meaningful when the queue is non-empty. Root on BOTH call paths, verified: the consensus path (RCLConsensus.cpp:823, inside doAccept) and the switchLastClosedLedger jump path (NetworkOPs.cpp:2150). The span is a ScopedSpanGuard, so it adopts whatever OTel context is ambient — but consensus.accept and consensus.accept.apply are unscoped thread-free SpanGuards and activate() is never called outside unit tests, so no consensus span is ever the ambient parent on the JtAccept worker. ledger.build's ScopedSpanGuard has already been destroyed by the time OpenLedger::accept runs." }, { "name": "txq.accept_tx", @@ -134,7 +145,8 @@ "parent": null, "required_attributes": ["ledger_seq", "expired_count"], "config_flag": "trace_transactions", - "optional": true + "optional": true, + "note": "TxQ::processClosedLedger (TxQ.cpp:1403). Root on BOTH call paths for the same reason as txq.accept: the consensus path (RCLConsensus.cpp:950) and the switchLastClosedLedger jump path (NetworkOPs.cpp:2121) both run with no consensus span activated as ambient context." }, { "name": "consensus.round", @@ -148,7 +160,7 @@ "consensus_phase" ], "config_flag": "trace_consensus", - "note": "Root consensus span created per round. Also carries trace_strategy, previous_ledger_seq, previous_proposers, previous_round_time_ms." + "note": "Root consensus span created per round. Also carries trace_strategy, previous_ledger_seq, previous_proposers, previous_round_time_ms. Emits seven span EVENTS that this manifest cannot assert: phase.open, phase.recovery, phase.establish, phase.accepted, outcome.yes, outcome.moved_on, outcome.expired (declared ConsensusSpanNames.h:265-277; emitted RCLConsensus.cpp:1344 and via onPhaseEvent/onOutcomeEvent from Consensus.h:764, 793, 1047, 1517-1525, 1530, 1566). validate_telemetry.py reads only span name, attributes and start/end timestamps from the Tempo OTLP payload — it has no event assertion support — so adding an \"events\" key here would be silently ignored. Recorded as a note instead; asserting events needs validator support first." }, { "name": "consensus.phase.open", @@ -188,25 +200,27 @@ { "name": "consensus.update_positions", "category": "consensus", - "parent": "consensus.round", + "parent": "consensus.establish", "required_attributes": [ "converge_percent", "proposers", "disputes_count" ], - "config_flag": "trace_consensus" + "config_flag": "trace_consensus", + "note": "childSpan of establishSpanContext_ (Consensus.h:1628), so the parent is consensus.establish — not consensus.round. Also emits a dispute.resolve span EVENT per resolved dispute (Consensus.h:1697-1698), which validate_telemetry.py cannot assert (no event support)." }, { "name": "consensus.check", "category": "consensus", - "parent": "consensus.round", + "parent": "consensus.establish", "required_attributes": [ "agree_count", "disagree_count", "threshold_percent", "consensus_result" ], - "config_flag": "trace_consensus" + "config_flag": "trace_consensus", + "note": "childSpan of establishSpanContext_ (Consensus.h:1837), so the parent is consensus.establish — not consensus.round." }, { "name": "consensus.accept", @@ -228,7 +242,7 @@ "resolution_direction" ], "config_flag": "trace_consensus", - "note": "Also carries close_time_correct, close_resolution_ms, consensus_state, proposing, round_time_ms, tx_count." + "note": "Also carries close_time_correct, close_resolution_ms, consensus_state, proposing, round_time_ms, tx_count. Emits a tx.included span EVENT per transaction in the accepted set (RCLConsensus.cpp:666, with a tx_id attribute), which validate_telemetry.py cannot assert (no event support)." }, { "name": "consensus.validation.send", @@ -262,11 +276,11 @@ { "name": "consensus.mode_change", "category": "consensus", - "parent": null, + "parent": "consensus.round", "required_attributes": ["mode_old", "mode_new"], "config_flag": "trace_consensus", "optional": true, - "note": "Only fires on an operating-mode transition; a steady cluster rarely changes mode after warmup." + "note": "childSpan of roundSpanContext_ (RCLConsensus.cpp:1101), so the parent is consensus.round. Only fires on an operating-mode transition; a steady cluster rarely changes mode after warmup. A mode change outside a round leaves roundSpanContext_ invalid, which yields a null (no-op) guard rather than a root span." }, { "name": "ledger.build", @@ -299,47 +313,37 @@ "name": "ledger.acquire", "category": "ledger", "parent": null, - "required_attributes": [ - "ledger_seq", - "acquire_reason", - "timeouts", - "peer_count", - "outcome" - ], + "required_attributes": ["ledger_seq", "acquire_reason"], "config_flag": "trace_ledger", "optional": true, - "note": "Only fires when a node must fetch a missing ledger (InboundLedger). A healthy local cluster rarely back-fills history." + "note": "Only fires when a node must fetch a missing ledger (InboundLedger). A healthy local cluster rarely back-fills history. ledger_seq and acquire_reason are set unconditionally in init() (InboundLedger.cpp:116, :131) and are therefore required. outcome, timeouts and peer_count are set only on the done() path (InboundLedger.cpp:508-515); init() can satisfy the acquisition from the local store or bail on failed_/!complete_ and return without reaching done(), so those three cannot be required." }, { "name": "peer.proposal.receive", "category": "peer", "parent": null, - "required_attributes": ["peer_id", "proposal_trusted"], - "config_flag": "trace_peer" + "required_attributes": ["peer_id"], + "config_flag": "trace_peer", + "note": "peer_id is set immediately after the freshRoot (PeerImp.cpp:1925) and is the only unconditional attribute. proposal_trusted is set at PeerImp.cpp:1953, after several early returns (stale/duplicate/self-originated proposal checks), so a single rejected proposal in the sampled trace would fail the check — it is therefore not required." }, { "name": "peer.validation.receive", "category": "peer", "parent": null, - "required_attributes": [ - "peer_id", - "validation_trusted", - "ledger_hash", - "full_validation" - ], + "required_attributes": ["peer_id", "ledger_hash", "full_validation"], "config_flag": "trace_peer", - "note": "ledger_hash and full_validation are shared with consensus.validation.send (same keys, told apart by span name)." + "note": "ledger_hash and full_validation are shared with consensus.validation.send (same keys, told apart by span name). Both are set at PeerImp.cpp:2573-2574, BEFORE the isCurrent() gate, so only a too-small or unparseable validation skips them — they stay required (and validate_telemetry.py's PARITY_SPAN_ATTRS already asserts them independently). validation_trusted is set at PeerImp.cpp:2591, after the isCurrent() early return at :2576-2584, so a single not-current validation in the sampled trace would fail the check — it is therefore not required." }, { "name": "pathfind.request", "category": "pathfind", - "parent": null, + "parent": "rpc.command.*", "required_attributes": [ "pathfind_source_account", "pathfind_dest_account" ], "config_flag": "trace_rpc", - "note": "Fires on ripple_path_find / path_find RPC. Driven by the ripple_path_find load in rpc_load_generator.py." + "note": "Fires on ripple_path_find / path_find RPC. Driven by the ripple_path_find load in rpc_load_generator.py. 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." }, { "name": "pathfind.compute", @@ -384,12 +388,21 @@ "child": "rpc.process", "description": "WebSocket message contains processing span", "skip": true, - "skip_reason": "rpc.ws_message and rpc.process run on different threads (the WS handler posts a coroutine to JobQueue for processing). Span context is not propagated across the thread boundary. Requires a C++ fix to capture and forward the span context through the coroutine lambda." + "skip_reason": "This relationship does not exist in the code: rpc.process is created only in ServerHandler::processRequest() (ServerHandler.cpp:705), reached only from processSession(Session, coro) (ServerHandler.cpp:646) — the HTTP/JSON-RPC path. The WebSocket path (processSession(WSSession, coro, jv), ServerHandler.cpp:467) never calls processRequest, so rpc.process is never emitted at all under the WebSocket-only harness. The earlier diagnosis (cross-thread context loss needing a C++ fix) was wrong: rpc.ws_message is a deliberate freshRoot (ServerHandler.cpp:473-474) so each WS message is its own trace rather than nesting under a span leaked on a reused coroutine worker. Nothing to fix." + }, + { + "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)", + "skip": true, + "skip_reason": "Code-verified real, but not assertable by the current validator. _validate_parent_child() collapses the wildcard to the single literal name via child_name.replace(\"*\", \"server_info\") and samples only the 3 most recent parent traces. Each rpc.ws_message trace carries exactly one command, and server_info is 25/103 of rpc_load_generator.py's DEFAULT_WEIGHTS, so roughly 43% of healthy runs would sample three non-server_info traces and fail. Asserting this needs the validator to accept a wildcard child as a prefix match (or to raise the trace sample size); until then the relationship is documented, not enforced." }, { "parent": "rpc.process", "child": "rpc.command.*", - "description": "Processing span contains per-command span" + "description": "Processing span contains per-command span (HTTP/JSON-RPC path only)", + "skip": true, + "skip_reason": "Real relationship, but unreachable here: rpc.process only exists on the HTTP/JSON-RPC path and the harness load generator is WebSocket-only, so there are no rpc.process traces to check. The WS-path equivalent (rpc.ws_message -> rpc.command.*) is asserted above instead." }, { "parent": "ledger.build", @@ -414,6 +427,6 @@ "skip_reason": "pathfind.compute only fires when a path computation actually runs; the self-to-self XRP probe in a fresh cluster with no liquidity returns before computing, so the child is not emitted under the harness workload." } ], - "total_span_types": 40, - "total_unique_attributes": 58 + "total_span_types": 41, + "total_unique_attributes": 62 } diff --git a/docker/telemetry/workload/regression-metrics.json b/docker/telemetry/workload/regression-metrics.json index f475d86fd2..0ea9dcbe86 100644 --- a/docker/telemetry/workload/regression-metrics.json +++ b/docker/telemetry/workload/regression-metrics.json @@ -1,6 +1,6 @@ { "_description": "Metric surface for the OTel-driven regression gate. Each entry names a metric, the quantiles to capture, and how to query Prometheus. The comparator compares current run against baseline-timings.json under these exact keys.", - "_key_format": "{category}.{name}.p{quantile} (e.g. span.tx.process.p99, rpc.server_info.p95, job.transaction.queued.p95)", + "_key_format": "{category}.{name}.p{quantile} (e.g. span.tx.process.p99, job.transaction.queued.p95). Only the categories defined below are captured; there is no rpc_methods group, so no rpc.* key is produced or gated (FU-4).", "spans": { "_query_template": "histogram_quantile({quantile}, sum by (le) (rate(span_duration_milliseconds_bucket{span_name=\"{name}\"}[{window}])))", "_unit": "ms", diff --git a/docker/telemetry/workload/run-full-validation.sh b/docker/telemetry/workload/run-full-validation.sh index c6c292410b..3e9021fc0c 100755 --- a/docker/telemetry/workload/run-full-validation.sh +++ b/docker/telemetry/workload/run-full-validation.sh @@ -286,7 +286,6 @@ ${IPS_FIXED} enabled=1 service_instance_id=validator-${i} endpoint=http://localhost:4318/v1/traces -exporter=otlp_http batch_size=512 batch_delay_ms=2000 max_queue_size=2048 diff --git a/docker/telemetry/workload/workload-profiles.json b/docker/telemetry/workload/workload-profiles.json index 84abcf3ed0..958f3524fa 100644 --- a/docker/telemetry/workload/workload-profiles.json +++ b/docker/telemetry/workload/workload-profiles.json @@ -1,7 +1,7 @@ { "profiles": { "full-validation": { - "description": "Full 18-dashboard coverage with burst/idle/plateau patterns", + "description": "Full coverage of all 15 provisioned dashboards (14 assert metric data; log-derived-insights is Loki-backed and only checked for provisioning) with burst/idle/plateau patterns across 7 phases", "phases": [ { "name": "warmup", diff --git a/docs/telemetry-runbook.md b/docs/telemetry-runbook.md index a5496f7f94..d6584e4637 100644 --- a/docs/telemetry-runbook.md +++ b/docs/telemetry-runbook.md @@ -3344,16 +3344,44 @@ docker/telemetry/workload/run-full-validation.sh --xrpld .build/xrpld # Check the report: cat /tmp/xrpld-validation/reports/validation-report.json | jq '.summary' + +# Tear the stack and the node processes down: +docker/telemetry/workload/run-full-validation.sh --cleanup ``` +Harness options (`run-full-validation.sh`): + +| Flag | Default | Effect | +| ------------------- | ----------------- | ----------------------------------------------------------------------------------------------------------------------------------------- | +| `--xrpld PATH` | `.build/xrpld` | Binary to run. Also settable via the `XRPLD` env var. | +| `--nodes NUM` | `5` | Size of the local validator cluster. | +| `--profile NAME` | `full-validation` | Load profile from `workload-profiles.json` (`full-validation`, `quick-smoke`, `stress`). This is the **only** thing that sets load shape. | +| `--skip-loki` | off | Skip the log-trace correlation checks. CI always passes this. | +| `--skip-regression` | off | Skip timing capture and the baseline comparison. Local exploration only. | +| `--with-benchmark` | off | Also run `benchmark.sh` (telemetry-off vs telemetry-on overhead) after validation. | +| `--cleanup` | — | Tear everything down and exit. | + +`--rpc-rate`, `--rpc-duration`, `--tx-tps` and `--tx-duration` are accepted by the +parser but **never read** — they predate profiles and have no effect. Use +`--profile`, or add a profile to `workload-profiles.json`. + +Exit codes: `0` all checks and the regression gate passed; `1` a validation check +failed or the gate detected a regression; `2` infrastructure error (stack or +cluster did not come up, or timing capture failed). + ### What Gets Validated -| Category | Checks | Description | -| ---------- | -------------- | ------------------------------------------------------- | -| Spans | 16+ span types | All span names appear in Tempo with required attributes | -| Metrics | 30+ metrics | SpanMetrics, StatsD gauges/counters, Phase 9 metrics | -| Logs | 2 checks | trace_id/span_id present in Loki, cross-reference works | -| Dashboards | 15 dashboards | All Grafana dashboards load without errors | +The counts are not hard-coded in the validator — it iterates the inventory files, +so those files are authoritative. The figures below are the inventory as it +stands today. + +| Category | Checks | Description | +| ---------- | ----------------------------------------------------------------------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ | +| Spans | Every **required** entry in `expected_spans.json` — 41 span types at the time of writing: 26 required, 15 marked `"optional": true` | Span name found in Tempo carrying its `required_attributes`, plus the declared parent-child relationships. An `"optional": true` entry that does not fire is recorded as a skip, not a failure — it needs traffic the harness may not generate (HTTP/JSON-RPC client, gRPC client, missing-ledger fetch, mode transitions). | +| Metrics | Every entry in every asserted category of `expected_metrics.json` — 52 metrics in 23 categories at the time of writing | SpanMetrics, `beast::insight` gauges/counters exported over OTLP, and the Phase 9 metrics. Each must have > 0 Prometheus series; none are optional. The separate `not_asserted` group lists metrics deliberately left out of the gate because they are workload-gated or defect-gated; it has no `metrics` key, so the validator skips it. | +| Logs | 2 checks | `trace_id`/`span_id` present in Loki, and a Tempo trace id resolves in Loki. Skipped in CI, which runs `--skip-loki`. | +| Parity | 10 checks | 6 span attributes the external-parity dashboard panels read, plus 4 metric value-sanity bounds. | +| Dashboards | Every uid in `expected_metrics.json` under `grafana_dashboards.uids` — currently all 15 provisioned dashboards | Each listed dashboard loads and reports a panel count. This is a provisioning check only: it does **not** execute the panels' queries, so a dashboard can pass while individual panels render empty. `log-derived-insights` is Loki-backed, so under `--skip-loki` only its provisioning is meaningfully covered. | ### Running Individual Tools @@ -3374,8 +3402,134 @@ python3 docker/telemetry/workload/validate_telemetry.py \ ### Interpreting Failures - **Span failures**: Check that the relevant trace category is enabled in `[telemetry]` config (e.g., `trace_rpc=1`). -- **Metric failures**: Verify the OTel Collector is running and Prometheus is scraping port 8889. Check `docker compose logs otel-collector`. -- **Dashboard failures**: Ensure Grafana provisioning is mounted correctly. Check `docker compose logs grafana`. +- **Metric failures**: Verify the OTel Collector is running and Prometheus is scraping port 8889. +- **Dashboard failures**: Ensure Grafana provisioning is mounted correctly. + +`run-full-validation.sh` brings the stack up with +`docker compose -f docker/telemetry/docker-compose.workload.yaml`, so a bare +`docker compose logs` from the repository root finds no project. Pass the same +compose file: + +```bash +docker compose -f docker/telemetry/docker-compose.workload.yaml logs otel-collector +docker compose -f docker/telemetry/docker-compose.workload.yaml logs grafana +docker compose -f docker/telemetry/docker-compose.workload.yaml ps +``` + +### Regression Gate and CI + +The validation checks answer "is the telemetry there?". A second, independent +gate answers "did xrpld get slower?" — it is the part of this harness that can +fail CI on a performance change, so it is worth understanding before you push. + +It runs as step 6 of `run-full-validation.sh`, after validation, and is skipped +only with `--skip-regression`: + +```mermaid +flowchart TB + classDef stage fill:#1d4ed8,stroke:#1e3a8a,color:#fff; + classDef data fill:#047857,stroke:#064e3b,color:#fff; + classDef gate fill:#b45309,stroke:#7c2d12,color:#fff; + classDef out fill:#334155,stroke:#0f172a,color:#fff; + + PROM[("Prometheus
localhost:9090")]:::data + MET["regression-metrics.json
(spans + job_queue groups)"]:::data + CAP["capture_timings.py
--window REGRESSION_WINDOW"]:::stage + TIM["reports/timings.json
(key to value + unit)"]:::data + BASE["baselines/baseline-timings.json
(committed)"]:::data + THR["regression-thresholds.json
(pct AND abs bounds)"]:::data + CMP["compare_to_baseline.py"]:::stage + PH{"baseline is a placeholder
or has no metrics?"}:::gate + PASTE["Print paste-me JSON
exit 0 — gate does NOT run"]:::out + DIFF["Diff per metric
regression = over BOTH bounds"]:::gate + REP["reports/regression-report.json
exit 1 on any regression"]:::out + + MET --> CAP + PROM --> CAP --> TIM --> CMP + BASE --> CMP + THR --> CMP + CMP --> PH + PH -->|yes| PASTE + PH -->|no| DIFF --> REP +``` + +Key properties: + +- **A metric regresses only when it exceeds BOTH the percentage and the absolute + bound.** The `AND` is deliberate: SpanMetrics latency histograms use explicit + buckets, so a quantile sitting near a low bucket boundary can jump a whole + bucket (1 ms to 5 ms) with no real change. Bounds live in + `regression-thresholds.json` — `defaults` per category and quantile, with + per-metric `overrides` (e.g. `span.consensus.ledger_close` is held to 5%). +- **A metric with no configured threshold is captured but never gates.** It is + reported with a note instead. Today only `span.*` and `job.*` keys have + thresholds; `rpc.*` is not produced and would not gate if it were (see + `docker/telemetry/workload/baselines/README.md`). +- **A metric missing from the current run is not a regression.** + `summary.missing_in_current` in `regression-report.json` is a count; the + identities are the `metrics[]` entries whose `note` is + `"not captured in current run"`. +- **`REGRESSION_WINDOW`** (env var, default `3m`) is the window handed to + Prometheus `rate()` during capture. Keep it close to the workload duration — + a longer window dilutes a short-lived regression. `BASELINE_FILE`, + `THRESHOLDS_FILE` and `METRICS_FILE` are also env-overridable. + +```bash +# Validation without the gate (fast local loop): +docker/telemetry/workload/run-full-validation.sh --xrpld .build/xrpld \ + --profile quick-smoke --skip-loki --skip-regression + +# Narrow the rate window to a short profile: +REGRESSION_WINDOW=1m docker/telemetry/workload/run-full-validation.sh \ + --xrpld .build/xrpld --profile quick-smoke + +# Inspect the gate's own output: +jq '.summary' /tmp/xrpld-validation/reports/regression-report.json +jq -r '.metrics[] | select(.regressed) | "\(.key) \(.baseline) -> \(.current) \(.unit)"' \ + /tmp/xrpld-validation/reports/regression-report.json +``` + +#### Refreshing the baseline + +The baseline is a committed file, and moving it is a reviewed change — that PR +review is the audit point for "who moved the performance bar". There is no +automatic promotion from `develop`. + +1. Run the `Telemetry Validation` workflow on the branch. It always captures + timings, so `timings.json` is uploaded as an artifact and the regression + summary is written to the run's Step Summary. +2. If the baseline in the checkout is a placeholder (`"placeholder": true` or an + empty `metrics` object), the Step Summary contains a fenced JSON block under + **"Paste into `baselines/baseline-timings.json`"**, already formatted the way + the file expects (sorted keys, 2-space indent, trailing newline). +3. Open a PR replacing the file contents with that block, dropping the + `placeholder` key. For a refresh of an already-populated baseline, take the + `timings.json` artifact instead and justify the delta in the PR description. + +Never hand-edit `baseline-timings.json` — every entry should trace back to a real +CI run so its variance characteristics are preserved. Details in +`docker/telemetry/workload/baselines/README.md`. + +#### CI workflow + +`.github/workflows/telemetry-validation.yml` runs three jobs — `linux-image-tag` +(reads the CI image tag from the build matrix so this workflow cannot drift onto +a different compiler than the main CI), `build-xrpld` (self-hosted runner, same +container as the main CI, so Conan and ccache hit the shared caches), and +`validate-telemetry` (`ubuntu-latest`, which has Docker). + +- **Triggers**: `workflow_dispatch`, and `push` on `pratik/otel-phase*`, + `feature/otel-*`, `feature/telemetry-*` limited to a `paths` filter covering + the workflow file, `docker/telemetry/**`, and the telemetry sources under + `include/xrpl/telemetry/**`, `src/libxrpl/telemetry/**` and + `src/xrpld/telemetry/**`. There is no cron schedule. +- **Invocation**: `run-full-validation.sh --xrpld --skip-loki`, so the + default `full-validation` profile is used and the Loki checks are skipped. +- **Inputs**: only `run_benchmark` changes behaviour. `rpc_rate`, `rpc_duration`, + `tx_tps` and `tx_duration` are inert, as noted in their descriptions. +- **Results**: reports are uploaded as the `telemetry-validation-reports` + artifact and node logs as `xrpld-node-logs` when validation did not succeed. + Summaries go to the run's Step Summary; the workflow does not comment on PRs. ## Performance Benchmarking @@ -3399,7 +3553,19 @@ docker/telemetry/workload/benchmark.sh --xrpld .build/xrpld --duration 300 If benchmarks exceed thresholds: -1. **Reduce sampling**: `sampling_ratio=0.01` (1% of traces) +1. **Reduce trace volume with collector-side tail sampling.** There is no + `sampling_ratio` config key — xrpld's head sampling is a compile-time + constant fixed at 1.0 + ([Telemetry.h:234](../include/xrpl/telemetry/Telemetry.h#L234) + `static constexpr double samplingRatio = 1.0;`), and + [TelemetryConfig.cpp:139](../src/libxrpl/telemetry/TelemetryConfig.cpp#L139) + explicitly parses nothing for it. Volume reduction is a collector decision. + The only policy shipped is a single 0.5% probabilistic `tail_sampling` + processor in `otel-collector-config.grafanacloud.yaml`; the base + `otel-collector-config.yaml` has **no** tail sampling, so a stock local + stack keeps every trace. Where the Cloud policy is in force it sits on the + trace-storage branch only — spanmetrics runs on a separate branch and still + sees 100% of spans, so the derived RED metrics stay exact. 2. **Disable peer tracing**: `trace_peer=0` (highest volume category) 3. **Increase batch delay**: `batch_delay_ms=10000` (less frequent exports) 4. **Reduce queue size**: `max_queue_size=1024` (back-pressure earlier)