ducoterra
5f3ed9bcd4
Phase 23 final verification complete — all green.
```
VERIFIED (criteria)
1 /api/llm/snapshot windows ≈2 s live (1.98–2.00), /api/system window_seconds ≈10 s (9.996–10.005);
/api/config llm.rate_window_seconds=2=LLM_INTERVAL_SECONDS; browser re-check ALL CHECKS PASSED
(data/logs/23-window-{llm,system}.png — /llm prints Δ2.0s, /system footnote Δ10.0s)
2 Phase-13 pins unchanged: floor, 2×span ceiling, 8× jump gate + independent anchor — all pass
(only import/span-line diffs in tests/; git diff confirms no assertion rewritten)
3 Live proof re-derived from artifacts: 780 rows, 0 unlabelled, windows 0.61–3.38 s, 5 starts +
5 ends settled by poll 2 (0 unsettled), 1 m rollups max 42.3 vs raw 201.6, 0 over 300 tok/s;
counterfactual 10 s window: median settle poll 3, |ln| 0.924 vs 0.037
4 uv run pytest: 1494 passed / 15 skipped · coverage 98.94% (floor 94) · ruff clean · pyright 0
errors · node --check clean · bash .agents/validate.sh exit 0 · live 11 passed · store_perf 4 passed
Dev server up, all nine sources ok. No git add/commit run; everything left in the working tree.
DOCS PASS — 4 inconsistencies fixed in AGENTS.md (last two runs above include them)
- UI conventions hero example still said the `.sub` footnote reads `Δ10.0s`; the only hero that
prints a Δ is /llm's → now `Δ2.0s` on /llm, "at the current load" on /ups
- gap 9: "found 10 busy-edges" contradicted its own artifact (17 edges, 10 judged, 7 reported-not-
judged) → 17; and the poll-2 ratios were a 3-of-5 cherry-pick → full five values both windows
- gap 12: the responsive-table fix is now scheduled — names 27_mobile_tables_and_audit
README, config table, .env.example, rates/prom docstrings, app/api bullets and the testing-policy
pins all re-checked against code and found consistent (store pragmas, budgets, throttle, fleet).
NOTES
- Advisory only, not phase 23: fastapi 0.153.0 → 0.156.8 available; dependencies untouched here,
so rule 8's "update on purpose" is left to the operator.
- NOTES.md is empty in the working tree (its items became phases 24–27); left as-is, untracked-file
rules forbid me removing it.
- Next phase: 24_dev_mtls_rollout (25–27 follow).
```
353 lines
17 KiB
Python
353 lines
17 KiB
Python
"""Rate estimation over a labelled window.
|
|
|
|
Every throughput number in this dashboard is Δcounter/Δt. If the estimator returns a
|
|
plausible-looking number for a counter that restarted, or a silent 0 for a scrape that
|
|
arrived late, the UI cannot tell the difference — so the None cases matter more here than
|
|
the happy path.
|
|
"""
|
|
from __future__ import annotations
|
|
|
|
import math
|
|
|
|
import pytest
|
|
|
|
from dashboards.rates import RateEstimator
|
|
from rate_window_contract import HOST_WINDOW, LLM_WINDOW
|
|
|
|
|
|
def test_first_sample_has_no_rate() -> None:
|
|
r = RateEstimator(span=10)
|
|
assert r.rate("cpu", 100.0, now=1_000.0) == (None, None)
|
|
|
|
|
|
def test_second_sample_gives_rate_and_window() -> None:
|
|
r = RateEstimator(span=10)
|
|
r.rate("cpu", 100.0, now=1_000.0)
|
|
rate, window = r.rate("cpu", 300.0, now=1_010.0)
|
|
assert rate == 20.0
|
|
assert window == 10.0
|
|
|
|
|
|
def test_window_is_labelled_with_the_span_actually_used() -> None:
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 0.0, now=0.0)
|
|
r.rate("x", 10.0, now=2.0) # inside the span
|
|
rate, window = r.rate("x", 30.0, now=11.0)
|
|
# base is the sample 11s ago (outside the span) -> falls back to the previous sample
|
|
assert window == 9.0
|
|
assert rate == pytest.approx(20.0 / 9.0)
|
|
|
|
|
|
def test_none_value_does_not_poison_the_window() -> None:
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 10.0, now=0.0)
|
|
assert r.rate("x", None, now=1.0) == (None, None)
|
|
rate, _window = r.rate("x", 30.0, now=2.0)
|
|
assert rate == 10.0, "the None scrape must not become the baseline"
|
|
|
|
|
|
def test_nan_and_inf_are_treated_as_missing() -> None:
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 1.0, now=0.0)
|
|
for bad in (float("nan"), float("inf")):
|
|
assert r.rate("x", bad, now=1.0) == (None, None)
|
|
|
|
|
|
# --- phase 13: the live decode-tok/s spike ---------------------------------- #
|
|
# Confirmed against the stored history and reproduced on live hardware; the findings are in
|
|
# data/logs/NOTES-decode-spike.md. These two tests were written RED (as strict xfails) by
|
|
# task 02 and turned GREEN by task 03's bounded window; the markers were removed and every
|
|
# assertion kept verbatim, as the phase mandated. They are permanent pins now.
|
|
#
|
|
# The incident, from `sample` (source=llm, host=gufo, metric=llm.decode_tokens_per_second,
|
|
# res=raw) on 2026-10-18, with the counter value reconstructed from the rows' own windows:
|
|
#
|
|
# 09:16:15.839 53.64 tok/s window ~10 s (steady work on deskwork: 53 tok/s)
|
|
# ... 15.25 s with no sample at all: every source in the process gaps at the same instant ...
|
|
# 09:16:31.091 7.47 tok/s window 15.25 s (114 tokens — a body generated ~2 s into it)
|
|
# 09:16:31.308 3284.59 tok/s window 0.217 s (713 tokens — the rest of the stall)
|
|
# 09:16:33.311 371.23 tok/s window 2.22 s (the stale sample is still base[0])
|
|
# 09:16:35.315 222.32, 09:16:37.318 166.23, 09:16:39.316 138.37, then back to ~50
|
|
#
|
|
# 827 tokens across the whole 15.47 s is 53.5 tok/s — the engine's true rate. The tokens are
|
|
# real; the window is the lie. `probe-decode-spike2.py` produced the same row pair (and nearly
|
|
# the same tail: 379 / 232 / 174 / 140) against live gufo with the production parser.
|
|
|
|
GUFO_TOKENS = "llamacpp:tokens_predicted_total"
|
|
|
|
|
|
def stalled_estimator(span: float = 10.0) -> RateEstimator:
|
|
"""A window fed the steady 2 s cadence at exactly 50 tok/s."""
|
|
r = RateEstimator(span=span)
|
|
for i in range(6):
|
|
r.rate(GUFO_TOKENS, 100.0 * i, now=1_000.0 + 2.0 * i)
|
|
return r
|
|
|
|
|
|
def test_a_catch_up_poll_after_a_stall_answers_na_not_a_spike() -> None:
|
|
"""A fetch that takes 15 s and the loop's 0.2 s catch-up floor must not make a rate.
|
|
|
|
`poller.Job._loop` sleeps `max(0.2, interval - elapsed)`, so any poll slower than the
|
|
interval is followed by a second one ~0.2 s later. Whatever the stalled fetch carried is
|
|
then diffed over that 0.2 s.
|
|
"""
|
|
r = stalled_estimator() # steady 50 tok/s, last sample (1010.0, 500.0)
|
|
# the stalled fetch: 15.25 s after the last sample, but its body was generated ~2 s in,
|
|
# so it carries 114 tokens and gets stamped 13 s later than the engine measured them
|
|
diluted, _window = r.rate(GUFO_TOKENS, 614.0, now=1_025.25)
|
|
assert diluted == pytest.approx(7.47, abs=0.01) # the diluted row the DB actually holds
|
|
# the catch-up: 0.22 s later, the current counter (713 tokens of stall still unaccounted)
|
|
rate, window = r.rate(GUFO_TOKENS, 1_327.0, now=1_025.47)
|
|
assert window == pytest.approx(0.22)
|
|
assert rate is None, "a 0.22 s window is not a rate over the span; it must be n/a"
|
|
|
|
|
|
def test_a_stalled_sample_does_not_inflate_the_polls_after_it() -> None:
|
|
"""The tail is as wrong as the spike: base[0] is the stale sample for the next ~span."""
|
|
r = stalled_estimator()
|
|
r.rate(GUFO_TOKENS, 614.0, now=1_025.25)
|
|
r.rate(GUFO_TOKENS, 1_327.0, now=1_025.47)
|
|
# back to a normal 2 s cadence and the same honest 50 tok/s
|
|
tail = [r.rate(GUFO_TOKENS, 1_327.0 + 100.0 * n, now=1_029.47 + 2.0 * (n - 1))[0]
|
|
for n in range(1, 5)]
|
|
assert all(v is None or v <= 60.0 for v in tail), f"inflated tail, real rate is 50: {tail}"
|
|
|
|
|
|
# --- phase 13 task 03: both window bounds and the confirmed jump ------------- #
|
|
|
|
def test_window_below_the_floor_answers_na_with_its_honest_label() -> None:
|
|
"""A 0.4 s catch-up gap is not a measurement over a 10 s span; it labels itself."""
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 100.0, now=0.0)
|
|
rate, window = r.rate("x", 103.0, now=0.4)
|
|
assert rate is None
|
|
assert window == pytest.approx(0.4), "the n/a still names the window it refused"
|
|
# the refused base was dropped: the next normal poll measures from the catch-up sample
|
|
rate, window = r.rate("x", 203.0, now=4.4)
|
|
assert rate == pytest.approx(25.0)
|
|
assert window == pytest.approx(4.0)
|
|
|
|
|
|
def test_fallback_base_older_than_two_spans_answers_na_and_recovers() -> None:
|
|
"""A 20-second window on a 10-second panel is a different claim — one n/a, then normal."""
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 0.0, now=0.0)
|
|
assert r.rate("x", 50.0, now=30.0) == (None, None)
|
|
rate, window = r.rate("x", 100.0, now=32.0)
|
|
assert rate == pytest.approx(25.0)
|
|
assert window == pytest.approx(2.0), "the next poll re-bases on the fresh sample"
|
|
|
|
|
|
def test_a_fallback_inside_the_documented_ceiling_still_publishes() -> None:
|
|
"""The stall row the DB actually holds (15.25 s ≤ 2 x 10 s) keeps its diluted rate."""
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 0.0, now=0.0)
|
|
rate, window = r.rate("x", 100.0, now=15.25)
|
|
assert rate == pytest.approx(100.0 / 15.25)
|
|
assert window == pytest.approx(15.25)
|
|
|
|
|
|
def test_two_samples_at_the_same_instant_are_not_a_rate() -> None:
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 100.0, now=5.0)
|
|
assert r.rate("x", 200.0, now=5.0) == (None, None)
|
|
|
|
|
|
def test_a_jump_is_held_for_one_poll_and_publishes_when_confirmed() -> None:
|
|
"""A real step-up survives one more interval and then prints — one poll late.
|
|
|
|
The confirming window is anchored on the sample 10 s back, which has moved on from the one
|
|
the held jump was measured from — that is what makes it a second measurement. The other
|
|
half is `test_a_held_jump_is_not_confirmed_by_a_window_on_the_same_anchor`.
|
|
"""
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 0.0, now=0.0)
|
|
r.rate("x", 100.0, now=10.0) # 10 tok/s published
|
|
rate, window = r.rate("x", 900.0, now=20.0) # 80 tok/s = 8x: held
|
|
assert rate == pytest.approx(10.0)
|
|
assert window == pytest.approx(10.0), "the held value keeps the Δ label it was published with"
|
|
rate, window = r.rate("x", 1_720.0, now=30.0) # 82 tok/s: the step is real — publish
|
|
assert rate == pytest.approx(82.0)
|
|
assert window == pytest.approx(10.0)
|
|
|
|
|
|
def test_an_unconfirmed_jump_is_dropped_and_the_held_value_keeps_printing() -> None:
|
|
"""A one-interval artifact never publishes; the cell kept printing through it anyway."""
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 0.0, now=0.0)
|
|
r.rate("x", 100.0, now=10.0) # 10 tok/s
|
|
assert r.rate("x", 900.0, now=20.0)[0] == pytest.approx(10.0) # 80: held
|
|
assert r.rate("x", 1_005.0, now=30.0)[0] == pytest.approx(10.0) # 10.5: artifact dropped
|
|
rate, _ = r.rate("x", 1_105.0, now=40.0) # ordinary publishing resumes
|
|
assert rate == pytest.approx(10.0)
|
|
|
|
|
|
def test_a_held_jump_is_not_confirmed_by_a_window_on_the_same_anchor() -> None:
|
|
"""A stalled fetch stamps its body late, and that body then anchors the whole span.
|
|
|
|
Measured on live gufo at 2026-10-19 12:42 (`data/logs/NOTES-decode-stable.md`'s window,
|
|
one request running at ~50 tok/s): the process stalled 11 s, the first reply back carried
|
|
the counter gufo had rendered ~2 s into it, and the estimator diffed the rest of the stall
|
|
over a 3 s window — 232 tok/s — then re-diffed **the same delta** over 5, 7 and 9 s
|
|
(146, 114, 95) because the stale sample stayed `inside[0]`. Measured twice from one sample
|
|
is one measurement, so the confirmation gate requires a window anchored on a different
|
|
sample; the hold simply continues until the stale anchor ages out of the span.
|
|
"""
|
|
r = RateEstimator(span=10.0)
|
|
tokens = lambda t: 45.0 * t # noqa: E731 the engine: a steady 45 tok/s
|
|
polls = [(0.0, tokens(0.0)),
|
|
(11.0, tokens(2.2)), # the stalled reply: honest body, 9 s-old stamp
|
|
(12.0, tokens(12.0)), # the catch-up: ≥8x the diluted row, so it is held
|
|
(14.0, tokens(14.0)), # …and every poll still anchored on that stale sample
|
|
(16.0, tokens(16.0)),
|
|
(18.0, tokens(18.0)),
|
|
(20.0, tokens(20.0)),
|
|
(22.0, tokens(22.0)), # the anchor has aged out; one poll still denies the jump
|
|
(24.0, tokens(24.0)),
|
|
(26.0, tokens(26.0))]
|
|
published = [r.rate("g", value, now=1_000.0 + t)[0] for t, value in polls]
|
|
assert all(v is None or v <= 60.0 for v in published), \
|
|
f"a 45 tok/s engine printed {max(v for v in published if v is not None):.0f}: {published}"
|
|
assert published[-1] == pytest.approx(45.0), "the stall ends in the truth, not a tail"
|
|
|
|
|
|
# --- phase 23: the gates are the estimator's, not the old 10 s span's --------- #
|
|
# `app.build_hub` now spans the `llm` jobs by `LLM_INTERVAL_SECONDS` (2 s), a fifth of the host's
|
|
# `RATE_WINDOW_SECONDS`. Everything phase 13 built has to survive the shrink or the smaller window
|
|
# is a licence for the same 3284.59 tok/s row, so each gate runs here at both spans. The numbers
|
|
# scale with the span: what these three pin is the *relation*, which is what "unchanged" means.
|
|
# The fourth protection — a held jump needing a **different anchor** — is deliberately not
|
|
# parametrized: it compares two sample timestamps and no span arithmetic, and a 2 s window holds
|
|
# one sample per poll interval anyway, so a stale anchor ages out one poll later instead of five.
|
|
# Its span-10 regression pair (`test_a_held_jump_is_not_confirmed_by_a_window_on_the_same_anchor`
|
|
# above, `test_gufo_a_stale_scrape_body_never_becomes_a_rate_above_the_engine` in
|
|
# `tests/test_llm_source.py`) runs unchanged, and the floor row of this section is the one that
|
|
# could actually have been weakened by the smaller window: `MIN_WINDOW_SECONDS` is absolute.
|
|
|
|
@pytest.mark.parametrize("span", [LLM_WINDOW, HOST_WINDOW])
|
|
def test_the_floor_refuses_the_catch_up_gap_at_either_window(span: float) -> None:
|
|
"""The poll loop's ~0.2 s catch-up is a gap whatever the panel's span is.
|
|
|
|
0.22 s is a tenth of a 10 s window and an eighth of a 2 s one, and neither is a measurement:
|
|
the floor is absolute on purpose (phase 13 pinned that), so the LLM's narrower claim is not a
|
|
narrower guard.
|
|
"""
|
|
r = RateEstimator(span=span)
|
|
r.rate("x", 0.0, now=0.0)
|
|
r.rate("x", 50.0 * span, now=span) # the honest cadence: 50 tok/s
|
|
rate, window = r.rate("x", 50.0 * span + 11.0, now=span + 0.22)
|
|
assert rate is None, f"a 0.22 s catch-up became a rate at span={span}"
|
|
assert window == pytest.approx(0.22), "the n/a still names the window it refused"
|
|
|
|
|
|
@pytest.mark.parametrize("span", [LLM_WINDOW, HOST_WINDOW])
|
|
def test_the_ceiling_is_two_spans_at_either_window(span: float) -> None:
|
|
"""`2 x span` is relative, so a stall stays a stall at either window size."""
|
|
r = RateEstimator(span=span)
|
|
r.rate("x", 0.0, now=0.0)
|
|
assert r.rate("x", 100.0, now=2.5 * span) == (None, None), "past the ceiling: no rate"
|
|
rate, window = r.rate("x", 200.0, now=3.5 * span)
|
|
assert rate == pytest.approx(100.0 / span)
|
|
assert window == pytest.approx(span), "the next poll re-bases on the fresh sample"
|
|
|
|
|
|
@pytest.mark.parametrize("span", [LLM_WINDOW, HOST_WINDOW])
|
|
def test_a_jump_is_held_and_confirmed_at_either_window(span: float) -> None:
|
|
"""An 8x step holds one poll at a 2 s window exactly as at a 10 s one.
|
|
|
|
The ratio is dimensionless, so narrowing the window does not loosen the gate: a real burst
|
|
outlives one poll interval of either size and prints one poll late, while the held value keeps
|
|
the `Δ<window>` label it was published with.
|
|
"""
|
|
r = RateEstimator(span=span)
|
|
r.rate("x", 0.0, now=0.0)
|
|
r.rate("x", 10.0 * span, now=span) # 10 tok/s published
|
|
rate, window = r.rate("x", 90.0 * span, now=2.0 * span) # 80 tok/s = 8x: held
|
|
assert rate == pytest.approx(10.0)
|
|
assert window == pytest.approx(span), "the held value keeps the Δ label it was published with"
|
|
rate, window = r.rate("x", 172.0 * span, now=3.0 * span) # 82: a new anchor confirms it
|
|
assert rate == pytest.approx(82.0)
|
|
assert window == pytest.approx(span)
|
|
|
|
|
|
def test_a_rise_from_zero_is_never_held() -> None:
|
|
"""The first work an idle engine does must print on its own poll, not one late."""
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 0.0, now=0.0)
|
|
r.rate("x", 0.0, now=10.0) # 0 tok/s published
|
|
assert r.rate("x", 500.0, now=20.0)[0] == pytest.approx(50.0)
|
|
|
|
|
|
def test_confirmation_state_is_per_key() -> None:
|
|
"""One key's pending jump must not hold another key's numbers."""
|
|
r = RateEstimator(span=10)
|
|
r.rate("busy", 0.0, now=0.0)
|
|
r.rate("busy", 100.0, now=10.0) # 10 tok/s — a jump base exists
|
|
r.rate("idle", 5.0, now=0.0)
|
|
r.rate("idle", 5.0, now=10.0) # 0 tok/s — previous is 0, nothing to confirm against
|
|
assert r.rate("busy", 900.0, now=20.0)[0] == pytest.approx(10.0)
|
|
assert r.rate("idle", 505.0, now=20.0)[0] == pytest.approx(50.0)
|
|
|
|
|
|
def test_a_counter_restart_clears_the_confirmation_state() -> None:
|
|
"""A restarted counter has no previous lineage to be judged against."""
|
|
r = RateEstimator(span=10)
|
|
r.rate("x", 0.0, now=0.0)
|
|
r.rate("x", 100.0, now=10.0) # 10 tok/s
|
|
assert r.rate("x", 10.0, now=20.0) == (None, None) # restart drops the window
|
|
rate, _ = r.rate("x", 910.0, now=30.0) # 90 tok/s on the new counter
|
|
assert rate == pytest.approx(90.0)
|
|
|
|
|
|
def test_forget_drops_the_judgement_state_with_the_window() -> None:
|
|
r = RateEstimator(span=10)
|
|
r.rate("host:x", 0.0, now=0.0)
|
|
r.rate("host:x", 100.0, now=10.0)
|
|
r.rate("host:x", 900.0, now=20.0) # held: one pending jump, one published rate
|
|
assert r._published and r._pending
|
|
assert r.forget("host:") == 1
|
|
assert r._published == {} and r._pending == {}
|
|
|
|
|
|
def test_counter_reset_yields_none_once_then_recovers() -> None:
|
|
"""A restart must not report a huge negative — or, worse, a huge positive — rate."""
|
|
r = RateEstimator(span=60)
|
|
r.rate("tokens", 5_000.0, now=0.0)
|
|
rate, _ = r.rate("tokens", 10.0, now=10.0) # process restarted
|
|
assert rate is None
|
|
rate, _ = r.rate("tokens", 60.0, now=20.0)
|
|
assert rate == 5.0, "the window re-seeds from the post-restart counter"
|
|
|
|
|
|
def test_flat_counter_reports_zero_not_none() -> None:
|
|
r = RateEstimator(span=10)
|
|
r.rate("idle", 5.0, now=0.0)
|
|
rate, window = r.rate("idle", 5.0, now=5.0)
|
|
assert rate == 0.0 and window == 5.0
|
|
|
|
|
|
def test_keys_are_independent() -> None:
|
|
r = RateEstimator(span=10)
|
|
r.rate("a", 0.0, now=0.0)
|
|
r.rate("b", 100.0, now=0.0)
|
|
assert r.rate("a", 10.0, now=1.0)[0] == 10.0
|
|
assert r.rate("b", 100.0, now=1.0)[0] == 0.0
|
|
|
|
|
|
def test_forget_drops_a_removed_target() -> None:
|
|
r = RateEstimator(span=10)
|
|
for key in ("driveripper:cpu.total", "driveripper:disk.read", "deskwork:cpu.total"):
|
|
r.rate(key, 1.0, now=0.0)
|
|
assert r.forget("driveripper:") == 2
|
|
assert r.keys() == ["deskwork:cpu.total"]
|
|
# and the surviving target is untouched
|
|
assert r.rate("deskwork:cpu.total", 11.0, now=1.0)[0] == 10.0
|
|
|
|
|
|
def test_history_is_trimmed_to_max_samples() -> None:
|
|
r = RateEstimator(span=1e6, max_samples=8)
|
|
for i in range(50):
|
|
r.rate("x", float(i), now=float(i))
|
|
assert len(r._samples["x"]) <= 8 # bounded memory is the contract
|
|
assert all(math.isfinite(v) for _, v in r._samples["x"])
|