ARCHIVE/rippled
1
0
Fork 0
mirror of https://github.com/XRPLF/rippled.git synced 2026-09-26 23:19:07 +00:00
Code Issues Packages Projects Releases Wiki Activity

fix(telemetry): correct node directory naming and stale gates in the workload harness

Browse Source 
The harness killed and probed node directories named `node<N>`, but the
directories it creates are `validator-<N>` in run-full-validation.sh and
`bench-node-<N>` in benchmark.sh. Verified with pgrep against processes whose
command lines mimic the real ones: the pattern matched nothing either script
produces. Three consequences, all live:

  - `--cleanup` deleted the workdir and left the xrpld processes running. They
    are host processes, so the compose teardown does not reach them.
  - The pre-run cleanup could not free the previous run's RPC, WS and peer
    ports, which surfaces much later as a cluster that never reaches consensus.
  - The startup crash fast-fail read a pid path that never exists, so its
    `stopped > 0` branch was unreachable and a dead node waited out the full
    120-attempt window.

Rather than patch four literals, derive every node path, kill pattern and log
glob from one NODE_PREFIX per script. The directory name is also the node's
identity: the collector's file_log receiver lifts that segment into
service.instance.id, so the directory and the [telemetry] service_instance_id
must agree. Deriving both from one value is what stops them drifting again.

Also in the same files, each confirmed by test rather than inspection:

  - The collector readiness probe could never fail. curl -w '%{http_code}'
    prints 000 on a refused connection and then exits non-zero, so the
    `|| echo 000` inside the substitution appended a second 000 and the
    "not ready" comparison never matched. Move the fallback outside.
  - The generated config wrote [ips], the starter-list section. A loopback mesh
    that must reach quorum is the [ips_fixed] case, which is what the variable,
    the comment and the sibling cfg template already said.
  - benchmark.sh returned exit 1 for a row it could not measure, though the
    exit-code table reserves 1 for "every metric was measured and one breached".
    Report 2 there instead.
  - Five bc computations fell back to 0, which clears every threshold. The
    guards beside them already fall back to the inconclusive token; these now
    do too.
  - A comment claimed a `|| guard` after a heredoc lands in the heredoc, and
    that claim had removed a real guard from the config write. It does not: the
    guard runs, and fires when cat fails.
  - The EXIT trap was installed 88 lines before stop_workload was defined. If it
    fired in that window, errexit aborted the handler on "command not found" and
    the cluster reap never ran. Install it below both handlers.
  - jq exits 5 on malformed JSON, outside this script's documented codes, so
    read_metric now routes that through cannot_measure.
  - --nodes and --duration were unvalidated, and --nodes 0 made the pid-count
    guard compare 0 with 0 and pass, handing the sampler no pids at all.
  - --cleanup now passes -v so the named tempo-data volume goes with it.
    Otherwise the next run's Tempo still serves the previous run's traces and a
    span assertion can be satisfied by them.
  - Five messages reported an attempt count as seconds, though each attempt is
    a sleep plus every node's probe.

The baselines README and the two regression JSON files had gone stale when the
baseline was refreshed to a three-run median: they described 20 gated keys and
five exclusions, against an actual 19 and six, and cited the superseded run,
date and commit. Re-derive every affected figure from the committed files. The
detection floors are recomputed (2.00x to 7.41x, so a 10x regression is now
caught on all 19 keys), the newly excluded span.ledger.build.p99 is documented,
and figures that no committed artifact can verify are either replaced with
derivable ones or labelled with their numerator.

No baseline value, threshold bound or derivation entry changes.
This commit is contained in:
Pratik Mankawde
2026-09-17 15:07:15 +01:00
parent 3b674d822f
commit ffc4ee40fe
5 changed files with 250 additions and 139 deletions
Download Patch File Download Diff File Expand all files Collapse all files

196
docker/telemetry/workload/baselines/README.md
View File

@@ -27,24 +27,35 @@ was invoked with. Capture and comparison are profile-agnostic — they only read
Prometheus — so all existing profiles (`full-validation`, `quick-smoke`, `stress`)
continue to work unchanged.
## Current state: 20 metrics gate, on a baseline captured 2026-08-26
## Current state: 19 metrics gate, on a baseline captured 2026-09-10
`baseline-timings.json` holds real captured values for the 20 keys the harness gates, from CI run
`32964262700` at `8418d474a7`, profile `full-validation`, window `3m`. It replaced a capture taken
at `6a82fc6f37` that predated two workload changes — the removal of the refused path-finding RPC
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'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
in place. They stay retrievable from this file's git history.
`baseline-timings.json` holds real captured values for the 19 keys the harness gates. Every value is
the **median of three clean CI runs** — `34495527952`, `34505215266` and `34507425933` — taken at
`a0385c53cb`, profile `full-validation`, window `3m`. The file records that provenance itself, in
its `source_runs` and `statistic` fields.
The median of three is the point, not a detail. A single-run baseline is what disqualified five of
the six excluded keys below: one sample carries no information about spread, and the bound is
derived from that one sample alone.
It replaced a capture taken 2026-08-26, before the account-funding race was fixed. Phases whose
funding silently failed submitted little or no traffic, so that capture recorded artificially low
ledger and transaction timings. Once funding worked, `span.ledger.build.p99` read 29.00 ms against
its 9.109 ms baseline and turned the gate red on a run whose 200 span and metric checks all passed
— which is why that key is now excluded.
Two earlier generations stay retrievable from this file's git history: a 2026-08-24 capture, and
before it entries captured 2026-06-05 that were voided into a placeholder because they were captured
against the spanmetrics ladder's old 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 those entries had to be dropped rather than left in place.
**A placeholder must not outlive one run.** CI stays green the whole time one stands, so an
un-copied block is not a failure anyone will notice — it is a silent loss of regression coverage
that looks identical to a passing gate. Voiding a baseline is the one hand edit this file allows;
_setting_ one always comes from a printed CI block, per the "Refreshing the baseline" rule below.
that looks identical to a passing gate. Voiding a baseline is the one hand edit that needs no CI
block behind it. Setting one comes from a printed CI block, with a single documented exception —
combining several runs into a median, which nothing automates yet (see [Schema](#schema)).
## Absolute bounds are derived per metric, from the ladder
@@ -61,8 +72,8 @@ fire. Firing needs the quantile to have moved at least two buckets up. A multipl
_enclosing_ bucket's width cannot deliver this, because once the quantile crosses `hi` the
interpolation happens across the **next** bucket, which on this ladder is up to 8x wider —
`(0.5, 1]` is 0.5 ms wide and `(1, 5]` is 4 ms wide. The full derivation, both ladders, and a
per-key table of the arithmetic are in that file's `_absolute_bound_derivation` and
`_derivation_table`.
per-key table of the arithmetic are in that file's `_absolute_bound_derivation`,
`_bucket_note` (both ladders) and `_derivation_table`.
Two earlier generations of this bound were wrong, in opposite directions:
@@ -70,17 +81,24 @@ Two earlier generations of this bound were wrong, in opposite directions:
| ------------------------------ | -------------------------------------------- | --------------------- | ---------------------------------------- |
| flat | 10 ms `p50`/`p95`, 15 ms `p99`, 20000 us job | 5 / 28 keys | 2 / 25 keys |
| 2 × enclosing bucket width | per metric | 28 / 28 keys | **21 / 25 keys** |
| `hi_next − baseline` (current) | per metric | 19 / 20 keys | **0 / 20 keys** |
| `hi_next − baseline` (current) | per metric | **19 / 19 keys** | **0 / 19 keys** |
The first two rows were measured when 28 and 25 keys were gated; the current row was re-measured
over today's 20 by injecting a 10x regression into each gated key in turn against a real CI
`timings.json`. The gate flagged 19. The exception is `job.acceptLedger.running.p95`, whose
detection floor is 16.28x: 10x reaches 61429 us against a 100000 us trip point, and the gate first
fires at 16.28x (measured — 16.2x passes, 16.28x fails). At **20x the sweep catches 20 of 20**. That
is the ladder, not the rule; the key is listed under
[weakly guarded](#which-keys-are-only-weakly-guarded) below. On the 2026-08-24 baseline the same key
had a 5.74x floor and 10x did catch it, which is what a baseline refresh can silently do to
sensitivity. The zero in the last column is by
The first two rows were measured when 28 and 25 keys were gated, by injecting a 10x regression into
each gated key in turn against a real CI `timings.json`. The current row is **derived, not sampled**,
and holds for every key on the 2026-09-10 baseline. A key's detection floor is exactly
`trip point ÷ baseline`, because the gate fires when the reading exceeds the trip point and a `k`x
regression reads `k × baseline`. So a 10x regression is caught precisely when the floor is under 10x,
and the weakest floor on this baseline is 7.41x — see
[weakly guarded](#which-keys-are-only-weakly-guarded) below.
That is a real improvement over the 2026-08-26 baseline, where `job.acceptLedger.running.p95` had a
16.28x floor and was the one key a 10x regression missed. Its baseline rose from 6142.9 us to
15967.7 us while `hi_next` stayed at 100000 us, which pulled its floor down to 6.26x. Note the
direction this can move in: floors are a property of where each baseline lands on the ladder, so a
refresh changes sensitivity without anything about the code changing. Re-derive this table on every
refresh.
The zero in the last column is by
construction rather than by sampling: rule C in
[`check_regression_bounds.py`](../../../../.github/scripts/telemetry/check_regression_bounds.py)
fails the build unless every trip point is exactly `hi_next`, and a trip point at a bucket edge
@@ -105,30 +123,34 @@ signature described below.
### Which keys are only weakly guarded
The guarantee costs sensitivity where the ladder is coarse: the detection floor is
`hi_next / baseline`, so a baseline sitting just above an edge is guarded loosely. Measured over
the current baseline the floor ranges 2.21x to 16.28x. Do **not** read these as guarded:
`hi_next / baseline`, so a baseline sitting just above an edge is guarded loosely. Over the
2026-09-10 baseline the floor ranges 2.00x to 7.41x. Do **not** read these six as guarded:
| key | baseline | fires at | floor | limiting ladder step |
| --------------------------------- | --------- | --------- | ------ | -------------------- |
| `job.acceptLedger.running.p95` | 6142.9 us | 100000 us | 16.28x | 25000 us → 100000 us |
| `span.consensus.accept.p50` | 0.5287 ms | 5 ms | 9.46x | 1 ms → 5 ms |
| `job.transaction.running.p95` | 600.0 us | 5000 us | 8.33x | 1000 us → 5000 us |
| `span.tx.process.p95` | 0.6100 ms | 5 ms | 8.20x | 1 ms → 5 ms |
| `span.rpc.ws_message.p95` | 0.6977 ms | 5 ms | 7.17x | 1 ms → 5 ms |
| `span.consensus.ledger_close.p95` | 0.7830 ms | 5 ms | 6.39x | 1 ms → 5 ms |
| `span.rpc.ws_message.p99` | 0.9757 ms | 5 ms | 5.12x | 1 ms → 5 ms |
| key | baseline | fires at | floor | limiting ladder step |
| --------------------------------- | ---------- | --------- | ----- | -------------------- |
| `span.consensus.ledger_close.p95` | 0.6750 ms | 5 ms | 7.41x | 1 ms → 5 ms |
| `span.consensus.accept.p50` | 1.4364 ms | 10 ms | 6.96x | 5 ms → 10 ms |
| `job.acceptLedger.running.p95` | 15967.7 us | 100000 us | 6.26x | 25000 us → 100000 us |
| `span.rpc.ws_message.p95` | 0.8122 ms | 5 ms | 6.16x | 1 ms → 5 ms |
| `span.rpc.ws_message.p99` | 0.9873 ms | 5 ms | 5.06x | 1 ms → 5 ms |
| `span.tx.process.p99` | 0.9940 ms | 5 ms | 5.03x | 1 ms → 5 ms |
`job.acceptLedger.running.p95` is the one that matters most, because it is the only gated key a
10x regression does not catch (see the generation table above). Its floor moved there **in this
refresh**, from 5.74x: the baseline fell from 17428.6 us to 6142.9 us while `hi_next` stayed at
100000 us. It does **not** fire on any observed run — its worst reading is 0.16 of its trip point —
so it stays gated, and the weak floor is recorded here so it is visible rather than surprising. The
fix is a 2 ms edge (ideally 3 ms as well) in the collector's spanmetrics `buckets` list plus the
Four of the six are limited by the same `1 ms → 5 ms` step, which is where this ladder is coarsest
relative to how the spans actually behave. None of the six fires on any observed run, so all six
stay gated; the weak floor is recorded here so it is visible rather than surprising.
The fix is a 2 ms edge (ideally 3 ms as well) in the collector's spanmetrics `buckets` list plus the
matching entries in `kMillisecondBuckets`, and 2000 us plus 50000 us edges in `kMicrosecondBuckets`.
That work belongs to the branch that owns the ladders.
`job.transaction.running.p95` and `span.tx.process.p95` were on this list against the 2026-08-26
baseline, at 8.33x and 8.20x, and both dropped off it in the refresh — 2.65x and 2.00x now.
`span.tx.process.p95` is the tightest gated key on this baseline — 0.50 on baseline over trip point,
and 0.76 on the observed maximum across the three source runs — so it is the first to re-measure if
the gate reddens. The two ratios have different numerators; neither is the other.
`span.tx.apply.p50` is absent from this table because it is **no longer gated at all** — see
[what all five excluded keys have in common](#what-all-five-excluded-keys-have-in-common). Beyond
[what all six excluded keys have in common](#what-all-six-excluded-keys-have-in-common). Beyond
its variance it had a second, independent problem: its baseline of `0.00597` ms sat inside the
ladder's **first** bucket `(0, 0.01]`, so the reported figure was interpolation across that bucket,
tracking the _fraction_ of applies finishing under 10 us rather than a latency — the same mechanism
@@ -165,13 +187,15 @@ exclusion at _quantile_ rather than _span_ granularity, which is why
lists span names and `_quantiles` is shared across all of them, so removing two quantiles of one
span cannot be expressed by deleting a name.
Measured across four CI runs:
Measured across four CI runs, against the baseline in force **when the two keys were excluded**.
The `p50` row is the only one still gated. Its baseline was 0.0779 ms then and is 0.0598 ms now, with
the same 0.25 ms trip point either way, so the argument is unchanged:
| key | baseline | trip point | observed min | observed max | spread |
| --------------------------------- | --------- | ---------- | ------------ | ------------ | ------ |
| `span.ledger.validate.p50` (kept) | 0.0647 ms | 0.25 ms | 0.0484 ms | 0.0778 ms | 1.6x |
| `span.ledger.validate.p95` | 0.2404 ms | 0.5 ms | 0.1281 ms | 0.7500 ms | 5.9x |
| `span.ledger.validate.p99` | 1.0600 ms | 10 ms | 0.3875 ms | 25.8750 ms | 66.8x |
| key | baseline at exclusion | trip point | observed min | observed max | spread |
| --------------------------------- | --------------------- | ---------- | ------------ | ------------ | ------ |
| `span.ledger.validate.p50` (kept) | 0.0779 ms | 0.25 ms | 0.0484 ms | 0.0778 ms | 1.6x |
| `span.ledger.validate.p95` | 0.2404 ms | 0.5 ms | 0.1281 ms | 0.7500 ms | 5.9x |
| `span.ledger.validate.p99` | 1.0600 ms | 10 ms | 0.3875 ms | 25.8750 ms | 66.8x |
Both excluded quantiles reach past their trip point on an ordinary run, so CI reddened twice with
no code change: run `32867433073` read `p95` = 0.7500 ms (+212%) and run `32862589645` read
@@ -206,9 +230,9 @@ 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 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):
That is what happened to three `p50` keys on the **2026-08-26** 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 produced that baseline):
| key | bound | trip point | observed max | max ÷ trip | spread |
| --------------------------------- | --------- | ---------- | ------------ | ---------- | ------ |
@@ -216,15 +240,15 @@ this rule being applied, not a new exception. Measured across the three CI runs
| `span.ledger.build.p50` | 0.3849 ms | 0.5 ms | 2.3826 ms | **4.77x** | 20.7x |
| `span.consensus.ledger_close.p50` | 0.0613 ms | 0.1 ms | 0.2377 ms | **2.38x** | 6.1x |
Before the exclusion, replaying **either** older run against this baseline reported exactly those
Before the exclusion, replaying **either** older run against that baseline reported exactly those
three and nothing else — and run `32867433073` carries the same post-path-finding-removal workload
as the baseline itself, so the movement was metric variance, not a workload difference. Those two
runs are what would have reddened CI. After the exclusion both replay clean.
The evidence that settles it is `span.tx.apply.p50`'s own history. It read **0.7917 ms** in the
previous baseline and **0.00597 ms** in this one — a 132x difference between two runs of the same
workload. At the old value the identical `hi_next − baseline` rule produced a 4.21 ms bound whose
5 ms trip point absorbed the entire range; at the new value it produces 0.0440 ms and cannot.
2026-08-24 baseline and **0.00597 ms** in the 2026-08-26 one — a 132x difference between two runs of
the same workload. At the old value the identical `hi_next − baseline` rule produced a 4.21 ms bound
whose 5 ms trip point absorbed the entire range; at the new value it produces 0.0440 ms and cannot.
Nothing about the metric changed. **Whether the gate functioned was decided by where in its own
distribution the captured run happened to land** — which is not a threshold that needs tuning, it
is a key that cannot be gated from a single-run baseline at all.
@@ -232,9 +256,12 @@ is a key that cannot be gated from a single-run baseline at all.
So the remedy is the `excluded_keys` entry with the measurement behind it, exactly as
`ledger.validate` p95 and p99 got — **not** a widened bound, and **not** re-baselining until a run
lands favourably. A key that fails this test is never fixed by widening its bound. The remaining
20 gated keys sit at or below 0.58 of their trip points, the worst being `span.consensus.accept.p50`.
19 gated keys sit between 0.14 and 0.50 of their **baseline** over their trip point, the tightest
being `span.tx.process.p95` at 0.50. That ratio is derivable from the two committed JSON files, so it
is checkable; a headroom figure against each key's observed maximum is not, because no per-run
`timings.json` is committed.
### What all five excluded keys have in common
### What all six excluded keys have in common
| key | trip point | observed max | mechanism |
| --------------------------------- | ---------- | ------------ | ------------------------------------- |
@@ -243,19 +270,29 @@ lands favourably. A key that fails this test is never fixed by widening its boun
| `span.ledger.build.p50` | 0.5 ms | 2.3826 ms | baseline in a low bucket |
| `span.ledger.validate.p95` | 0.5 ms | 0.7500 ms | baseline in a low bucket |
| `span.ledger.validate.p99` | 10 ms | 25.8750 ms | spread too large for any bound |
| `span.ledger.build.p99` | 25 ms | 29.0000 ms | spread too large for any bound |
One invariant covers all five: **the observed maximum exceeds `baseline + bound`**, so an ordinary
run clears the trip point with nothing having regressed. Two mechanisms produce it. Four of the five
One invariant covers all six: **the observed maximum exceeds `baseline + bound`**, so an ordinary
run clears the trip point with nothing having regressed. Two mechanisms produce it. Four of the six
have a baseline sitting low in the ladder, where the derived bound is tiny because the bound _is_
the distance to the next edge up. The fifth, `ledger.validate.p99`, has a comparatively generous
8.94 ms bound and still fails, because a 66.8x spread reaches 25.875 ms against a 10 ms trip point.
the distance to the next edge up. The other two fail despite generous bounds:
`ledger.validate.p99` has 8.94 ms and a 66.8x spread that reaches 25.875 ms against a 10 ms trip
point, and `ledger.build.p99` has 16.056 ms and a 4.11x spread whose maximum is 1.16x its trip
point.
**The follow-up that would restore coverage**, stated rather than 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.
`span.ledger.build.p99` is the newest of the six and the clearest illustration of the rule, because
the previous baseline **hid** it: at 9.109 ms the same rule also gave a 25 ms trip point, and the key
read as gated only because both the capture and the comparison runs happened to land low. Ledger
construction keeps coverage through `span.ledger.build.p95`, whose baseline sits at 0.48 of its trip
point.
**The follow-up that would restore coverage**, stated rather than left implied: a bound derived from
the ladder alone cannot support these keys, because it carries no information about spread. What
would let them be gated again is a bound sized against **observed variance** — a spread measurement
captured alongside the baseline, rather than the ladder distance only. The 2026-09-10 baseline is
already a median of three runs, which is the raw material for that; using the spread to size bounds
is the part that is not implemented, and it is the design change these six exclusions are waiting
on.
## Bootstrapping the baseline
@@ -346,9 +383,11 @@ debug-level detail, enable it per partition **after** the baseline exists.
"window": "3m",
"git_sha": "<SHA of the commit that produced these numbers>",
"profile": "<workload profile used>",
"source_runs": [34495527952, 34505215266, 34507425933],
"statistic": "median of three clean full-validation runs",
"capture": {
"declared": 20,
"captured": 20,
"declared": 19,
"captured": 19,
"min_ratio": 0.5,
"complete": true
},
@@ -359,6 +398,21 @@ debug-level detail, enable it per partition **after** the baseline exists.
}
```
`source_runs` and `statistic` record how the numbers were arrived at, and the committed baseline
carries both. They matter because the bound-derivation rule reads the baseline as a single number:
if `statistic` says the values are a median of several runs, a reviewer knows the spread was
observable, and if it is absent the baseline came from one run and every key on it is exposed to the
single-run problem described under
[The general rule this exposed](#the-general-rule-this-exposed). Neither field is read by any
script; they are provenance, like `git_sha`.
`capture_timings.py` emits neither field, and no script in this directory combines several runs, so
a multi-run baseline is currently assembled by hand and these two fields are how that is declared.
That is a gap, not a workflow: it sits outside the paste-from-CI rule the rest of this file
describes, so the median and the run ids are only as trustworthy as the PR that introduced them.
Automating the combination — and having it write both fields — is part of the multi-run baseline work
the exclusions are waiting on.
`capture` describes the capture that produced the file, not the metrics in it:
`declared` is how many keys the surface asked for, `captured` how many came back with a
value, `min_ratio` the bar they were judged against, and `complete` the verdict. It is a

101
docker/telemetry/workload/benchmark.sh
View File

@@ -86,6 +86,14 @@ PEER_PORT_BASE=51250
# Above run-full-validation.sh's 6006.. so both harnesses can share a box.
WS_PORT_BASE=6020
# Name stem of each node's directory: node i lives in $WORKDIR/$NODE_PREFIX-$i.
# Every node path and kill pattern below derives from it, and so does the
# service_instance_id the telemetry arm reports. The telemetry arm exports to the
# same endpoint the workload harness uses, so a stem that differs from that
# harness's is what keeps the two clusters apart in the backend. Deriving both
# from one value is what stops the directory and the reported id drifting.
NODE_PREFIX="bench-node"
# Head start the generators get before the sampler opens its window.
# tx_submitter.py creates and funds eight accounts from genesis and then waits
# for those payments to validate, so without a lead the first seconds of every
@@ -148,6 +156,19 @@ done
# Validate prerequisites. A missing binary or tool means no measurement can be
# taken, which is "cannot measure", not "too slow".
# Validate the two numeric options before anything derives ports, loop counts or
# pid-count guards from them. --nodes 0 is the dangerous one: node_pids_csv then
# yields an empty list, awk reports 0 fields, and the "found N of NUM_NODES pids"
# guard compares 0 with 0 and passes, handing the sampler no pids at all.
case "$NUM_NODES" in
'' | *[!0-9]*) cannot_measure "--nodes must be a positive integer, got '$NUM_NODES'" ;;
esac
[ "$NUM_NODES" -ge 1 ] || cannot_measure "--nodes must be at least 1, got '$NUM_NODES'"
case "$DURATION" in
'' | *[!0-9]*) cannot_measure "--duration must be a positive integer, got '$DURATION'" ;;
esac
[ "$DURATION" -ge 1 ] || cannot_measure "--duration must be at least 1, got '$DURATION'"
[ -x "$XRPLD" ] || cannot_measure "xrpld not found at $XRPLD"
command -v jq >/dev/null 2>&1 || cannot_measure "jq not found"
command -v bc >/dev/null 2>&1 || cannot_measure "bc not found"
@@ -189,7 +210,7 @@ start_cluster() {
# Build per-node configs.
for i in $(seq 1 "$NUM_NODES"); do
local node_dir="$WORKDIR/bench-node-$i"
local node_dir="$WORKDIR/$NODE_PREFIX-$i"
mkdir -p "$node_dir/nudb" "$node_dir/db" ||
cannot_measure "Could not create node$i directories under $node_dir"
@@ -227,7 +248,7 @@ start_cluster() {
telemetry_section="
[telemetry]
enabled=1
service_instance_id=bench-node-${i}
service_instance_id=$NODE_PREFIX-${i}
endpoint=http://localhost:4318/v1/traces
exporter=otlp_http
batch_size=512
@@ -251,10 +272,10 @@ endpoint=http://localhost:4318/v1/metrics"
enabled=0"
fi
# No `|| cannot_measure` here: a guard after `<<EOCFG` is read as the
# heredoc's first line, so it lands in the config and never runs. The
# mkdir above already covers the only realistic failure.
cat >"$node_dir/xrpld.cfg" <<EOCFG
# Guarded like every other fallible write. An unwritable node_dir would
# otherwise surface as cat's status 1, the code this script reserves for a
# measured threshold breach.
cat >"$node_dir/xrpld.cfg" <<EOCFG || cannot_measure "Could not write $node_dir/xrpld.cfg"
[server]
port_rpc
port_ws
@@ -361,18 +382,16 @@ stop_cluster() {
log "Stopping cluster..."
for i in $(seq 1 "$NUM_NODES"); do
local pidfile="$WORKDIR/bench-node-$i/xrpld.pid"
local pidfile="$WORKDIR/$NODE_PREFIX-$i/xrpld.pid"
if [ -f "$pidfile" ]; then
kill "$(cat "$pidfile")" 2>/dev/null || true
fi
done
# Belt and braces for a node whose pidfile is missing or stale. Matched on
# the per-node config path — the shape start_cluster launches nodes with
# (`--conf $WORKDIR/nodeN/xrpld.cfg`) — rather than on the workdir alone.
# The loose form killed anything whose command line merely mentioned the
# workdir, including a developer's `tail -f $WORKDIR/node1/debug.log`, and
# the EXIT trap now makes this run on every exit path.
pkill -f "$WORKDIR/node[0-9]+/xrpld\.cfg" 2>/dev/null || true
# Belt and braces for a node whose pidfile is missing or stale. Matched on the
# per-node config path start_cluster launches with, not the workdir alone: a
# workdir-only pattern would also match anything that merely mentions the
# tree, such as a developer's `tail -f` on a node's debug.log.
pkill -f "$WORKDIR/$NODE_PREFIX-[0-9]+/xrpld\.cfg" 2>/dev/null || true
# Guarded on purpose. This runs as the EXIT trap, where any unguarded
# failure makes `set -e` exit with that command's status and discard the
@@ -384,12 +403,6 @@ stop_cluster() {
return 0
}
# Reap the cluster on every exit path. Installed here rather than straight
# after argument parsing so the handler name always resolves. Without it, any
# failure between start_cluster and stop_cluster leaks the xrpld children
# along with their RPC ports (5020+) and peer ports (51250+).
trap 'stop_workload; stop_cluster' EXIT
# Build RPC ports CSV string.
rpc_ports_csv() {
local ports=""
@@ -422,7 +435,7 @@ ws_endpoints() {
node_pids_csv() {
local i out="" pid
for i in $(seq 1 "$NUM_NODES"); do
pid=$(cat "$WORKDIR/bench-node-$i/xrpld.pid" 2>/dev/null) || continue
pid=$(cat "$WORKDIR/$NODE_PREFIX-$i/xrpld.pid" 2>/dev/null) || continue
[ -n "$pid" ] && out="$out,$pid"
done
printf '%s' "${out#,}"
@@ -485,6 +498,14 @@ stop_workload() {
return 0
}
# Reap the workload and the cluster on every exit path. Installed below both
# handlers, not after argument parsing: if the trap fires while either name is
# still undefined, errexit aborts the handler on "command not found" and the
# rest of it -- the cluster reap -- never runs. Without the trap, any failure
# between start_cluster and stop_cluster leaks the xrpld children along with
# their RPC ports (5020+) and peer ports (51250+).
trap 'stop_workload; stop_cluster' EXIT
collect_metrics() {
local label="$1"
local out_file="$2"
@@ -548,26 +569,31 @@ INCONCLUSIVE="n/a"
read_metric() {
local file="$1"
local key="$2"
jq -r ".$key // 0" "$file"
# jq exits 5 on malformed JSON and 2 on a missing file. Neither is one of
# this script's three documented codes, and a bare assignment would let it
# escape through errexit, so route both through cannot_measure.
jq -r ".$key // 0" "$file" 2>/dev/null ||
cannot_measure "$file is not readable JSON — refusing to compare an unreadable run"
}
BASE_CPU=$(read_metric "$BASELINE_FILE" "cpu_pct_avg")
TELE_CPU=$(read_metric "$TELEMETRY_FILE" "cpu_pct_avg")
CPU_DELTA=$(echo "scale=2; $TELE_CPU - $BASE_CPU" | bc 2>/dev/null || echo "0")
CPU_DELTA=$(echo "scale=2; $TELE_CPU - $BASE_CPU" | bc 2>/dev/null || echo "$INCONCLUSIVE")
BASE_MEM=$(read_metric "$BASELINE_FILE" "memory_rss_mb_peak")
TELE_MEM=$(read_metric "$TELEMETRY_FILE" "memory_rss_mb_peak")
MEM_DELTA=$(echo "scale=2; $TELE_MEM - $BASE_MEM" | bc 2>/dev/null || echo "0")
MEM_DELTA=$(echo "scale=2; $TELE_MEM - $BASE_MEM" | bc 2>/dev/null || echo "$INCONCLUSIVE")
BASE_RPC=$(read_metric "$BASELINE_FILE" "rpc_p99_ms")
TELE_RPC=$(read_metric "$TELEMETRY_FILE" "rpc_p99_ms")
RPC_DELTA=$(echo "scale=2; $TELE_RPC - $BASE_RPC" | bc 2>/dev/null || echo "0")
RPC_DELTA=$(echo "scale=2; $TELE_RPC - $BASE_RPC" | bc 2>/dev/null || echo "$INCONCLUSIVE")
# Both impacts below are ratios of the baseline, so a non-positive baseline
# leaves them undefined. The collector writes tps=0 whenever no ledger
# advanced and read_metric defaults a missing key to 0, so this is a routine
# outcome rather than an edge case. Reporting it as "0% impact" would clear
# the threshold and hide a failed baseline run.
# leaves them undefined. Reporting that as "0% impact" would clear the
# threshold and hide a failed baseline run. The reachable case is not the
# collector's tps=0 placeholder -- that marks the run incomplete and stops it
# earlier -- but quantization: tps is printed to two decimals, so a barely
# advancing cluster yields "0.00" with the metrics still flagged complete.
#
# Both expressions scale by 100 before dividing. bc truncates at "scale" after
# every operation, so dividing first would floor the ratio to 2 decimals and
@@ -576,7 +602,7 @@ RPC_DELTA=$(echo "scale=2; $TELE_RPC - $BASE_RPC" | bc 2>/dev/null || echo "0")
BASE_TPS=$(read_metric "$BASELINE_FILE" "tps")
TELE_TPS=$(read_metric "$TELEMETRY_FILE" "tps")
if [[ "$(echo "$BASE_TPS > 0" | bc 2>/dev/null)" = "1" ]]; then
TPS_IMPACT=$(echo "scale=2; ($BASE_TPS - $TELE_TPS) * 100 / $BASE_TPS" | bc 2>/dev/null || echo "0")
TPS_IMPACT=$(echo "scale=2; ($BASE_TPS - $TELE_TPS) * 100 / $BASE_TPS" | bc 2>/dev/null || echo "$INCONCLUSIVE")
else
TPS_IMPACT="$INCONCLUSIVE"
fi
@@ -584,7 +610,7 @@ fi
BASE_CONS=$(read_metric "$BASELINE_FILE" "consensus_round_mean_ms")
TELE_CONS=$(read_metric "$TELEMETRY_FILE" "consensus_round_mean_ms")
if [[ "$(echo "$BASE_CONS > 0" | bc 2>/dev/null)" = "1" ]]; then
CONS_IMPACT=$(echo "scale=2; ($TELE_CONS - $BASE_CONS) * 100 / $BASE_CONS" | bc 2>/dev/null || echo "0")
CONS_IMPACT=$(echo "scale=2; ($TELE_CONS - $BASE_CONS) * 100 / $BASE_CONS" | bc 2>/dev/null || echo "$INCONCLUSIVE")
else
CONS_IMPACT="$INCONCLUSIVE"
fi
@@ -615,7 +641,7 @@ check_threshold() {
# Unusable measurement. Counted as a failure so the exit gate fires: an
# undefined result must never read as a pass.
if [ "$actual" = "$INCONCLUSIVE" ]; then
fail "$name: INCONCLUSIVE — baseline was zero or missing" >&2
fail "$name: INCONCLUSIVE — the baseline was zero or missing, or the arithmetic failed" >&2
FAIL_COUNT=$((FAIL_COUNT + 1))
INCONCLUSIVE_COUNT=$((INCONCLUSIVE_COUNT + 1))
printf -v "$result_var" 'INCONCLUSIVE'
@@ -695,7 +721,14 @@ EOMD
ok "Benchmark report written to $REPORT_FILE"
cat "$REPORT_FILE"
# Exit with failure if any check failed.
if [ "$FAIL_COUNT" -gt 0 ]; then
# Exit per the code table at the top of this file. A breach and an unmeasurable
# row both have to fail the gate, but they are different codes: exit 1 promises
# every metric was measured, so a run carrying an INCONCLUSIVE row reports 2
# instead. FAIL_COUNT includes the inconclusive rows, so subtract them to see
# whether any real threshold was exceeded.
if [ "$((FAIL_COUNT - INCONCLUSIVE_COUNT))" -gt 0 ]; then
exit 1
elif [ "$INCONCLUSIVE_COUNT" -gt 0 ]; then
fail "$INCONCLUSIVE_COUNT overhead row(s) could not be measured — reporting an infrastructure error, not a breach" >&2
exit 2
fi

4
docker/telemetry/workload/regression-metrics.json
View File

@@ -2,7 +2,7 @@
"_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.",
"_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 \u2014 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:470 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 \u2014 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 \u2014 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 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_shape": "ALL SIX 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 four of the six 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 six 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_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.",
"_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).",
"excluded_keys": {
@@ -11,7 +11,7 @@
"span.ledger.build.p99": "Run-to-run variance exceeds the bound this ladder can derive, measured on the first three runs after the account-funding race was fixed. Baseline 8.944 ms (median of CI runs 34495527952, 34505215266, 34507425933) sits in (5, 10], so hi_next is 25 ms, the bound is 16.056 ms and the trip point is 25 ms. Across those three runs the value read 29.000, 7.060 and 8.944 ms -- a 4.11x spread, and the maximum is 1.16x the trip point, so a healthy run reddens CI. Run 34495527952 is that run: it turned the workload gate red on this key alone while all 200 span and metric checks passed and every phase reported 0 errors. Two corroborating details. First, its 29.000 ms reading is shared to the last digit with span.consensus.accept.p99 in the same run, which is the signature of histogram_quantile interpolating a thin tail inside one bucket rather than of ledger construction slowing down. Second, the previous baseline hid this: at 9.109 ms the same rule also gave a 25 ms trip point, and the key read as gated only because both the capture and the comparison runs happened to land low -- the 2026-08-26 capture predated the funding fix, so its phases submitted little or no traffic. Widening is not available: a bound tolerating 29.000 ms would be 20.06 ms and reach into the (25, 50] bucket, restoring exactly the single-crossing false positive the derivation rule exists to remove. Ledger construction is not left unguarded -- span.ledger.build.p95 stays gated and sits at 0.48 of its trip point. Do NOT re-gate this key by widening the bound; it needs a spread-aware baseline, or a finer ladder edge between 10 ms and 25 ms.",
"span.ledger.validate.p95": "Run-to-run variance is larger than the bound this ladder can derive. Measured across four CI runs the value spans 0.1281 to 0.7500 ms, a 5.9x spread, against a baseline of 0.2404 ms whose trip point is the next ladder edge at 0.5 ms -- so an ordinary run clears the trip point with nothing having regressed. Run 32867433073 read 0.7500 ms, +212%, and turned CI red. The derived bound models QUANTIZATION noise only (hi_next - baseline is one bucket of headroom); the dominant noise term for this span is peer-validation arrival timing in a 5-node cluster, and that term was never measured before the key was gated. Widening is not available: a bound that tolerated 0.7500 ms would reach past the 1 ms edge and leave the key gating nothing. This is a variance limit, not a defect and not a missing bound -- do NOT re-gate it by widening.",
"span.ledger.validate.p99": "The same mechanism as p95, two orders of magnitude worse. Across the same four runs the value spans 0.3875 to 25.8750 ms, a 66.8x spread, against a baseline of 1.0600 ms and a 10 ms trip point; run 32862589645 read 25.8750 ms, +2341%. The span opens only once a quorum-completing validation arrives (LedgerMaster.cpp:1003, inside checkAccept, past the tvc < minVal early return) and wraps the promotion work that follows -- setValidated, setFull, setValidLedger, pendSaveValidated -- so its duration tracks peer-validation arrival timing and what promotion then triggers. One slow consensus round therefore dominates the tail of a 3m rate window, and which round that is differs every run. A bound tolerating 25.8750 ms would be ~24.8 ms against a 1.0600 ms baseline, which gates nothing at all. Note that the two CI failures landed on DIFFERENT quantiles in different runs while the other quantile stayed well inside its bound in the same run: that asymmetry is the signature of variance, not of a regression.",
"span.tx.apply.p50": "The most extreme case of the low-bucket mechanism, and the clearest evidence that a single-run baseline cannot size a bound for these keys. Baseline 0.00597 ms lands in the ladder's FIRST bucket (0, 0.01], so hi_next is 0.05 ms and the bound is 0.0440 ms. Across three CI runs the value spans 0.00597 to 2.3378 ms, a 391.8x spread (364x over four runs), putting the observed maximum at 46.76x its trip point -- by far the worst of the five. The previous baseline read 0.7917 ms for the same key on the same workload, a 132x difference between two runs, and at that value the identical rule produced a 4.21 ms bound whose 5 ms trip point absorbed the full range. Nothing about the metric changed between those two captures; only where the sampled run fell in its own distribution did. Separately, a baseline inside the first bucket means the reported figure is interpolation across that bucket and tracks the FRACTION of applies finishing under 10 us rather than a latency, which is the ledger.store problem in embryo -- so restoring this key needs a finer low-end ladder as well as a spread-aware baseline. Rule E does not flag it because the value is not quantile x first_edge exactly."
"span.tx.apply.p50": "The most extreme case of the low-bucket mechanism, and the clearest evidence that a single-run baseline cannot size a bound for these keys. Baseline 0.00597 ms lands in the ladder's FIRST bucket (0, 0.01], so hi_next is 0.05 ms and the bound is 0.0440 ms. Across three CI runs the value spans 0.00597 to 2.3378 ms, a 391.8x spread (364x over four runs), putting the observed maximum at 46.76x its trip point -- by far the worst of the six. The previous baseline read 0.7917 ms for the same key on the same workload, a 132x difference between two runs, and at that value the identical rule produced a 4.21 ms bound whose 5 ms trip point absorbed the full range. Nothing about the metric changed between those two captures; only where the sampled run fell in its own distribution did. Separately, a baseline inside the first bucket means the reported figure is interpolation across that bucket and tracks the FRACTION of applies finishing under 10 us rather than a latency, which is the ledger.store problem in embryo -- so restoring this key needs a finer low-end ladder as well as a spread-aware baseline. Rule E does not flag it because the value is not quantile x first_edge exactly."
},
"job_queue": {
"_phases": ["queued", "running"],

4
docker/telemetry/workload/regression-thresholds.json
View File

File diff suppressed because one or more lines are too long

84
docker/telemetry/workload/run-full-validation.sh
View File

@@ -81,6 +81,13 @@ RPC_PORT_BASE=5005
WS_PORT_BASE=6006
PEER_PORT_BASE=51235
# Node i lives in $WORKDIR/$NODE_PREFIX-$i, and every node path, kill pattern and
# log glob below derives from it. The directory name is also the node's identity:
# the collector stamps that segment as service.instance.id. If it and the
# [telemetry] service_instance_id below disagree, log lines get a node name no
# trace or metric shares. Sibling harness files pin their own stem.
NODE_PREFIX="validator"
# Hard ceiling on every RPC probe below. curl applies no overall timeout of its
# own, so a node that accepts the connection and then stops answering parks the
# poll loop for the rest of the run. The loops here count attempts, not seconds,
@@ -217,8 +224,19 @@ while [ $# -gt 0 ]; do
# Match the node config path, not the bare workdir: a plain
# "$WORKDIR" pattern also matches any shell, editor or log tail
# whose command line merely mentions that path.
pkill -f "$WORKDIR/node[0-9]+/xrpld\.cfg" 2>/dev/null || true
docker compose -f "$COMPOSE_FILE" down 2>/dev/null || true
#
# This is the only thing that stops the nodes. They are host
# processes, not containers, so the compose teardown below does not
# touch them.
pkill -f "$WORKDIR/$NODE_PREFIX-[0-9]+/xrpld\.cfg" 2>/dev/null || true
# pkill sends SIGTERM and a node keeps writing NuDB while it unwinds,
# so the rm below would race a live writer and fail with ENOTEMPTY.
# Same wait as the pre-run cleanup path.
sleep 2
# -v also drops the named tempo-data volume. Without it the next
# run's Tempo starts with the previous run's traces still queryable,
# which a span assertion can be satisfied by.
docker compose -f "$COMPOSE_FILE" down -v 2>/dev/null || true
# The collector bind-mounts $WORKDIR (see XRPLD_LOG_DIR below), so a
# file left behind owned by a container uid makes this fail. Leaving
# it in place would hand the next run stale node state, so say so
@@ -256,8 +274,11 @@ ok "Prerequisites verified."
# Cleanup previous run
# ---------------------------------------------------------------------------
log "Cleaning up previous run..."
# Narrowed for the same reason as the --cleanup branch above.
pkill -f "$WORKDIR/node[0-9]+/xrpld\.cfg" 2>/dev/null || true
# Matches the node config path, for the same reason as the --cleanup branch
# above. A node left over
# from a previous run still holds this run's RPC, WS and peer ports, so missing
# one here surfaces much later as a cluster that never reaches consensus.
pkill -f "$WORKDIR/$NODE_PREFIX-[0-9]+/xrpld\.cfg" 2>/dev/null || true
sleep 2
rm -rf "$WORKDIR" || die "Could not remove the previous run's workdir $WORKDIR"
mkdir -p "$WORKDIR" "$REPORT_DIR" || die "Could not create $WORKDIR and $REPORT_DIR"
@@ -273,12 +294,15 @@ XRPLD_LOG_DIR="$WORKDIR" docker compose -f "$COMPOSE_FILE" up -d ||
log "Waiting for OTel Collector..."
for attempt in $(seq 1 30); do
status=$(curl -so /dev/null -w '%{http_code}' --max-time "$CURL_MAX_TIME" http://localhost:4318/ 2>/dev/null || echo 000)
# The fallback must not sit inside the substitution: curl already prints 000
# on a refused connection and then exits non-zero, so `|| echo 000` there
# appends a second 000 and the "not ready" test can never match.
status=$(curl -so /dev/null -w '%{http_code}' --max-time "$CURL_MAX_TIME" http://localhost:4318/ 2>/dev/null) || status=000
if [ "$status" != "000" ]; then
ok "OTel Collector ready (attempt $attempt)"
break
fi
[ "$attempt" -eq 30 ] && die "OTel Collector not ready after 30s"
[ "$attempt" -eq 30 ] && die "OTel Collector not ready after 30 attempts"
sleep 1
done
@@ -288,7 +312,7 @@ for attempt in $(seq 1 30); do
ok "Tempo ready (attempt $attempt)"
break
fi
[ "$attempt" -eq 30 ] && die "Tempo not ready after 30s"
[ "$attempt" -eq 30 ] && die "Tempo not ready after 30 attempts"
sleep 1
done
@@ -298,7 +322,7 @@ for attempt in $(seq 1 30); do
ok "Prometheus ready (attempt $attempt)"
break
fi
[ "$attempt" -eq 30 ] && die "Prometheus not ready after 30s"
[ "$attempt" -eq 30 ] && die "Prometheus not ready after 30 attempts"
sleep 1
done
@@ -311,20 +335,20 @@ bash "$SCRIPT_DIR/generate-validator-keys.sh" "$XRPLD" "$NUM_NODES" "$WORKDIR" |
die "generate-validator-keys.sh failed — no validator keys for the $NUM_NODES-node cluster"
for i in $(seq 1 "$NUM_NODES"); do
NODE_DIR="$WORKDIR/validator-$i"
mkdir -p "$NODE_DIR/nudb" "$NODE_DIR/db" || die "Could not create node$i directories under $NODE_DIR"
NODE_DIR="$WORKDIR/$NODE_PREFIX-$i"
mkdir -p "$NODE_DIR/nudb" "$NODE_DIR/db" || die "Could not create $NODE_PREFIX-$i directories under $NODE_DIR"
RPC_PORT=$((RPC_PORT_BASE + i - 1))
WS_PORT=$((WS_PORT_BASE + i - 1))
PEER_PORT=$((PEER_PORT_BASE + i - 1))
SEED=$(jq -r ".[$((i - 1))].seed" "$WORKDIR/validator-keys.json") ||
die "Could not read node$i's seed from $WORKDIR/validator-keys.json"
die "Could not read $NODE_PREFIX-$i's seed from $WORKDIR/validator-keys.json"
# jq prints the string "null" and exits 0 when the array is shorter than
# NUM_NODES, so the exit status alone does not detect a short key file. An
# unusable seed here is only visible ~200s later as a cluster that never
# proposes, which names the wrong step.
case "$SEED" in
"" | null) die "node$i has no seed in $WORKDIR/validator-keys.json — the file holds fewer than $NUM_NODES entries, or entry $((i - 1)) carries no seed" ;;
"" | null) die "$NODE_PREFIX-$i has no seed in $WORKDIR/validator-keys.json — the file holds fewer than $NUM_NODES entries, or entry $((i - 1)) carries no seed" ;;
esac
# Build ips_fixed.
@@ -336,7 +360,7 @@ for i in $(seq 1 "$NUM_NODES"); do
fi
done
cat >"$NODE_DIR/xrpld.cfg" <<EOCFG || die "Could not write node$i's config to $NODE_DIR/xrpld.cfg"
cat >"$NODE_DIR/xrpld.cfg" <<EOCFG || die "Could not write $NODE_PREFIX-$i's config to $NODE_DIR/xrpld.cfg"
[server]
port_rpc
port_ws
@@ -376,12 +400,12 @@ $SEED
[validators_file]
$WORKDIR/validators.txt
[ips]
[ips_fixed]
${IPS_FIXED}
[telemetry]
enabled=1
service_instance_id=validator-${i}
service_instance_id=$NODE_PREFIX-${i}
endpoint=http://localhost:4318/v1/traces
batch_size=512
batch_delay_ms=2000
@@ -442,7 +466,7 @@ EOCFG
# The pid file is the only record of this child: every later liveness check
# and crash report reads it back. Losing it silently would make a dead node
# indistinguishable from one that was never started.
echo $! >"$NODE_DIR/xrpld.pid" || die "Could not write node$i's pid file $NODE_DIR/xrpld.pid"
echo $! >"$NODE_DIR/xrpld.pid" || die "Could not write $NODE_PREFIX-$i's pid file $NODE_DIR/xrpld.pid"
log " Node $i: RPC=$RPC_PORT WS=$WS_PORT Peer=$PEER_PORT PID=$!"
done
@@ -478,17 +502,17 @@ node_running() {
report_stopped_nodes() {
local i pid status
for i in $(seq 1 "$NUM_NODES"); do
pid=$(cat "$WORKDIR/validator-$i/xrpld.pid" 2>/dev/null || echo "")
pid=$(cat "$WORKDIR/$NODE_PREFIX-$i/xrpld.pid" 2>/dev/null || echo "")
[ -n "$pid" ] || continue
node_running "$pid" && continue
status=0
wait "$pid" 2>/dev/null || status=$?
warn "node$i (pid $pid) is not running — wait status $status"
if [ -s "$WORKDIR/validator-$i/stdout.log" ]; then
warn "node$i last output:"
tail -n 15 "$WORKDIR/validator-$i/stdout.log" | sed 's/^/ /' >&2
warn "$NODE_PREFIX-$i (pid $pid) is not running — wait status $status"
if [ -s "$WORKDIR/$NODE_PREFIX-$i/stdout.log" ]; then
warn "$NODE_PREFIX-$i last output:"
tail -n 15 "$WORKDIR/$NODE_PREFIX-$i/stdout.log" | sed 's/^/ /' >&2
else
warn "node$i wrote no stdout at all"
warn "$NODE_PREFIX-$i wrote no stdout at all"
fi
done
}
@@ -510,7 +534,7 @@ for attempt in $(seq 1 120); do
# node is missing but not which one, which leaves nothing to grep
# for in the artifacts. An empty state means the RPC port did not
# answer at all, which usually means the process is gone.
laggards="$laggards node$i=${state:-unreachable}"
laggards="$laggards $NODE_PREFIX-$i=${state:-unreachable}"
fi
done
if [ "$ready" -ge "$NUM_NODES" ]; then
@@ -522,7 +546,7 @@ for attempt in $(seq 1 120); do
# minutes of progress output.
stopped=0
for n in $(seq 1 "$NUM_NODES"); do
p=$(cat "$WORKDIR/node$n/xrpld.pid" 2>/dev/null || echo "")
p=$(cat "$WORKDIR/$NODE_PREFIX-$n/xrpld.pid" 2>/dev/null || echo "")
if [ -n "$p" ] && ! node_running "$p"; then
stopped=$((stopped + 1))
fi
@@ -548,7 +572,7 @@ for attempt in $(seq 1 120); do
# is a no-op when nothing stopped, and it costs nothing to be sure.
# Tolerated for the same reason as above.
report_stopped_nodes || true
die "Consensus timeout — only $ready/$NUM_NODES nodes proposing after ${attempt}s. Not proposing:${laggards}. Check $WORKDIR/node*/debug.log and $WORKDIR/node*/stdout.log (a node that died before its log sink opened writes only the latter), then '$0 --cleanup'."
die "Consensus timeout — only $ready/$NUM_NODES nodes proposing after ${attempt} attempts. Not proposing:${laggards}. Check $WORKDIR/$NODE_PREFIX-*/debug.log and $WORKDIR/$NODE_PREFIX-*/stdout.log (a node that died before its log sink opened writes only the latter), then '$0 --cleanup'."
fi
printf "\r %d/%d nodes proposing..." "$ready" "$NUM_NODES"
sleep 1
@@ -570,7 +594,7 @@ for attempt in $(seq 1 60); do
# ledger_economy{metric="base_fee_xrp"} is only observed from a validated
# ledger, and complete_ledgers stays absent while the range is empty.
if [ "$attempt" -eq 60 ]; then
die "No validated ledger after ${attempt}s (last seq: $val_seq). Check $WORKDIR/node*/debug.log, then '$0 --cleanup'."
die "No validated ledger after ${attempt} attempts (last seq: $val_seq). Check $WORKDIR/$NODE_PREFIX-*/debug.log, then '$0 --cleanup'."
fi
sleep 1
done
@@ -704,9 +728,9 @@ diag_node_logs() {
local i log bytes total correlated sample
echo " [leg 1/4 node] debug.log lines matching '$DIAG_TRACE_RE'"
for i in $(seq 1 "$NUM_NODES"); do
log="$WORKDIR/validator-$i/debug.log"
log="$WORKDIR/$NODE_PREFIX-$i/debug.log"
if [ ! -f "$log" ]; then
echo " node$i: no debug.log at $log — the node never opened its log sink"
echo " $NODE_PREFIX-$i: no debug.log at $log — the node never opened its log sink"
continue
fi
bytes=$(wc -c <"$log" 2>/dev/null || echo 0)
@@ -714,7 +738,7 @@ diag_node_logs() {
# grep -c exits 1 on zero matches but still prints the count, so the
# guard keeps the 0 rather than replacing it with an empty string.
correlated=$(grep -cE "$DIAG_TRACE_RE" "$log" 2>/dev/null || true)
echo " node$i: bytes=$bytes lines=$total correlated=${correlated:-0}"
echo " $NODE_PREFIX-$i: bytes=$bytes lines=$total correlated=${correlated:-0}"
# Severity mix from the '[partition:]SEV' token, which Logs::format()
# writes as the 4th whitespace-separated field. Fixed key order so two
# runs' output can be diffed directly. Lines whose 4th field is not a
@@ -1076,7 +1100,7 @@ echo " xrpld nodes ($NUM_NODES) are running:"
for i in $(seq 1 "$NUM_NODES"); do
rpc=$((RPC_PORT_BASE + i - 1))
ws=$((WS_PORT_BASE + i - 1))
pid=$(cat "$WORKDIR/validator-$i/xrpld.pid" 2>/dev/null || echo 'unknown')
pid=$(cat "$WORKDIR/$NODE_PREFIX-$i/xrpld.pid" 2>/dev/null || echo 'unknown')
echo " Node $i: RPC=$rpc WS=$ws PID=$pid"
done
echo ""