diff --git a/scripts/audit_rebuild_log.py b/scripts/audit_rebuild_log.py new file mode 100644 index 000000000..6409b4acb --- /dev/null +++ b/scripts/audit_rebuild_log.py @@ -0,0 +1,220 @@ +#!/usr/bin/env python3 +"""Summarise a per-session rebuild_log JSONL. + +Phase-1c companion to the #288 phase-1a rebuild diagnostic log. Reads +one or more `.jsonl` files and prints: + + * total rebuild invocations + * pack rate (n_packed / n_candidates) distribution: mean, p50, p90 + * drop-reason histogram (e.g. ``below_floor:0.40``, + ``content_hash_collision_with:``, ``budget``) + * for packed rows, the rank distribution (1, 2, 3, ...) — surfaces + whether the rebuilder typically packs the top candidate or + something further down + * count of truncated session-files + +Usage: + + python scripts/audit_rebuild_log.py [...] + +Exit codes: + 0 summary printed + 1 no readable input + 2 usage error + +Reads only — never modifies the log files. +""" +from __future__ import annotations + +import argparse +import json +import sys +from collections import Counter +from pathlib import Path +from typing import Iterable + + +def _iter_records(path: Path) -> Iterable[dict]: + """Yield decoded JSON records from a JSONL file. Skips malformed + lines (the writer is fail-soft so partial lines on a crash are + expected).""" + try: + text = path.read_text(encoding="utf-8") + except OSError as exc: + print( + f"audit_rebuild_log: cannot read {path}: {exc}", + file=sys.stderr, + ) + return + for line in text.splitlines(): + if not line.strip(): + continue + try: + yield json.loads(line) + except json.JSONDecodeError: + continue + + +def _collect_paths(targets: list[Path]) -> list[Path]: + out: list[Path] = [] + for t in targets: + if t.is_dir(): + out.extend(sorted(t.glob("*.jsonl"))) + elif t.is_file(): + out.append(t) + else: + print( + f"audit_rebuild_log: skipping {t}: not a file or dir", + file=sys.stderr, + ) + return out + + +def _percentile(values: list[float], p: float) -> float: + """Nearest-rank percentile. Empty -> 0.0.""" + if not values: + return 0.0 + s = sorted(values) + k = max(0, min(len(s) - 1, int(round((p / 100.0) * (len(s) - 1))))) + return s[k] + + +def _summarise(records: list[dict]) -> dict: + n_records = 0 + n_truncated = 0 + pack_rates: list[float] = [] + drop_reasons: Counter[str] = Counter() + packed_ranks: Counter[int] = Counter() + n_no_pack_summary = 0 + + for r in records: + if r.get("truncated") is True: + n_truncated += 1 + continue + n_records += 1 + pack = r.get("pack_summary") + if isinstance(pack, dict): + n_cand = pack.get("n_candidates", 0) or 0 + n_packed = pack.get("n_packed", 0) or 0 + if n_cand > 0: + pack_rates.append(n_packed / n_cand) + else: + n_no_pack_summary += 1 + candidates = r.get("candidates") + if not isinstance(candidates, list): + continue + for c in candidates: + if not isinstance(c, dict): + continue + decision = c.get("decision") + if decision == "dropped": + reason = c.get("reason") or "" + drop_reasons[str(reason)] += 1 + elif decision == "packed": + rank = c.get("rank") + if isinstance(rank, int): + packed_ranks[rank] += 1 + + return { + "n_records": n_records, + "n_truncated": n_truncated, + "n_no_pack_summary": n_no_pack_summary, + "pack_rate_mean": ( + sum(pack_rates) / len(pack_rates) if pack_rates else 0.0 + ), + "pack_rate_p50": _percentile(pack_rates, 50), + "pack_rate_p90": _percentile(pack_rates, 90), + "drop_reasons": drop_reasons, + "packed_ranks": packed_ranks, + } + + +def _bucketise_drop_reasons(reasons: Counter[str]) -> Counter[str]: + """Group reasons by their semantic prefix. + + A reason looks like ``below_floor:0.40`` or + ``content_hash_collision_with:abc123``. The float / id tail varies + per call, so the histogram is dominated by uniques unless we + bucket on the part before ``:``. Reasons without a ``:`` are kept + as-is. + """ + out: Counter[str] = Counter() + for reason, n in reasons.items(): + head = reason.split(":", 1)[0] if ":" in reason else reason + out[head] += n + return out + + +def _print_report(summary: dict, *, paths_read: int) -> None: + print(f"rebuild_log audit — {paths_read} file(s)") + print(f" records: {summary['n_records']}") + if summary["n_truncated"]: + print( + f" truncated: {summary['n_truncated']} " + "(session(s) hit the 5 MB cap)" + ) + if summary["n_no_pack_summary"]: + print( + f" malformed: {summary['n_no_pack_summary']} " + "(record had no pack_summary)" + ) + print() + print("pack rate (n_packed / n_candidates):") + print(f" mean: {summary['pack_rate_mean']:.3f}") + print(f" p50: {summary['pack_rate_p50']:.3f}") + print(f" p90: {summary['pack_rate_p90']:.3f}") + print() + print("drop-reason histogram (bucketed by prefix):") + bucketed = _bucketise_drop_reasons(summary["drop_reasons"]) + if not bucketed: + print(" (none)") + else: + for reason, n in bucketed.most_common(): + print(f" {n:>6} {reason}") + print() + print("packed-rank distribution (where in the candidate list " + "the packed row was):") + if not summary["packed_ranks"]: + print(" (none)") + else: + for rank in sorted(summary["packed_ranks"]): + print(f" rank {rank:>2}: {summary['packed_ranks'][rank]}") + + +def main(argv: list[str] | None = None) -> int: + parser = argparse.ArgumentParser( + description=( + "Summarise rebuild_log JSONL files (phase-1c for #288). " + "Reads only; never modifies the input." + ), + ) + parser.add_argument( + "paths", + nargs="+", + type=Path, + help=( + "One or more JSONL files, or directories containing " + "*.jsonl session-log files." + ), + ) + args = parser.parse_args(argv) + + paths = _collect_paths(args.paths) + if not paths: + print( + "audit_rebuild_log: no readable JSONL inputs", + file=sys.stderr, + ) + return 1 + + records: list[dict] = [] + for p in paths: + records.extend(_iter_records(p)) + + summary = _summarise(records) + _print_report(summary, paths_read=len(paths)) + return 0 + + +if __name__ == "__main__": + raise SystemExit(main()) diff --git a/tests/test_audit_rebuild_log.py b/tests/test_audit_rebuild_log.py new file mode 100644 index 000000000..75d73f883 --- /dev/null +++ b/tests/test_audit_rebuild_log.py @@ -0,0 +1,230 @@ +"""Tests for `scripts/audit_rebuild_log.py` (#288 phase-1c). + +Covers the summary maths, drop-reason bucketing, JSONL iteration with +malformed-line tolerance, and CLI exit codes. +""" +from __future__ import annotations + +import importlib.util +import io +import json +import sys +from collections import Counter +from pathlib import Path + +import pytest + + +_REPO_ROOT = Path(__file__).resolve().parent.parent +_AUDIT_PATH = _REPO_ROOT / "scripts" / "audit_rebuild_log.py" + + +def _load_module(): + spec = importlib.util.spec_from_file_location( + "audit_rebuild_log", _AUDIT_PATH, + ) + assert spec is not None and spec.loader is not None + mod = importlib.util.module_from_spec(spec) + spec.loader.exec_module(mod) + return mod + + +audit = _load_module() + + +# ---- helpers ----------------------------------------------------------- + + +def _record( + *, + candidates: list[dict], + n_candidates: int, + n_packed: int, + n_dropped_floor: int = 0, + n_dropped_dedup: int = 0, + n_dropped_budget: int = 0, +) -> dict: + return { + "ts": "2026-05-02T00:00:00Z", + "session_id": "s1", + "input": { + "recent_turns_hash": "abc", + "n_recent_turns": 1, + "extracted_query": "q", + "extracted_entities": [], + "extracted_intent": None, + }, + "candidates": candidates, + "pack_summary": { + "n_candidates": n_candidates, + "n_packed": n_packed, + "n_dropped_by_floor": n_dropped_floor, + "n_dropped_by_dedup": n_dropped_dedup, + "n_dropped_by_budget": n_dropped_budget, + "total_chars_packed": 100, + }, + } + + +def _packed(belief_id: str, rank: int) -> dict: + return { + "belief_id": belief_id, + "rank": rank, + "scores": {"bm25": None, "posterior_mean": None, + "reranker": None, "final": None}, + "lock_level": "none", + "decision": "packed", + "reason": None, + } + + +def _dropped(belief_id: str, rank: int, reason: str) -> dict: + return { + "belief_id": belief_id, + "rank": rank, + "scores": {"bm25": None, "posterior_mean": None, + "reranker": None, "final": None}, + "lock_level": "none", + "decision": "dropped", + "reason": reason, + } + + +def _write_jsonl(path: Path, rows: list[dict]) -> None: + path.parent.mkdir(parents=True, exist_ok=True) + with path.open("w", encoding="utf-8") as f: + for r in rows: + f.write(json.dumps(r, separators=(",", ":")) + "\n") + + +# ---- summarise --------------------------------------------------------- + + +def test_summarise_counts_records_and_pack_rate(tmp_path: Path) -> None: + rows = [ + _record( + candidates=[_packed("a", 1), _packed("b", 2), + _dropped("c", 3, "below_floor:0.40")], + n_candidates=3, n_packed=2, n_dropped_floor=1, + ), + _record( + candidates=[_packed("d", 1), + _dropped("e", 2, "below_floor:0.50"), + _dropped("f", 3, "below_floor:0.60")], + n_candidates=3, n_packed=1, n_dropped_floor=2, + ), + ] + s = audit._summarise(rows) + assert s["n_records"] == 2 + assert s["n_truncated"] == 0 + assert s["pack_rate_mean"] == pytest.approx((2 / 3 + 1 / 3) / 2) + assert s["packed_ranks"] == Counter({1: 2, 2: 1}) + assert s["drop_reasons"] == Counter({ + "below_floor:0.40": 1, + "below_floor:0.50": 1, + "below_floor:0.60": 1, + }) + + +def test_summarise_counts_truncated_marker_separately() -> None: + rows = [ + _record(candidates=[_packed("a", 1)], n_candidates=1, n_packed=1), + {"truncated": True, "ts": "2026-05-02T00:00:00Z", + "reason": "size_cap", "cap_bytes": 5_242_880}, + ] + s = audit._summarise(rows) + assert s["n_records"] == 1 + assert s["n_truncated"] == 1 + + +def test_summarise_handles_missing_pack_summary() -> None: + rows = [ + {"ts": "x", "session_id": None, "input": {}, + "candidates": [_packed("a", 1)]}, # no pack_summary + ] + s = audit._summarise(rows) + assert s["n_records"] == 1 + assert s["n_no_pack_summary"] == 1 + # packed rank still picked up from the candidate list + assert s["packed_ranks"] == Counter({1: 1}) + + +# ---- drop-reason bucketing -------------------------------------------- + + +def test_bucketise_drop_reasons_groups_on_prefix() -> None: + raw = Counter({ + "below_floor:0.40": 3, + "below_floor:0.41": 2, + "content_hash_collision_with:abc": 4, + "content_hash_collision_with:def": 1, + "budget": 7, + "below_floor:0.42": 1, + }) + bucketed = audit._bucketise_drop_reasons(raw) + assert bucketed == Counter({ + "below_floor": 6, + "content_hash_collision_with": 5, + "budget": 7, + }) + + +# ---- iteration / file handling ---------------------------------------- + + +def test_iter_records_skips_malformed_lines(tmp_path: Path) -> None: + p = tmp_path / "s.jsonl" + p.write_text( + json.dumps({"ts": "x", "candidates": []}) + "\n" + "this is not json\n" + "\n" + + json.dumps({"ts": "y", "candidates": []}) + "\n", + encoding="utf-8", + ) + rows = list(audit._iter_records(p)) + assert len(rows) == 2 + assert rows[0]["ts"] == "x" + assert rows[1]["ts"] == "y" + + +def test_collect_paths_expands_directory(tmp_path: Path) -> None: + (tmp_path / "a.jsonl").write_text("", encoding="utf-8") + (tmp_path / "b.jsonl").write_text("", encoding="utf-8") + (tmp_path / "ignore.txt").write_text("", encoding="utf-8") + out = audit._collect_paths([tmp_path]) + assert sorted(p.name for p in out) == ["a.jsonl", "b.jsonl"] + + +# ---- CLI -------------------------------------------------------------- + + +def test_cli_returns_1_on_no_input( + tmp_path: Path, capsys: pytest.CaptureFixture[str], +) -> None: + rc = audit.main([str(tmp_path / "missing")]) + assert rc == 1 + + +def test_cli_returns_0_and_prints_summary( + tmp_path: Path, capsys: pytest.CaptureFixture[str], +) -> None: + p = tmp_path / "s1.jsonl" + _write_jsonl(p, [ + _record(candidates=[_packed("a", 1), + _dropped("b", 2, "below_floor:0.40")], + n_candidates=2, n_packed=1, n_dropped_floor=1), + ]) + rc = audit.main([str(p)]) + assert rc == 0 + out = capsys.readouterr().out + assert "records: 1" in out + assert "below_floor" in out + assert "rank 1: 1" in out + + +def test_cli_percentile_nearest_rank() -> None: + assert audit._percentile([], 50) == 0.0 + assert audit._percentile([0.5], 50) == 0.5 + # 5 values, p50 -> middle, p90 -> last + assert audit._percentile([0.1, 0.2, 0.3, 0.4, 0.5], 50) == 0.3 + assert audit._percentile([0.1, 0.2, 0.3, 0.4, 0.5], 90) == 0.5