Commit Graph

10 Commits

Author SHA1 Message Date
Pratik Mankawde
00c0265cc6 test(telemetry): refresh the timing baseline from three clean runs
The committed baseline was captured 2026-08-26, before the account-funding
race was detectable. Phases whose funding silently failed submitted no
transactions, so the capture recorded artificially low ledger and transaction
timings, and job.transaction.queued.p95 and job.transaction.running.p95 could
not be captured at all. Once funding worked, span.ledger.build.p99 read
29.00 ms against a 9.11 ms baseline and turned the gate red on a run whose
200 span and metric checks all passed.

Refresh every value to the median of CI runs 34495527952, 34505215266 and
34507425933, the first three with the fix in place, and re-derive each
absolute bound as hi_next - baseline from that median.

Exclude span.ledger.build.p99. Across those three runs it read 29.00, 7.06
and 8.94 ms, a 4.11x spread whose maximum is 1.16x its 25 ms trip point, so a
healthy run reddens CI. Widening cannot fix it: a bound tolerating 29.00 ms
would reach into the bucket above and restore the single-crossing false
positive the derivation rule removes. span.ledger.build.p95 stays gated at
0.48 of its trip point, so ledger construction keeps coverage.

The other 19 keys sit between 0.17 and 0.76 of their trip points.
span.tx.process.p95 is the tightest and is the first to re-measure if the gate
reddens again.

Repoint one bounds-checker test at span.ledger.build.p95, since it mutated the
p99 override this commit removes.
2026-09-10 18:55:53 +01:00
Pratik Mankawde
7f829a5929 fix(telemetry): fail the regression gate on a unit change, and report what it gated
compare_to_baseline took the unit from the baseline entry and dropped the current
run's, and nothing compared the two, so a us -> ms change was scored as a numeric
delta: four keys rewritten to the same physical durations reported 99.9%
improvements and the gate exited 0. prom_queries.py says the baseline preserves
the unit "so the comparator can sanity-check unit drift"; it never did. A unit
mismatch now fails and names both units.

The workflow's step summary printed total, regressions and improvements. total is
every key in the report -- the union of baseline and current -- so it was neither
the baseline count nor what was gated, and missing_in_current was computed and
never printed. A run that gated 16 of 20 keys read as a full comparison. The
comparator now reports a real "compared" count and the summary prints it beside
the not-captured count, with a warning when any key was missed. The table also
refused nothing on a truncated report; existence is not readability.

check_regression_bounds told the operator to add max_abs_increase while reading
max_abs_increase_ms / _us, so following the message added a key nothing reads and
the gate kept failing with no explanation. The committed thresholds use only the
suffixed spelling, so the message was the defect. Its three JSON inputs were also
unchecked: a top-level null, list or number parsed and then died on the first
.get, and a string "metrics" survived the placeholder test and reported its own
characters as gated keys -- wrong advice rather than a crash.

Four tests cover these; all four fail against the previous checker.
2026-09-09 13:15:46 +01:00
Pratik Mankawde
3e930d9d37 merge: bring the traces_endpoint rename forward from phase-9 2026-09-03 16:07:14 +01:00
Pratik Mankawde
3a63a17548 docs(telemetry): stop the harness contract narrating its own revisions
Notes across the workload contract described earlier versions of themselves, or
cited commits that only exist inside this chain. A squash merge publishes none of
it, so each reference resolves nowhere.

Notes that described their own earlier text:

- expected_spans.json: 'this note previously concluded', 'this note previously
  said', 'Un-skipped 2026-08-26', 'the reason had simply gone stale for two
  weeks' and 'the claim this entry carried' are replaced by the standing reason
  each entry holds. The wildcard pairs now say the validator globs the child via
  _span_name_matches(), and state the literal-collapse failure as what a
  different validator WOULD do rather than as history.
- regression-thresholds.json: 'an earlier version of this note wrongly claimed',
  'the earlier version oversold it' and 'an earlier note called that' become the
  cautions themselves -- do not reason from 'every ladder step is at least 2x',
  do not oversell the backstop, do not read a false fire as a missing override.
- test_check_regression_bounds.py: the docstring gives the reason a literal is
  wrong here, not the story of two tests that once hard-coded one.

Baseline-refresh history rewritten as measurement:

- README.md, baselines/README.md, telemetry-runbook.md and regression-metrics.json
  no longer attribute threshold moves to 'the 2026-08-26 refresh'. The evidence
  is kept as measurement -- span.tx.apply.p50 has read 0.7917 ms and 0.00597 ms
  on the same workload, 132x apart; job.acceptLedger.running.p95 has measured a
  5.74x floor on one baseline and 16.28x on another -- which is what supports the
  claim that a single-run baseline cannot bound these keys.

Two chain-only commit ids removed, d059f21bf3 and 3860c93db2. Neither is
reachable from develop, so both cease to exist on merge; the second is chain
bookkeeping. The facts they were cited for (the validator globs wildcards; the
span ladder's floor is 0.01 ms) are stated directly instead.

Capture provenance is deliberately kept: baseline-timings.json 'captured_at',
the 2026-08-26 baseline heading, and the 2026-08-24 figures cited as data.

Documentation, JSON note strings and one docstring only, no behaviour change.
2026-09-02 20:32:13 +01:00
Pratik Mankawde
9b1cd87d2e docs(telemetry): remove pre-squash references from the gap-fill comments
These comments dated themselves against this branch or against an earlier
revision of the same change, neither of which survives a squash merge.

- 'as of this branch' in the pricing-case doc and the pass-through static_assert
  becomes a statement about what the constants currently produce.
- 'Extracted from processGetObjectByHash()' and 'Split from start()' describe
  edits internal to this change; both now say why the method stands alone.
- Recording.h: the mock-abstract mismatch is a standing consequence of a member
  set that differs between builds, not something that 'has previously' happened.
- MetricsRegistry.cpp: describe the loops.txt entry as recording two cycles
  rather than as what ordering.txt 'previously had'.
- InboundLedger.h: the acquire span is the only signal for back-fill cost; it
  did not 'previously emit' nothing.
- check_bucket_parity.py: replace the eleven-phase drift story with the reason
  the check exists, and point the failure message at HistogramBuckets.h and the
  collector config instead of OpenTelemetryPlan/, which does not reach develop.

Comments and one error message only, no behaviour change.
2026-09-02 19:47:35 +01:00
Pratik Mankawde
b8cb36ffca fix(telemetry): refuse an empty capture, and name a bad baseline entry
An empty metric surface counted as a complete capture. build_query_plan
returns an empty plan without complaining for any config that yields no
gated keys, so pointing --metrics at the wrong file exits 0 and hands the
paste-me path a metrics:{} artifact to offer as the next baseline. Nothing
about such a run is evidence the pipeline works, so declared == 0 is now a
failure rather than vacuously complete.

The bounds checker also raised AttributeError on a baseline entry that is
not an object, instead of naming the key. A validator whose job is to catch
a malformed contract should report it, not crash on it.

Test cleanup is bound to its own temp tree, so a loop no longer leaves five
of six directories behind.
2026-08-27 12:38:53 +01:00
Pratik Mankawde
a734da8b33 test(telemetry): recapture the baseline and stop gating what variance dominates
Refreshes baselines/baseline-timings.json from run 32964262700 at 8418d474a7,
byte-identical to the CI artifact. The previous baseline was captured at
6a82fc6f37, before the path-finding load was removed from the workload, so it
described a load shape the harness no longer runs.

Every absolute bound is re-derived, because the rule is hi_next minus baseline
and the baselines moved.

Three more keys stop being gated: span.tx.apply.p50, span.ledger.build.p50 and
span.consensus.ledger_close.p50. This is the rule the previous commit recorded
being applied, not a new exception -- a key is gateable only when its
run-to-run spread fits inside its bound.

The evidence is span.tx.apply.p50, which read 0.7917 ms in the old baseline and
0.00597 ms in this one. That is a 132x move between two runs of the SAME
workload. The old value happened to land mid-distribution, so hi_next minus
baseline gave a 4.21 ms bound that absorbed the spread; the new value lands in
the ladder's first bucket, so the same rule gives 0.0440 ms and cannot survive
one. Whether the gate functioned was decided by where in the distribution the
captured run happened to fall, which is not a threshold in need of tuning.
Measured spreads across four runs agree: 364x, 25.3x and 5.9x respectively.

All five excluded keys share one shape -- a baseline landing in the ladder's
low buckets, where the derived bound is tiny, together with large run-to-run
spread. Single-run baselines cannot support them; a multi-run baseline, or a
spread measurement captured alongside the baseline, is what would let them be
gated again. Not attempted here.

Both runs that would have reddened CI now replay clean, and an injected 10x
regression is still caught on 19 of the 20 remaining keys, 20 of 20 at 20x.
The exception is job.acceptLedger.running.p95, whose baseline fell while its
hi_next did not, moving its floor to 16.28x. It stays gated with that floor
recorded beside the other weak keys.

Also makes the bounds checker report a zero or negative baseline as a named
rule failure instead of dividing by it and raising.
2026-08-26 14:38:16 +01:00
Pratik Mankawde
3836078a78 fix(telemetry): stop gating ledger.validate p95 and p99, which vary too much
The regression gate has been red on runs with no code change. Only two of
the 25 gated keys ever tripped, both on the same span and never together:
run 32862589645 failed p99 at 25.8750 ms against a 1.0600 ms baseline
(+2341%), run 32867433073 failed p95 at 0.7500 ms against 0.2404 ms
(+212%), and in each run the other quantile sat well inside its own bound.
A real slowdown would move both. This is variance, not a defect.

Measured across four CI runs:

  span.ledger.validate.p50   0.0484 to 0.0778 ms    1.6x spread   kept
  span.ledger.validate.p95   0.1281 to 0.7500 ms    5.9x spread   excluded
  span.ledger.validate.p99   0.3875 to 25.8750 ms  66.8x spread   excluded

Both excluded quantiles reach past their trip point on a healthy run. The
mechanism is arrival timing, not slow code: the span opens only once a
quorum-completing validation arrives (LedgerMaster.cpp:987, inside
checkAccept, past the early return) and wraps the promotion work that
follows, so one slow consensus round dominates the tail of a 3m rate
window and which round that is differs every run.

Widening is not available and must not be attempted later: tolerating
25.8750 ms against a 1.0600 ms baseline needs a bound of about 24.8 ms,
which gates nothing. A bound admitting every healthy run's worst case
admits every regression too. p50 stays gated; it is stable.

THE GENERAL RULE, recorded so this does not recur: an absolute bound
derived as hi_next minus baseline comes from the histogram ladder, so it
budgets for quantization noise and for nothing else. It knows nothing about
how far a metric moves between runs on identical code. Before gating any
key, check its observed maximum across several runs against its trip point
and gate it only with margin. Spread alone proves nothing: tx.apply.p50
swings 364x and never fires, because its 5 ms trip point absorbs the range.
Of the 23 keys still gated the worst reaches 0.67 of its trip point.

Mechanism: spans.names lists span names while _quantiles is shared, so
dropping two quantiles of one span cannot be expressed by deleting a name.
regression-metrics.json gains an excluded_keys map from a flat key to the
reason it is not gated, subtracted by both prom_queries.py (so the key is
never queried) and check_regression_bounds.py rule A. A per-name quantile
override was rejected: a typo there leaves the key gating, whereas a typo
in an exclusion subtracts nothing and new rule F rejects it, along with an
empty reason, a leftover threshold override and a leftover baseline value.

Derived figures recomputed from the committed baseline: 25 gated keys to
23, detection floor 2.02x-9.43x to 2.02x-9.42x, weakly guarded keys ten to
nine, bound over baseline 102%-843% to 102%-842%. The baseline edit is a
deletion of two entries only, with no value rewritten.

Verified: both previously failing runs replay to zero regressions and exit
0; a tenfold increase injected into each of the 23 remaining keys in turn
is still caught in all 23 cases; rule F was confirmed load-bearing by
stubbing it out, which lets a stale exclusion pass.
2026-08-25 18:21:35 +01:00
Pratik Mankawde
e4926f55be fix(telemetry): derive workload gate bounds from the bucket above the baseline
The gate could not catch a regression on any sub-millisecond span.
compare_to_baseline.py requires both the percentage and the absolute bound to
breach, and every span shared one flat absolute bound of 10 ms (15 ms for p99)
calibrated for a 5-25 ms band the spans do not occupy. Against the baseline
captured on 2026-08-24, where 18 of the 28 quantiles gated at the time sat
below 1 ms, that bound sat 1.15x to 2000x above the metric it guarded, so the
AND never fired: a 100x regression injected into span.ledger.store.p95 reported
0 regressions and exit 0. Injecting a 10x regression into each key in turn was
caught on only 5 of 28.

Give every gated key its own absolute bound, equal to the distance from its
baseline to hi_next, the edge above the top of the bucket the baseline sits in.
The trip point is then exactly hi_next, so the gate fires only once the reading
clears the bucket above the baseline's own. That is the property a multiple of
the enclosing bucket width cannot provide: after the quantile crosses hi, the
interpolation happens across the next bucket, which on this ladder is up to
eight times wider, so no multiple of the enclosing width bounds the excursion.
Measured with a model-free reachability test, a single bucket crossing can
produce a false regression on 2 of 25 keys under the old flat bound and 0 of 25
under this rule. The smallest catchable regression is 2.02x to 9.43x per key.

The job queue bound had the same shape of problem on three of its four keys
(42x, 47x, 220x before). Defaults now sit at each ladder floor, leaving the
percentage bound operative for a metric that somehow reaches them.

Drop span.ledger.store from the gated surface. Its captured quantiles were
0.005, 0.0095 and 0.0099 ms, which is the ladder's 0.01 ms floor times the
quantile: every sample lands under 10 us, so the reported value does not move
even if each store slows from 2 us to 9 us. No bound can gate it. Presence is
still asserted by expected_spans.json and the integration test, and the rate is
still on the ledger-operations dashboard.

Add check_regression_bounds.py, wired into the same workflow step as the bucket
parity check. It fails when a bound is not the one its own baseline implies,
when a gated key has no override, when the baseline and metric surface disagree,
when the percentage bound would become operative, and when a baseline carries
the ladder floor signature. This gate has now broken three times through the
same drift between ladder, baseline and bounds, so documentation alone is not
enough.

compare_to_baseline.py is unchanged: its existing per-metric override mechanism
already expresses all of this.

A missing, unreadable or malformed input makes that check exit 1 naming the
input, rather than reporting success without having checked anything; only a
placeholder baseline, the documented bootstrap state, still exits 0. Its own
tests cover both halves of that contract plus one case per rule, and run in the
workflow before the check so a broken rule reads as a broken rule.
2026-08-25 13:02:12 +01:00
Pratik Mankawde
6e2b2da772 fix(telemetry): resolve microsecond latencies below 100us
The microsecond ladder's first edge was 100us, which sat ABOVE the mass of
every instrument using it. Measured on devnet: 99.3% of job_queued_us
samples, 92.5% of job_running_us and 90.4% of getobject_lookup_us fell in
that first bucket. histogram_quantile then interpolated inside bucket 0 and
returned `quantile / fraction_in_bucket_0 x first_edge` -- p75/p95/p99 of
job_queued_us read 75.52/95.66/99.69us against a prediction of
75.53/95.67/99.70. Three-decimal agreement: those panels were reporting
arithmetic on the bucket edge, not latency.

The fix was already half-written. kSubMillisecondBoundaries had been parked
in MetricsRegistry.cpp as [[maybe_unused]] with a comment noting exactly this
problem for nodestore reads. Its edges are now folded into kMicrosecondBuckets
rather than deleted, so the parked intent is carried forward: 1..1000us
resolution where the mass is, upper edges unchanged so multi-second stalls
stay measurable.

Also moves the GetObject count and charge ladders into HistogramBuckets.h, so
all five ladders have one owner and one set of invariant tests (29 now).

Adds check_bucket_parity.py, wired into the existing OTel naming workflow.
The C++ millisecond ladder and the collector's spanmetrics ladder are
specified to agree over their shared range; they were identical when shipped,
then the collector side alone was extended and nothing noticed for eleven
phases. The check asserts containment rather than equality, because jobs
outlive spans -- jobq_updatepaths averages ~60s, which no span approaches, so
demanding equality would force a ceiling that censors it. Verified it rejects
a missing collector edge, a bogus in-range edge, and a return to the 5s
ceiling.

ledger-data-sync's "Job Queue Wait p95 By Type" moves off the beast
jobq_*_q_milliseconds pair onto job_queued_us filtered by job_type. Those
beast metrics are ms-quantised at the source (Event rounds up to a whole
millisecond), so 94-100% of their samples sat in the first bucket and no
ladder change could fix them. Note the label values are camelCase
(job_type="ledgerData"), not the lowercase metric-name fragments.

Both histogram-fed alert thresholds re-validated and left unchanged, with the
measured basis recorded so neither gets tuned against the old artefact: only
0.0022% of job_queued_us samples exceed the 1s threshold, and every edge
bracketing the 1000ms ios_latency threshold survived the ladder change.

Docs: the rpc_size "known issue -- tracked separately" notes in the runbook
and 09-data-collection-reference are now resolved notes, the stale 10-edge
span_duration bucket list is corrected to the collector's real 20, and the
runbook gains a "Reading A Histogram Percentile" section covering both
saturation traps and the expected discontinuity after a ladder change.
2026-08-21 12:46:56 +01:00