From 93627471b72e3200e3ca78e1fb345c174414b716 Mon Sep 17 00:00:00 2001 From: Tejas Chopra Date: Thu, 25 Jun 2026 21:13:36 -0700 Subject: [PATCH] fix(perf): surface RTK/CLI context-tool savings in perf and the session card (#1433) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Description `headroom perf` read only `proxy.log` compression records, so RTK's savings — which live in RTK's own lifetime counter and never land in `proxy.log` — were **invisible**: perf reported "token savings" while silently dropping the entire CLI-filtering layer. The dashboard **Session** card likewise showed only the session-delta (≈0 right after a proxy restart), with no scope label and no lifetime figure. This surfaces RTK lifetime savings in `headroom perf` (text + JSON) and clarifies the dashboard Session card. It complements #1324 (which added RTK to the Historical tab) by covering the two surfaces #1324 didn't: `perf` and the live Session card. Closes # N/A — complements #1324; no standalone issue. ## Type of Change - [x] Bug fix (non-breaking change that fixes an issue) - [ ] New feature (non-breaking change that adds functionality) - [ ] Breaking change (fix or feature that would cause existing functionality to change) - [ ] Documentation update - [ ] Performance improvement - [ ] Code refactoring (no functional changes) ## Changes Made - `headroom/perf/analyzer.py`: `format_report` and `build_perf_summary` now attach RTK/CLI context-tool **lifetime** savings, sourced best-effort from `_get_context_tool_stats().lifetime` (the same source `/stats` and #1324 use). Lifetime — not session — is the right scope for a one-shot CLI, since the proxy-session baseline `/stats` subtracts is meaningless out of process. Omitted entirely when no tool is installed or its stats can't be read, so the report degrades to proxy-only rather than erroring. - `headroom/dashboard/templates/dashboard.html`: the Session card now labels the RTK number **"this session"**, uses the real `session_savings_pct` (via a new `cliFilteringSessionPctDisplay` getter) instead of an ad-hoc share, and shows **lifetime** alongside it (new `cliFilteringLifetime` getter + row, hidden when 0). - `tests/test_perf_cli_filtering.py` (new): perf surfaces RTK in text + JSON; omits cleanly when the tool is absent. - `tests/test_rtk_session_savings.py` (new): exercises the real `_get_context_tool_stats()` plumbing to pin that session RTK savings are the **delta from the startup baseline**, and session `savings_pct` is derived from that delta — not RTK's lifetime-diluted average. - `tests/test_proxy_dashboard_stats_cache.py`: updated the Session-card label assertion and added one for the new lifetime row. ## Testing - [x] Unit tests pass (`pytest`) - [x] Linting passes (`ruff check`) - [x] Type checking passes (`mypy headroom`) - [x] New tests added for new functionality - [x] Manual testing performed ### Test Output ```text $ ruff check headroom/perf/analyzer.py tests/test_perf_cli_filtering.py tests/test_rtk_session_savings.py tests/test_proxy_dashboard_stats_cache.py All checks passed! $ mypy headroom/perf/analyzer.py mypy: No issues found $ python -m pytest tests/test_perf_cli_filtering.py tests/test_rtk_session_savings.py tests/test_proxy_dashboard_stats_cache.py tests/test_owned_asset_encoding.py -q 17 passed, 1 skipped in 15.66s ``` ## Real Behavior Proof - Environment: macOS (darwin), Python 3.12, branch `fix/rtk-savings-perf-dashboard`, RTK v0.28.2. - Exact command / steps: `headroom perf` and `headroom perf --format json`. - Observed result: the text report now includes a section `RTK CLI Filtering (lifetime, all-time) — Tokens saved: 26,867,610 (68.8%), Commands: 8,023`, and the JSON output carries `"cli_filtering": {"tool":"rtk","label":"RTK","tokens_saved":26867610,"commands":8023,"savings_pct":68.8}`. Before this change, both omitted RTK entirely (perf's "Total saved" was proxy-compression only). The dashboard template renders the new "this session" / "lifetime" RTK rows (verified via `get_dashboard_html()` + substring test). - Not tested: live dashboard browser click-through (template loads and the new strings are asserted by the substring test); CSV output of `perf` (per-model table only, by design). ## Review Readiness - [x] I have performed a self-review - [x] This PR is ready for human review ## Checklist - [x] My code follows the project's style guidelines - [x] I have performed a self-review of my code - [x] I have commented my code, particularly in hard-to-understand areas - [ ] I have made corresponding changes to the documentation - [x] My changes generate no new warnings - [x] I have added tests that prove my fix is effective or that my feature works - [x] New and existing unit tests pass locally with my changes - [ ] I have updated the CHANGELOG.md if applicable ## Additional Notes - CHANGELOG: left to Release Please (the conventional `fix(perf):` commit generates the entry on merge), matching how the existing "Bug Fixes" entries are produced. - Follow-up: #1403 (`fix/rtk-savings-scope-regression`) bundles unrelated kompress must-keep work (overlaps #1400/#1419) and only documents the scope `%` invariant in the abstract. The real, code-exercising session-delta regression now lives here (`test_rtk_session_savings.py`), so #1403 can be split — route the kompress bits to #1400/#1419 and drop the rest. --- headroom/dashboard/templates/dashboard.html | 17 ++++- headroom/perf/analyzer.py | 72 +++++++++++++++++++-- tests/test_perf_cli_filtering.py | 51 +++++++++++++++ tests/test_proxy_dashboard_stats_cache.py | 3 +- tests/test_rtk_session_savings.py | 70 ++++++++++++++++++++ 5 files changed, 206 insertions(+), 7 deletions(-) create mode 100644 tests/test_perf_cli_filtering.py create mode 100644 tests/test_rtk_session_savings.py diff --git a/headroom/dashboard/templates/dashboard.html b/headroom/dashboard/templates/dashboard.html index f9d7ad519..89d6e3c40 100644 --- a/headroom/dashboard/templates/dashboard.html +++ b/headroom/dashboard/templates/dashboard.html @@ -213,7 +213,7 @@
/ - +
@@ -1023,9 +1023,13 @@
- +
+
+ + +
Proxy Removed @@ -2543,6 +2547,15 @@ return this.cliFilteringSaved / total * 100; }, + get cliFilteringLifetime() { + return this.stats.savings?.by_layer?.cli_filtering?.lifetime?.tokens_saved ?? 0; + }, + + get cliFilteringSessionPctDisplay() { + const p = this.stats.savings?.by_layer?.cli_filtering?.session_savings_pct; + return (p === null || p === undefined) ? this.cliFilteringShareOfTotal : p; + }, + // --- Headline savings percent --- // // Active ratio (saved / attempted) is the right metric when we have diff --git a/headroom/perf/analyzer.py b/headroom/perf/analyzer.py index 388e3a189..660e82c1c 100644 --- a/headroom/perf/analyzer.py +++ b/headroom/perf/analyzer.py @@ -426,15 +426,72 @@ def parse_log_files(last_n_hours: float = 168.0) -> PerfReport: return report +def _context_tool_lifetime_savings() -> dict | None: + """Lifetime savings from the configured CLI context tool (RTK / lean-ctx). + + ``perf`` reports a windowed view of the proxy's *compression* logs. The CLI + context tool (RTK) keeps its own lifetime counter that never lands in + ``proxy.log``, so without this it stays invisible in ``headroom perf`` even + when it dwarfs proxy-side savings. Lifetime (not session) is the right scope + here: ``perf`` is a one-shot CLI, so the proxy-session baseline ``/stats`` + subtracts is meaningless out of process. + + Best-effort: returns ``None`` when no tool is installed or its stats cannot + be read, so the report degrades to proxy-only rather than erroring. + """ + try: + from headroom.proxy.helpers import _get_context_tool_stats + + stats = _get_context_tool_stats() + except Exception: + return None + if not stats or not stats.get("installed", False): + return None + lifetime = stats.get("lifetime") or {} + tokens_saved = int(lifetime.get("tokens_saved", 0) or 0) + if tokens_saved <= 0: + return None + return { + "tool": str(stats.get("tool", "rtk")), + "label": str(stats.get("label", "RTK")), + "tokens_saved": tokens_saved, + "commands": int(lifetime.get("commands", 0) or 0), + "savings_pct": round(float(lifetime.get("savings_pct", 0.0) or 0.0), 1), + } + + +def _cli_filtering_report_lines() -> list[str]: + """Render the context-tool (RTK) lifetime savings section, or [] if absent.""" + cli = _context_tool_lifetime_savings() + if not cli: + return [] + return [ + f"{cli['label']} CLI Filtering (lifetime, all-time)", + "-" * 40, + f" Tokens saved: {cli['tokens_saved']:,} ({cli['savings_pct']:.1f}%)", + f" Commands: {cli['commands']:,}", + f" Note: {cli['label']}'s own lifetime counter — not limited to the --hours window.", + "", + ] + + def format_report(report: PerfReport) -> str: """Format a PerfReport into a human-readable string.""" lines: list[str] = [] + cli_filtering_lines = _cli_filtering_report_lines() if not report.perf_records and not report.router_records: - lines.append("No performance data found in ~/.headroom/logs/") - lines.append("") - lines.append("Start the proxy to begin collecting data:") - lines.append(" headroom proxy") + if cli_filtering_lines: + # RTK savings are independent of proxy logs — surface them even when + # there is no proxy traffic in the window. + lines.append("No proxy performance data in ~/.headroom/logs/ for this window.") + lines.append("") + lines.extend(cli_filtering_lines) + else: + lines.append("No performance data found in ~/.headroom/logs/") + lines.append("") + lines.append("Start the proxy to begin collecting data:") + lines.append(" headroom proxy") return "\n".join(lines) # Header @@ -662,6 +719,10 @@ def format_report(report: PerfReport) -> str: lines.append(f" {i}. {rec}") lines.append("") + # CLI context-tool (RTK) lifetime savings — its own counter never reaches + # proxy.log, so surface it here or it stays invisible in `headroom perf`. + lines.extend(cli_filtering_lines) + # Footer lines.append( f"Log files: {report.log_files_read} | Lines parsed: {report.total_lines_parsed:,}" @@ -905,6 +966,9 @@ def build_perf_summary(report: PerfReport) -> dict: "throughput": calculate_throughput(report), "log_files_read": report.log_files_read, "total_lines_parsed": report.total_lines_parsed, + # RTK/CLI context-tool lifetime savings (its own counter, not in + # proxy.log) — None when no tool is installed. Mirrors the text report. + "cli_filtering": _context_tool_lifetime_savings(), } diff --git a/tests/test_perf_cli_filtering.py b/tests/test_perf_cli_filtering.py new file mode 100644 index 000000000..7abbb9189 --- /dev/null +++ b/tests/test_perf_cli_filtering.py @@ -0,0 +1,51 @@ +"""``headroom perf`` must surface CLI context-tool (RTK) lifetime savings. + +RTK keeps its savings in its own counter, which never lands in ``proxy.log``, +so ``headroom perf`` used to omit them entirely — the report showed only +proxy-compression savings. These tests pin that the report (text + JSON) +includes the context-tool lifetime savings when available, and degrades +cleanly to proxy-only when the tool is absent. +""" + +from __future__ import annotations + +import headroom.proxy.helpers as helpers +from headroom.perf import analyzer + +_FAKE_RTK = { + "installed": True, + "tool": "rtk", + "label": "RTK", + "lifetime": {"tokens_saved": 26_853_652, "commands": 8000, "savings_pct": 68.9}, +} + + +def test_build_perf_summary_includes_cli_filtering(monkeypatch): + monkeypatch.setattr(helpers, "_get_context_tool_stats", lambda: _FAKE_RTK) + report = analyzer.parse_log_files(last_n_hours=0.0) + summary = analyzer.build_perf_summary(report) + + assert summary["cli_filtering"] is not None + assert summary["cli_filtering"]["tool"] == "rtk" + assert summary["cli_filtering"]["tokens_saved"] == 26_853_652 + assert summary["cli_filtering"]["savings_pct"] == 68.9 + + +def test_format_report_shows_cli_filtering(monkeypatch): + monkeypatch.setattr(helpers, "_get_context_tool_stats", lambda: _FAKE_RTK) + report = analyzer.parse_log_files(last_n_hours=0.0) + text = analyzer.format_report(report) + + assert "RTK CLI Filtering" in text + assert "26,853,652" in text + + +def test_perf_omits_cli_filtering_when_tool_absent(monkeypatch): + monkeypatch.setattr(helpers, "_get_context_tool_stats", lambda: None) + report = analyzer.parse_log_files(last_n_hours=0.0) + + summary = analyzer.build_perf_summary(report) + assert summary["cli_filtering"] is None + + text = analyzer.format_report(report) + assert "CLI Filtering" not in text diff --git a/tests/test_proxy_dashboard_stats_cache.py b/tests/test_proxy_dashboard_stats_cache.py index 079dfb1f3..92056e1ce 100644 --- a/tests/test_proxy_dashboard_stats_cache.py +++ b/tests/test_proxy_dashboard_stats_cache.py @@ -568,7 +568,8 @@ def test_dashboard_uses_cached_stats_and_lazy_history_feed_polling() -> None: assert "rtkShareOfTotal" not in html assert "Lean-ctx" in html assert "Context Tool" in html - assert "cliFilteringLabel + ' Filtered'" in html + assert "cliFilteringLabel + ' Filtered (this session)'" in html + assert "cliFilteringLabel + ' Filtered (lifetime)'" in html def test_proxy_throughput_in_stats_endpoint(monkeypatch: pytest.MonkeyPatch) -> None: diff --git a/tests/test_rtk_session_savings.py b/tests/test_rtk_session_savings.py new file mode 100644 index 000000000..820a7f922 --- /dev/null +++ b/tests/test_rtk_session_savings.py @@ -0,0 +1,70 @@ +"""Session RTK savings must be the delta from the proxy-startup baseline. + +Regression for the scope-mixing bug: the dashboard's *session* RTK number must +be computed from token deltas since the baseline pinned at proxy startup — NOT +from RTK's lifetime average (which dilutes a 62%-this-session rate down to an +18.5% all-time number). This exercises the real ``_get_context_tool_stats()`` +plumbing rather than asserting the arithmetic in the abstract. +""" + +from __future__ import annotations + +import headroom.proxy.helpers as helpers + + +def _reset(monkeypatch): + monkeypatch.delenv(helpers._RTK_GAIN_SCOPE_ENV, raising=False) + monkeypatch.setenv("HEADROOM_CONTEXT_TOOL", "rtk") + helpers._context_tool_stats_cache.update( + {"expires_at": 0.0, "has_value": False, "tool": None, "value": None} + ) + helpers._context_tool_session_baseline.update( + { + "initialized": False, + "tool": None, + "total_commands": 0, + "input_tokens": 0, + "output_tokens": 0, + "tokens_saved": 0, + "total_time_ms": 0, + "captured_at": 0.0, + } + ) + + +def _bust_cache(): + helpers._context_tool_stats_cache.update( + {"expires_at": 0.0, "has_value": False, "tool": None, "value": None} + ) + + +def test_session_savings_is_delta_not_lifetime_average(monkeypatch): + _reset(monkeypatch) + + state: dict = {"summary": None} + + def fake_lifetime(tool): + return helpers._context_tool_summary_payload( + tool="rtk", installed=True, scope="global", summary=state["summary"] + ) + + monkeypatch.setattr(helpers, "_read_context_tool_lifetime_stats", fake_lifetime) + + # First poll pins the baseline to the current lifetime → session delta is 0, + # but the lifetime number is preserved untouched. + state["summary"] = {"total_input": 1000, "total_output": 400, "total_saved": 600} + first = helpers._get_context_tool_stats() + assert first is not None + assert first["session"]["tokens_saved"] == 0 + assert first["lifetime"]["tokens_saved"] == 600 + + # Lifetime advances (more RTK commands run this session); the session number + # is the DELTA, not the 800 lifetime total. + _bust_cache() + state["summary"] = {"total_input": 1300, "total_output": 500, "total_saved": 800} + second = helpers._get_context_tool_stats() + assert second["session"]["tokens_saved"] == 200 # 800 - 600 + assert second["lifetime"]["tokens_saved"] == 800 + # Session % is derived from the delta (200 saved / 300 input delta), not the + # lifetime-diluted average. + assert second["session"]["savings_pct"] == round(200 / 300 * 100, 4)