From e1f5faa6ed44cae16181eadd0e45ddf2cc6158cc Mon Sep 17 00:00:00 2001 From: szibis Date: Wed, 21 Oct 2026 11:38:50 +0200 Subject: [PATCH] ci: the daily performance run reports regressions, improvements and a ratchet The daily run only recorded numbers, so a result that started differing from Loki or a query that started failing waited for someone to read the trend. `history.py alerts` compares each set's newest history line with the previous valid one and reports transitions, not the state many rows are already in: - regression: result same -> differs; status 200 -> an error Loki does not give; warm p50 slower beyond the 25% / 50 ms noise rule that held for two runs (both worse than the run before them, range starting at that run) or that the same run's verdict against the release also calls slower - improvement: the reverse of the first two, or faster beyond the noise rule - every alert names its commit range A new history column, loki_cold_computed, records from Loki's cache counters whether Loki computed its cold run (true), its results cache answered it (false) or nothing is known (null, on every older line, which carry their own cols). bench/ab/history/ratchet.json lists rows with the same result as Loki, status 200 and a cold run no slower than a computed Loki cold run; the run only adds to it, rows leave by hand, and a ratcheted row that differs or fails, or is slower than Loki's computed cold in two runs in a row, is a loss. daily.py writes alerts.md and alerts.json next to the run's files (not committed: they describe one run), only for the sets it just wrote. The workflow puts them at the top of the daily pull request and in the job summary, and a final step fails the job on a regression or a ratchet loss. The pull request validation shows them and does not fail on them. --- .github/workflows/perf-daily.yaml | 37 +++- CHANGELOG.md | 25 +++ bench/ab/README.md | 29 +++- bench/ab/daily.py | 15 +- bench/ab/history.py | 193 ++++++++++++++++++++- bench/ab/tests/test_alerts.py | 279 ++++++++++++++++++++++++++++++ 6 files changed, 571 insertions(+), 7 deletions(-) create mode 100644 bench/ab/tests/test_alerts.py diff --git a/.github/workflows/perf-daily.yaml b/.github/workflows/perf-daily.yaml index ca2f1b34c..f5e1389ec 100644 --- a/.github/workflows/perf-daily.yaml +++ b/.github/workflows/perf-daily.yaml @@ -11,6 +11,12 @@ name: Perf daily # PR's days included): no new run, no new or updated pull request. A manual # dispatch always runs. # +# The run compares each set's newest history line with the previous one and +# reports regressions, improvements and the ratchet (bench/ab/history/ratchet.json, +# rows as good as Loki) at the top of the daily pull request and in the job +# summary. A regression or a lost ratchet row turns the run red, which is the +# notification; nothing else is opened or labelled. +# # A pull request that edits this pipeline runs a short validation instead # (control set, 1h, 3 runs): it writes the files on the runner and shows the # trend report in the job summary, but opens no pull request. @@ -80,6 +86,8 @@ jobs: - name: Publish trend if: always() run: | + # Alerts are shown here and never fail a pull request's validation. + if [ -f "$OUT/alerts.md" ]; then cat "$OUT/alerts.md" >> "$GITHUB_STEP_SUMMARY"; fi if [ -f bench/ab/history/trend.md ]; then cat bench/ab/history/trend.md >> "$GITHUB_STEP_SUMMARY"; fi git status --short @@ -91,6 +99,7 @@ jobs: path: | ${{ env.OUT }}/*.json ${{ env.OUT }}/*.log + ${{ env.OUT }}/*.md bench/ab/results/daily-*.json bench/ab/history/ if-no-files-found: ignore @@ -179,6 +188,7 @@ jobs: path: | ${{ env.OUT }}/*.json ${{ env.OUT }}/*.log + ${{ env.OUT }}/*.md bench/ab/results/daily-*.json bench/ab/history/ if-no-files-found: ignore @@ -196,8 +206,14 @@ jobs: # config, and the checkout above did not keep one. HEADER="$(printf 'x-access-token:%s' "${PUSH_TOKEN}" | base64 | tr -d '\n')" echo "::add-mask::${HEADER}" + # bench/ab/history includes trend.md and ratchet.json. FILES=(bench/ab/results bench/ab/history conformance/registry/generated/perf-evidence.json conformance/reports/performance.md conformance/reports/gaps.md) + ALERTS="" + if [ -f "$OUT/alerts.md" ]; then + ALERTS="$(cat "$OUT/alerts.md")" + echo "$ALERTS" >> "$GITHUB_STEP_SUMMARY" + fi if [ -z "$(git status --porcelain -- "${FILES[@]}")" ]; then echo "nothing changed" exit 0 @@ -210,9 +226,10 @@ jobs: git commit -m "bench: daily performance report ${DATE}" git -c "http.https://github.com/.extraheader=AUTHORIZATION: basic ${HEADER}" push origin "$BRANCH" --force TITLE="bench: daily performance report ${DATE}" - BODY="$(printf '%s\n\n%s\n\n%s\n' \ + BODY="$(printf '%s\n\n%s\n\n%s\n\n%s\n' \ + "$ALERTS" \ "Daily A/B run from \`main\` ($(git rev-parse --short HEAD^1)): the last release vs \`main\` vs Loki direct on a fresh stack, every shape set over its ranges up to 24h." \ - "Updates \`bench/ab/results/daily-*.json\`, appends \`bench/ab/history/*.jsonl\`, regenerates \`bench/ab/history/trend.md\` and the registry performance evidence. Run: ${GITHUB_SERVER_URL}/${GITHUB_REPOSITORY}/actions/runs/${GITHUB_RUN_ID}" \ + "Updates \`bench/ab/results/daily-*.json\`, appends \`bench/ab/history/*.jsonl\`, regenerates \`bench/ab/history/trend.md\`, updates \`bench/ab/history/ratchet.json\` and the registry performance evidence. Run: ${GITHUB_SERVER_URL}/${GITHUB_REPOSITORY}/actions/runs/${GITHUB_RUN_ID}" \ "Merging keeps the history continuous; an unmerged day is carried into the next day's PR.")" PR_NUMBER="$(gh pr list --repo "$GITHUB_REPOSITORY" --head "$BRANCH" --base main --state open --json number --jq '.[0].number // empty')" if [ -n "$PR_NUMBER" ]; then @@ -241,3 +258,19 @@ jobs: if ! gh pr merge "$PR_NUMBER" --repo "$GITHUB_REPOSITORY" --auto --squash; then echo "::warning::could not arm auto-merge on pull request #${PR_NUMBER}; enable it by hand" fi + + - name: Fail on regressions + if: steps.measured.outputs.run != 'false' + run: | + # Red run = the notification. Regressions are transitions since the + # previous run; a ratchet loss stays red until fixed or the row is + # removed from ratchet.json by hand. + [ -f "$OUT/alerts.json" ] || exit 0 + python3 - "$OUT/alerts.json" <<'PY' + import json, sys + a = json.load(open(sys.argv[1])) + for key in ("regressions", "ratchet_lost"): + for r in a[key]: + print(f"::error title=perf {key}::{r['set']} / {r['shape']} / {r['range']}: {r['detail']} ({r['commits']})") + sys.exit(1 if a["regressions"] or a["ratchet_lost"] else 0) + PY diff --git a/CHANGELOG.md b/CHANGELOG.md index a11cdc296..62041411a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -27,6 +27,31 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 measurement of every current shape set was taken at (7 runs, every range up to 24h; an open daily pull request's days included). A manual dispatch always runs, and a history that cannot be read runs the measurement. +- **The daily performance run reports regressions, improvements and a ratchet + of the rows that are as good as Loki, and turns red on a regression.** The + daily run only recorded numbers, so a result that started differing from + Loki or a query that started failing was found by whoever read the trend + next. `bench/ab/history.py alerts` now compares each set's newest history + line with the previous valid one and reports transitions, not state (many + rows already differ from Loki and must not alert every day): a result that + went `same` to `differs`, a status that went 200 to an error Loki does not + give, and a warm p50 slower beyond the 25% and 50 ms noise rule that held for + two runs or that the same run's verdict against the release also calls + `slower`; and the improvements (the reverse of the first two, or faster beyond + the noise rule in one run). Each alert names its commit range to bisect. A new + history column, `loki_cold_computed`, records from Loki's cache counters + whether Loki computed its cold run or its results cache answered it (null on + older lines, which each carry their own `cols`). `bench/ab/history/ratchet.json` + lists the rows whose newest line has the same result as Loki, answers 200 and + has a cold run no slower than a Loki cold run that was computed (never warm + p50, which for Loki is its results cache); the run only adds to it, rows leave + it by hand, and a ratcheted row that differs or fails, or whose cold run is + slower than Loki's computed cold run in two runs in a row, is a ratchet + loss. The alerts go at the top of the daily pull request and into the job + summary (`alerts.md` is written next to the run's files, not committed), and + a final `Fail on regressions` step fails the job on a regression or a ratchet + loss, so GitHub notifies the owner; no issue is opened and no label added. + The pull request validation shows the alerts and does not fail on them. ### Documentation diff --git a/bench/ab/README.md b/bench/ab/README.md index ad07c88d2..56aa2d86a 100644 --- a/bench/ab/README.md +++ b/bench/ab/README.md @@ -353,8 +353,9 @@ release build's 24h ranges are capped at 3 runs. It writes: | path | content | |---|---| | `results/daily-.json` | the day's summary per set (`report.py` format), overwritten daily; git history keeps every day, and `perf_evidence.py` reads it as the latest evidence | -| `history/.jsonl` | one line per set per day, append-only: date, commit, baseline, runs, validity, and one row per shape ร— range in the column order its `cols` names (proxy status, warm p50, cold, Loki p50, cold and status, result vs Loki, release p50, verdict vs release) | +| `history/.jsonl` | one line per set per day, append-only: date, commit, baseline, runs, validity, and one row per shape ร— range in the column order its `cols` names (proxy status, warm p50, cold, Loki p50, cold and status, result vs Loki, release p50, verdict vs release, and whether Loki computed its cold run or its results cache answered it) | | `history/trend.md` | per set: proxy p50, day-over-day and week-over-week change (๐ŸŸข/๐Ÿ”ด beyond 25% and 50 ms), Loki p50, proxy รท Loki warm and cold, result vs Loki and a 14-day sparkline | +| `history/ratchet.json` | the rows that were as good as Loki, one entry per set ร— shape ร— range; the run only adds to it | | `conformance/registry/generated/perf-evidence.json`, `conformance/reports/performance.md`, `gaps.md` | regenerated from the new results | The files reach `main` through a bot pull request on the rolling branch @@ -377,6 +378,32 @@ stack's `test/e2e-compat/docker-compose.yml`, `loki-local-config.yaml` and `log-generator.py`, and the workflow itself. A manual dispatch always runs, and a history that cannot be read runs the measurement. +Each run also compares every set's newest history line with the previous +valid one (`history.py alerts`) and reports transitions, not the state many rows +are already in (rows that differ from Loki today do not alert again). A +regression is a result that went `same` โ†’ `differs`, a status that went 200 โ†’ +an error Loki does not give, or a warm p50 slower beyond 25% and 50 ms that held +for two runs (both worse than the run before them) or that the same run's +verdict against the release also calls `slower`. An improvement is the reverse +of the first two, or a warm p50 faster beyond the same margin (one run is +enough). Each alert names the commit range to bisect, `..` (a slowdown that held for two runs starts at the line +before it began). A row enters `history/ratchet.json` when its newest line has +the same result as Loki, answers 200 and its cold run is no slower than Loki's +cold run, and only when Loki computed that cold run (`loki_cold_computed`, from +Loki's cache counters): never on warm p50, which for Loki is its results cache, +and never on lines written before the column existed. A ratchet loss is a +ratcheted row whose newest line differs from Loki or fails (at once), or whose +cold run is slower than Loki's computed cold run beyond the margin in the newest +line and the previous valid one (a cold run is one sample); it repeats every run +until fixed. +Rows leave the list only by hand. The run writes the alerts to +`/alerts.md` and `alerts.json` (not committed: they describe one run), puts +them at the top of the daily pull request and in the job summary, and a final +step fails the job when there is a regression or a ratchet loss, so the red run +is the notification. A pull request that edits the pipeline shows them and never +fails on them. + For docs, read `history/.jsonl` (one JSON object per line; zip `cols` with each row) or reuse `history/trend.md` as is. A pull request that edits the daily pipeline runs a short version of it (control set, 1h, 3 runs) that diff --git a/bench/ab/daily.py b/bench/ab/daily.py index 3b6afdd68..732e5f4de 100644 --- a/bench/ab/daily.py +++ b/bench/ab/daily.py @@ -9,6 +9,11 @@ history keeps every day) bench/ab/history/.jsonl one appended line per set per day bench/ab/history/trend.md day-over-day and week-over-week report + bench/ab/history/ratchet.json rows as good as Loki (only ever added to) + /alerts.md, alerts.json regressions, improvements and ratchet + losses of this run's lines (not committed: + they describe one run; the workflow puts + them in the pull request and fails on them) conformance/registry/generated/perf-evidence.json, conformance/reports/ performance.md and gaps.md regenerated from the new results @@ -117,12 +122,20 @@ def main(): # of results and history, fail the job so the next day retries. stack.log("run invalid (VictoriaLogs restarted); nothing written") return 2 + written = [] for summary in summaries: with open(os.path.join(RESULTS, f"daily-{summary['set']}.json"), "w") as f: json.dump(summary, f, indent=1) - history.append(summary, commit=head) + if history.append(summary, commit=head)[1]: + written.append(summary["set"]) with open(os.path.join(history.HISTORY, "trend.md"), "w") as f: f.write(history.trend()) + # Only the sets this run wrote: a manual run of one set must not report the others' old lines again. + found = history.write_alerts(history.HISTORY, written, os.path.join(out, "alerts.json"), + os.path.join(out, "alerts.md")) + stack.log(f"alerts: {len(found['regressions'])} regressions, {len(found['improvements'])} improvements, " + f"{len(found['ratchet_lost'])} ratchet losses, ratchet {len(found['ratchet'])} rows " + f"(+{len(found['ratchet_added'])})") for script in ("perf_evidence.py", "gaps.py"): subprocess.run([PY, os.path.join(ROOT, "conformance/scripts", script)], cwd=ROOT, check=True) stack.log(f"daily run written in {(time.time() - t0) / 60:.1f} min") diff --git a/bench/ab/history.py b/bench/ab/history.py index 895321769..dc758dc39 100644 --- a/bench/ab/history.py +++ b/bench/ab/history.py @@ -8,6 +8,7 @@ history.py append SUMMARY.json [--commit SHA] [--dir bench/ab/history] history.py trend [--dir bench/ab/history] [--out bench/ab/history/trend.md] history.py last-commit [--dir bench/ab/history] + history.py alerts [--dir bench/ab/history] [--sets a,b] [--json OUT] [--markdown OUT] A line holds the run's metadata and one row per shape x range in the column order named by "cols" (so a line stays small and self-describing): @@ -17,7 +18,18 @@ Columns: shape, range, status (candidate HTTP status), p50 and cold (candidate warm p50 and first-run seconds), loki_p50, loki_cold, loki_status, parity -(candidate result vs Loki), base_p50 and verdict (vs the baseline build). +(candidate result vs Loki), base_p50 and verdict (vs the baseline build) and +loki_cold_computed (true: Loki computed its cold run; false: its results cache +answered it; null: not known, as on every line written before the column). + +alerts compares each set's newest line with the previous valid one and reports +transitions, never the state many rows are already in: a regression (result +same -> differs, 200 -> error, or a slowdown that held for two runs or that the +same run's verdict against the release also shows), an improvement, and the +ratchet. history/ratchet.json lists the rows that were as good as Loki (same +result, 200, cold no slower than Loki's computed cold); the generator only adds +to it, an owner removes a row by hand, and a row that stops being as good is a +ratchet loss. Cold, never warm p50: Loki's warm is its results cache. """ import argparse import datetime @@ -29,7 +41,7 @@ HERE = os.path.dirname(os.path.abspath(__file__)) HISTORY = os.path.join(HERE, "history") COLS = ["shape", "range", "status", "p50", "cold", "loki_p50", "loki_cold", "loki_status", "parity", "base_p50", - "verdict"] + "verdict", "loki_cold_computed"] SPARK = "โ–โ–‚โ–ƒโ–„โ–…โ–†โ–‡โ–ˆ" SHAPES = os.path.join(HERE, "shapes.json") # What one full daily measurement is: this many runs per shape x range and @@ -37,6 +49,15 @@ FULL_RUNS, FULL_MAX_RANGE = 7, "24h" # A day-over-day or week-over-week move is reported only beyond both. NOISE, MIN_DELTA = 0.25, 0.05 +RATCHET = "ratchet.json" + + +def cold_computed(row, ref): + """Whether Loki computed the reference's cold run: False when its results cache answered it + (its own counters, or identical answers for moved windows), None without counters.""" + if ref in row.get("cold_cache_served", []) or ref in row.get("stale", []): + return False + return True if (row.get("cache", {}).get(ref) or {}).get("cold") else None def entry(summary, commit=""): @@ -45,7 +66,7 @@ def entry(summary, commit=""): for row in summary["rows"]: rows.append([row["shape"], row["range"], row["status"].get(c), row["p50"].get(c), row["cold"].get(c), row["p50"].get(r), row["cold"].get(r), row["status"].get(r), - row.get("parity_vs_reference", "n/a"), row["p50"].get(b), row["verdict"]]) + row.get("parity_vs_reference", "n/a"), row["p50"].get(b), row["verdict"], cold_computed(row, r)]) return {"date": summary["date"], "commit": commit, "set": summary["set"], "label": summary.get("label", ""), "baseline": b, "candidate": c, "reference": r, "runs": summary.get("runs"), "valid": summary.get("valid", True), "restarts": [summary.get("restart_before"), summary.get("restart_after")], @@ -188,6 +209,163 @@ def trend(directory=HISTORY, window=14): return "\n".join(lines).rstrip() + "\n" +def slower(old, new): + return old is not None and new is not None and new > old * (1 + NOISE) and new - old > MIN_DELTA + + +def faster(old, new): + return old is not None and new is not None and new < old / (1 + NOISE) and old - new > MIN_DELTA + + +def short(sha): + return (sha or "?")[:10] + + +def same(parity): + # "same" and the tolerance pass "same series, sum ยฑ0.24%"; "differs" and "n/a" are not. + return isinstance(parity, str) and parity.startswith("same") + + +def fails_like_loki(row): + """An error Loki gives too, with the same result: a fix towards Loki, not a new error.""" + return row.get("status") == row.get("loki_status") and same(row.get("parity")) + + +def read_ratchet(directory=HISTORY): + path = os.path.join(directory, RATCHET) + if not os.path.exists(path): + return [] + with open(path) as f: + return json.load(f) + + +def write_ratchet(rows, directory=HISTORY): + rows = sorted(rows, key=lambda r: (r["set"], r["shape"], r["range"])) + with open(os.path.join(directory, RATCHET), "w") as f: + f.write(json.dumps(rows, indent=1, sort_keys=True, ensure_ascii=False) + "\n") + + +def cold_slower(row): + """The proxy's cold run is slower than a Loki cold run Loki computed, beyond the noise rule.""" + return (row["status"] == "200" and row.get("loki_status") == "200" and row.get("loki_cold_computed") is True + and slower(row["loki_cold"], row["cold"])) + + +def ratchet_loss(row, old): + """Why a ratcheted row is no longer as good as Loki, or "". A different result or an error counts at + once; a cold run slower than Loki's only when the previous valid line was too (one cold run is one sample).""" + if row["parity"] == "differs": + return "result differs from Loki" + if row["status"] not in (None, "200") and not fails_like_loki(row): + return f"status {row['status']}" + if cold_slower(row) and old and cold_slower(old): + return (f"cold {secs(old['cold'])} โ†’ {secs(row['cold'])} against Loki's computed " + f"{secs(old['loki_cold'])} โ†’ {secs(row['loki_cold'])}, held for two runs") + return "" + + +def ratchets(row): + """A row enters the ratchet when its result matches Loki's, it answers 200 and its cold run is + no slower than the cold run Loki computed (never the warm p50: that is Loki's results cache).""" + return (same(row["parity"]) and row["status"] == "200" and row.get("loki_status") == "200" + and row.get("loki_cold_computed") is True and row["cold"] is not None and row["loki_cold"] is not None + and row["cold"] <= row["loki_cold"]) + + +def alerts(directory=HISTORY, sets=None): + """Transitions between each set's newest line and the previous valid one, plus the ratchet. + + sets limits it to the sets a run just wrote. Pure: ratchet.json is read, never written. + """ + out = {"regressions": [], "improvements": [], "ratchet_lost": [], "ratchet_added": [], "range": {}} + held = {(r["set"], r["shape"], r["range"]): r for r in read_ratchet(directory)} + added = [] + for path in sorted(glob.glob(os.path.join(directory, "*.jsonl"))): + entries = read(path) + if not entries or not entries[-1].get("valid", True) or (sets is not None and entries[-1]["set"] not in sets): + continue + new, name = entries[-1], entries[-1]["set"] + valid = [e for e in entries[:-1] if e.get("valid", True)] + prev, prev2 = (valid[-1] if valid else None), (valid[-2] if len(valid) > 1 else None) + cur = rows_of(new) + old_rows = rows_of(prev) if prev else {} + old2_rows = rows_of(prev2) if prev2 else {} + if prev: + out["range"][name] = f"{short(prev.get('commit'))}..{short(new.get('commit'))}" + + def alert(kind, key, detail, first=prev): + return {"set": name, "shape": key[0], "range": key[1], "kind": kind, "detail": detail, + "commits": f"{short(first.get('commit'))}..{short(new.get('commit'))}"} + + for key, row in cur.items(): + old = old_rows.get(key) + if old: + if same(old["parity"]) and row["parity"] == "differs": + out["regressions"].append(alert("result", key, "result vs Loki: same โ†’ differs")) + elif old["parity"] == "differs" and same(row["parity"]): + out["improvements"].append(alert("result", key, "result vs Loki: differs โ†’ same")) + if old["status"] == "200" and row["status"] not in (None, "200") and not fails_like_loki(row): + out["regressions"].append(alert("status", key, f"status 200 โ†’ {row['status']}")) + elif old["status"] not in (None, "200") and row["status"] == "200": + out["improvements"].append(alert("status", key, f"status {old['status']} โ†’ 200")) + if old["status"] == "200" and row["status"] == "200": + span = f"warm p50 {secs(old['p50'])} โ†’ {secs(row['p50'])}" + old2 = old2_rows.get(key) or {} + if faster(old["p50"], row["p50"]): + out["improvements"].append(alert("faster", key, span)) + elif slower(old["p50"], row["p50"]) and row["verdict"] == "slower": + out["regressions"].append(alert("slower", key, f"{span}, and slower than the release in the same run")) + # Worse than the run before both of them, in both: one run of noise is not a regression. + # The change happened after prev2, so that is where the range starts (and it was + # already reported when the first slow run itself was slower than the release). + elif (old2.get("status") == "200" and slower(old2["p50"], old["p50"]) and slower(old2["p50"], row["p50"]) + and old["verdict"] != "slower"): + out["regressions"].append(alert( + "slower", key, f"warm p50 {secs(old2['p50'])} โ†’ {secs(old['p50'])} โ†’ {secs(row['p50'])}, " + "held for two runs", prev2)) + where = (name, key[0], key[1]) + if where in held: + reason = ratchet_loss(row, old) + if reason: + # A cold loss that took two runs to show began after prev2. + out["ratchet_lost"].append(alert("ratchet", key, reason, (prev2 if "held" in reason else prev) or {})) + elif ratchets(row): + added.append({"set": name, "shape": key[0], "range": key[1], "added": new["date"], + "commit": new.get("commit") or ""}) + for k in ("regressions", "improvements", "ratchet_lost"): + out[k].sort(key=lambda a: (a["set"], a["shape"], a["range"], a["kind"])) + out["ratchet_added"] = added + out["ratchet"] = sorted(list(held.values()) + added, key=lambda r: (r["set"], r["shape"], r["range"])) + return out + + +def render_alerts(a): + def items(rows, none="none"): + return [f"- `{r['set']}` {r['shape']} ยท {r['range']}: {r['detail']} (`{r['commits']}`)" for r in rows] or [none] + + return "\n".join( + ["## Regressions", "", *items(a["regressions"]), "", + "## Improvements", "", *items(a["improvements"]), "", + "## Ratchet", "", f"Lost ({len(a['ratchet_lost'])}):", "", *items(a["ratchet_lost"]), "", + f"Held: {len(a['ratchet'])} rows ({len(a['ratchet_added'])} added by this run); " + f"the list is `bench/ab/history/{RATCHET}`.", ""]) + + +def write_alerts(directory=HISTORY, sets=None, json_out="", markdown_out=""): + """alerts(), with ratchet.json updated (additions only) and the outputs written.""" + a = alerts(directory, sets) + os.makedirs(directory, exist_ok=True) + write_ratchet(a["ratchet"], directory) + if json_out: + with open(json_out, "w") as f: + json.dump(a, f, indent=1, sort_keys=True, ensure_ascii=False) + f.write("\n") + if markdown_out: + with open(markdown_out, "w") as f: + f.write(render_alerts(a)) + return a + + def main(): ap = argparse.ArgumentParser(description=__doc__, formatter_class=argparse.RawDescriptionHelpFormatter) sub = ap.add_subparsers(dest="cmd", required=True) @@ -200,6 +378,11 @@ def main(): t.add_argument("--out", default=os.path.join(HISTORY, "trend.md")) lc = sub.add_parser("last-commit") lc.add_argument("--dir", default=HISTORY) + al = sub.add_parser("alerts") + al.add_argument("--dir", default=HISTORY) + al.add_argument("--sets", default="", help="comma-separated sets (default: all)") + al.add_argument("--json", default="") + al.add_argument("--markdown", default="") args = ap.parse_args() if args.cmd == "append": for path in args.summaries: @@ -208,6 +391,10 @@ def main(): print(f"{'appended to' if added else 'already recorded in'} {target}") elif args.cmd == "last-commit": print(last_commit(args.dir)) + elif args.cmd == "alerts": + a = write_alerts(args.dir, [x for x in args.sets.split(",") if x] or None, args.json, args.markdown) + if not args.markdown: + print(render_alerts(a), end="") else: text = trend(args.dir) with open(args.out, "w") as f: diff --git a/bench/ab/tests/test_alerts.py b/bench/ab/tests/test_alerts.py new file mode 100644 index 000000000..d017a4192 --- /dev/null +++ b/bench/ab/tests/test_alerts.py @@ -0,0 +1,279 @@ +"""Unit tests for the alerts and the ratchet in bench/ab/history.py.""" +import json +import os +import subprocess +import sys +import tempfile +import unittest + +HERE = os.path.dirname(os.path.abspath(__file__)) +sys.path.insert(0, os.path.join(HERE, "..")) +import history # noqa: E402 + +COUNTERS = {"cold": {"result": {"entriesFound": 0, "bytesReceived": 0}, "statsResult": {"entriesFound": 2}}} +SHAPE, RANGE = "logs | json", "1h" + + +def row(p50=0.5, cold=0.4, loki_cold=0.9, status="200", parity="same", verdict="same", served=False, reused=False, + counters=True, loki_status="200", shape=SHAPE): + r = {"shape": shape, "range": RANGE, "verdict": verdict, + "p50": {"release": 0.5, "main": p50, "loki": 0.4}, "cold": {"release": 1.0, "main": cold, "loki": loki_cold}, + "status": {"release": "200", "main": status, "loki": loki_status}, "parity_vs_reference": parity} + if counters: + r["cache"] = {"loki": dict(COUNTERS)} + if served: + r["cold_cache_served"] = ["loki"] + if reused: + r["loki_cold_reused_from"] = {"set": "other", "shape": "x"} + return r + + +def summary(date, *rows, name="control"): + return {"set": name, "label": "daily", "date": date, "baseline": "release", "candidate": "main", + "reference": "loki", "runs": 7, "valid": True, "restart_before": "0", "restart_after": "0", + "rows": list(rows or [row()])} + + +class AlertsTest(unittest.TestCase): + def setUp(self): + self.dir = tempfile.mkdtemp() + self.n = 0 + + def day(self, *rows, name="control", commit=None): + self.n += 1 + history.append(summary(f"2026-10-{self.n:02d}", *rows, name=name), self.dir, commit or f"c{self.n}" * 12) + + def kinds(self, key, **kw): + return [(a["kind"], a["detail"]) for a in history.alerts(self.dir, **kw)[key]] + + # regressions + def test_result_regression_names_the_commit_range(self): + self.day(row(parity="same"), commit="aaaaaaaaaaaa") + self.day(row(parity="differs"), commit="bbbbbbbbbbbb") + a = history.alerts(self.dir) + self.assertEqual([(r["kind"], r["commits"]) for r in a["regressions"]], [("result", "aaaaaaaaaa..bbbbbbbbbb")]) + self.assertEqual(a["range"], {"control": "aaaaaaaaaa..bbbbbbbbbb"}) + self.assertEqual(a["improvements"], []) + + def test_tolerance_pass_is_still_same(self): + self.day(row(parity="same series, sum ยฑ0.24%")) + self.day(row(parity="differs")) + self.assertEqual(len(history.alerts(self.dir)["regressions"]), 1) + self.day(row(parity="same series, sum ยฑ0.04%")) + self.assertEqual(self.kinds("improvements"), [("result", "result vs Loki: differs โ†’ same")]) + + def test_unknown_parity_is_not_a_transition(self): + self.day(row(parity="n/a")) + self.day(row(parity="differs")) + self.assertEqual(history.alerts(self.dir)["regressions"], []) + + def test_new_error_is_a_regression_unless_loki_fails_the_same_way(self): + self.day(row()) + self.day(row(status="502", parity="differs")) + self.assertIn(("status", "status 200 โ†’ 502"), self.kinds("regressions")) + self.day(row(status="400", loki_status="400", parity="same")) + self.assertEqual(self.kinds("regressions"), []) + + def test_single_run_slowdown_is_not_a_regression(self): + self.day(row(p50=0.2)) + self.day(row(p50=0.6)) + self.assertEqual(history.alerts(self.dir)["regressions"], []) + + def test_slowdown_that_held_two_runs_is_one_from_before_it_began(self): + self.day(row(p50=0.2), commit="aaaaaaaaaaaa") + self.day(row(p50=0.6), commit="bbbbbbbbbbbb") + self.day(row(p50=0.62), commit="cccccccccccc") + a = history.alerts(self.dir)["regressions"] + self.assertEqual([(r["kind"], r["commits"]) for r in a], [("slower", "aaaaaaaaaa..cccccccccc")]) + self.assertIn("held for two runs", a[0]["detail"]) + # Reported once: the next steady day is not worse than the run before it. + self.day(row(p50=0.61)) + self.assertEqual(history.alerts(self.dir)["regressions"], []) + + def test_slowdown_within_noise_is_not_one(self): + self.day(row(p50=0.2)) + self.day(row(p50=0.22, verdict="slower")) + self.day(row(p50=0.23, verdict="slower")) + self.assertEqual(history.alerts(self.dir)["regressions"], []) + + def test_release_verdict_slowdown_is_a_regression_with_the_slowdown_itself(self): + self.day(row(p50=0.2)) + self.day(row(p50=0.6, verdict="slower")) + a = history.alerts(self.dir)["regressions"] + self.assertEqual(len(a), 1) + self.assertIn("slower than the release in the same run", a[0]["detail"]) + + def test_release_verdict_alone_is_state_not_a_transition(self): + self.day(row(p50=0.6, verdict="slower")) + self.day(row(p50=0.61, verdict="slower")) + self.assertEqual(history.alerts(self.dir)["regressions"], []) + + def test_slowdown_reported_by_the_verdict_is_not_repeated_a_run_later(self): + self.day(row(p50=0.2)) + self.day(row(p50=0.6, verdict="slower")) + self.day(row(p50=0.6, verdict="slower")) + self.assertEqual(history.alerts(self.dir)["regressions"], []) + + # improvements + def test_improvements(self): + self.day(row(parity="differs", p50=0.6), row(shape="b", status="502", p50=0.2), row(shape="c", p50=0.9)) + self.day(row(parity="same", p50=0.6), row(shape="b", status="200", p50=0.2), row(shape="c", p50=0.3)) + got = {(a["shape"], a["kind"]) for a in history.alerts(self.dir)["improvements"]} + self.assertEqual(got, {(SHAPE, "result"), ("b", "status"), ("c", "faster")}) + self.assertEqual(history.alerts(self.dir)["regressions"], []) + + def test_only_the_newest_line_against_the_previous_valid_one(self): + self.day(row(parity="same")) + s = summary("2026-10-02", row(parity="differs")) + s["valid"] = False + history.append(s, self.dir, "bad") + self.n = 2 + self.day(row(parity="same")) + self.assertEqual(history.alerts(self.dir)["regressions"], []) + self.day(row(parity="differs")) + self.assertEqual(len(history.alerts(self.dir)["regressions"]), 1) + + def test_row_new_in_the_newest_line_has_no_transition(self): + self.day(row()) + self.day(row(), row(shape="new", parity="differs", status="502")) + self.assertEqual(history.alerts(self.dir)["regressions"], []) + + def test_sets_limit_what_is_compared(self): + self.day(row(parity="same"), name="a") + self.day(row(parity="differs"), name="a") + self.day(row(parity="same"), name="b") + self.day(row(parity="differs"), name="b") + self.assertEqual({r["set"] for r in history.alerts(self.dir)["regressions"]}, {"a", "b"}) + self.assertEqual({r["set"] for r in history.alerts(self.dir, sets=["b"])["regressions"]}, {"b"}) + self.assertEqual(history.alerts(self.dir, sets=[])["regressions"], []) + + # the column + def test_loki_cold_computed(self): + col = history.COLS.index("loki_cold_computed") + for r, want in ((row(), True), (row(served=True), False), (row(counters=False), None), + (row(reused=True), True)): + self.assertEqual(history.entry(summary("2026-10-01", r))["rows"][0][col], want) + # Identical answers for moved windows: a cache answered, whatever the counters say. + stale = row() + stale["stale"] = ["loki"] + self.assertFalse(history.entry(summary("2026-10-01", stale))["rows"][0][col]) + self.assertEqual(history.COLS[-1], "loki_cold_computed") + + # ratchet + def test_ratchet_adds_only_computed_loki_colds_no_slower_than_loki(self): + self.day(row(), row(shape="served", served=True), row(shape="unknown", counters=False), + row(shape="slow", cold=1.0), row(shape="warm only", p50=0.01, cold=2.0, loki_cold=0.9), + row(shape="differs", parity="differs"), row(shape="err", status="502")) + added = history.alerts(self.dir)["ratchet_added"] + self.assertEqual([r["shape"] for r in added], [SHAPE]) + self.assertEqual(added[0], {"set": "control", "shape": SHAPE, "range": RANGE, "added": "2026-10-01", + "commit": "c1" * 12}) + + def test_lines_without_the_column_never_ratchet(self): + old = history.entry(summary("2026-10-01", row())) + old["cols"], old["rows"] = history.COLS[:-1], [r[:-1] for r in old["rows"]] + with open(os.path.join(self.dir, "control.jsonl"), "w") as f: + f.write(json.dumps(old) + "\n") + a = history.alerts(self.dir) + self.assertEqual((a["ratchet"], a["regressions"]), ([], [])) + self.n = 1 + self.day(row(parity="differs")) # old line followed by a new one still compares + self.assertEqual(len(history.alerts(self.dir)["regressions"]), 1) + self.assertIn("control", history.trend(self.dir)) + + def test_ratchet_is_written_sorted_and_only_ever_added_to(self): + self.day(row(shape="b"), row(shape="a")) + history.write_alerts(self.dir) + path = os.path.join(self.dir, "ratchet.json") + with open(path) as f: + first = f.read() + self.assertEqual([r["shape"] for r in json.loads(first)], ["a", "b"]) + self.day(row(shape="b", parity="differs"), row(shape="a"), row(shape="c")) + a = history.write_alerts(self.dir) + self.assertEqual([r["shape"] for r in a["ratchet_added"]], ["c"]) + with open(path) as f: + self.assertEqual([r["shape"] for r in json.load(f)], ["a", "b", "c"]) + # Idempotent: the same data again changes nothing. + history.write_alerts(self.dir) + with open(path) as f: + self.assertEqual(len(json.load(f)), 3) + self.assertEqual(first, first.rstrip("\n") + "\n") + + def test_ratchet_losses(self): + self.day(*(row(shape=s) for s in ("r", "e", "c", "ok", "gone", "s", "u"))) + history.write_alerts(self.dir) + self.day(row(shape="r", parity="differs"), row(shape="e", status="500", parity="n/a"), + row(shape="c", cold=1.5), row(shape="ok", cold=0.95), + row(shape="s", cold=5.0, served=True), row(shape="u", cold=5.0, counters=False)) + # Result and status are lost at once; a slower cold run is one sample. + lost = history.alerts(self.dir)["ratchet_lost"] + self.assertEqual([(a["shape"], a["detail"]) for a in lost], + [("e", "status 500"), ("r", "result differs from Loki")]) + self.assertTrue(all(a["commits"] == f"{'c1' * 5}..{'c2' * 5}" for a in lost)) + + def test_cold_loss_needs_two_runs_and_is_reported_while_it_holds(self): + self.day(row()) + history.write_alerts(self.dir) + self.day(row(cold=1.5)) + self.assertEqual(history.alerts(self.dir)["ratchet_lost"], []) + self.day(row(cold=1.4)) + lost = history.alerts(self.dir)["ratchet_lost"] + self.assertEqual([(a["kind"], a["commits"]) for a in lost], [("ratchet", f"{'c1' * 5}..{'c3' * 5}")]) + self.assertIn("held for two runs", lost[0]["detail"]) + self.day(row(cold=1.4)) + self.assertEqual(len(history.alerts(self.dir)["ratchet_lost"]), 1) + self.day(row(cold=0.5)) + self.assertEqual(history.alerts(self.dir)["ratchet_lost"], []) + + def test_cold_loss_ignores_a_loki_cold_the_cache_answered(self): + self.day(row()) + history.write_alerts(self.dir) + self.day(row(cold=1.5, served=True)) + self.day(row(cold=1.5, served=True)) + self.assertEqual(history.alerts(self.dir)["ratchet_lost"], []) + self.day(row(cold=1.5)) + self.assertEqual(history.alerts(self.dir)["ratchet_lost"], []) + + def test_markdown_is_stable(self): + self.day(row(p50=0.2), row(shape="b", parity="differs"), commit="aaaaaaaaaaaa") + history.write_alerts(self.dir) + self.day(row(p50=0.2, parity="differs"), row(shape="b", parity="same"), commit="bbbbbbbbbbbb") + text = history.render_alerts(history.alerts(self.dir)) + self.assertEqual(text, "\n".join([ + "## Regressions", "", + "- `control` logs | json ยท 1h: result vs Loki: same โ†’ differs (`aaaaaaaaaa..bbbbbbbbbb`)", "", + "## Improvements", "", + "- `control` b ยท 1h: result vs Loki: differs โ†’ same (`aaaaaaaaaa..bbbbbbbbbb`)", "", + "## Ratchet", "", "Lost (1):", "", + "- `control` logs | json ยท 1h: result differs from Loki (`aaaaaaaaaa..bbbbbbbbbb`)", "", + "Held: 2 rows (1 added by this run); the list is `bench/ab/history/ratchet.json`.", ""])) + self.assertEqual(text, history.render_alerts(history.alerts(self.dir))) + + def test_empty_sections_say_none(self): + self.day(row()) + text = history.render_alerts(history.alerts(self.dir)) + self.assertIn("## Regressions\n\nnone\n\n## Improvements\n\nnone\n\n## Ratchet\n\nLost (0):\n\nnone\n", text) + + def test_cli_writes_the_files(self): + self.day(row(parity="same")) + self.day(row(parity="differs")) + out = tempfile.mkdtemp() + js, md = os.path.join(out, "alerts.json"), os.path.join(out, "alerts.md") + res = subprocess.run([sys.executable, os.path.join(HERE, "..", "history.py"), "alerts", "--dir", self.dir, + "--json", js, "--markdown", md], capture_output=True, text=True, check=True) + self.assertEqual(res.stdout, "") + with open(js) as f: + a = json.load(f) + self.assertEqual([r["kind"] for r in a["regressions"]], ["result"]) + for k in ("improvements", "ratchet_lost", "ratchet_added", "range"): + self.assertIn(k, a) + with open(md) as f: + self.assertTrue(f.read().startswith("## Regressions\n\n- `control`")) + self.assertTrue(os.path.exists(os.path.join(self.dir, "ratchet.json"))) + res = subprocess.run([sys.executable, os.path.join(HERE, "..", "history.py"), "alerts", "--dir", self.dir], + capture_output=True, text=True, check=True) + self.assertIn("## Ratchet", res.stdout) + + +if __name__ == "__main__": + unittest.main()