mirror of
https://github.com/headroomlabs-ai/headroom.git
synced 2026-08-27 14:17:10 -04:00
fix(perf): surface RTK/CLI context-tool savings in perf and the session card (#1433)
## 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.
This commit is contained in:
Tejas Chopra
GitHub
parent
dca9853ed9
commit
93627471b7
5 changed files with 206 additions and 7 deletions
|
|
@ -213,7 +213,7 @@
|
|||
<div class="mt-1 text-xs text-gray-500 leading-relaxed">
|
||||
<span x-text="'Proxy ' + formatNumber(stats.tokens?.proxy_compression_saved || 0) + ' (' + proxyShareOfTotal.toFixed(1) + '%)'"></span>
|
||||
<span class="mx-1 text-gray-600">/</span>
|
||||
<span x-text="cliFilteringLabel + ' ' + formatNumber(cliFilteringSaved) + ' (' + cliFilteringShareOfTotal.toFixed(1) + '%)'"></span>
|
||||
<span x-text="cliFilteringLabel + ' ' + formatNumber(cliFilteringSaved) + ' this session (' + cliFilteringSessionPctDisplay.toFixed(1) + '%)'"></span>
|
||||
</div>
|
||||
<div class="mt-1 text-xs text-gray-600 leading-relaxed">
|
||||
<span x-text="'Of total wire: ' + (stats.tokens?.savings_percent || 0).toFixed(2) + '%'" title="Savings as fraction of all input tokens including frozen prefix"></span>
|
||||
|
|
@ -1023,9 +1023,13 @@
|
|||
<span class="font-mono text-sm" x-text="formatNumber(stats.tokens?.total_before_compression || 0)"></span>
|
||||
</div>
|
||||
<div class="flex justify-between items-center">
|
||||
<span class="text-sm text-gray-400" x-text="cliFilteringLabel + ' Filtered'"></span>
|
||||
<span class="text-sm text-gray-400" x-text="cliFilteringLabel + ' Filtered (this session)'"></span>
|
||||
<span class="font-mono text-sm text-emerald-400" x-text="formatNumber(cliFilteringSaved)"></span>
|
||||
</div>
|
||||
<div class="flex justify-between items-center" x-show="cliFilteringLifetime > 0">
|
||||
<span class="text-sm text-gray-500" x-text="cliFilteringLabel + ' Filtered (lifetime)'"></span>
|
||||
<span class="font-mono text-sm text-emerald-400/70" x-text="formatNumber(cliFilteringLifetime)"></span>
|
||||
</div>
|
||||
<div class="flex justify-between items-center">
|
||||
<span class="text-sm text-gray-400">Proxy Removed</span>
|
||||
<span class="font-mono text-sm text-accent" x-text="formatNumber(stats.tokens?.proxy_compression_saved || 0)"></span>
|
||||
|
|
@ -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
|
||||
|
|
|
|||
|
|
@ -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(),
|
||||
}
|
||||
|
||||
|
||||
|
|
|
|||
51
tests/test_perf_cli_filtering.py
Normal file
51
tests/test_perf_cli_filtering.py
Normal file
|
|
@ -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
|
||||
|
|
@ -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:
|
||||
|
|
|
|||
70
tests/test_rtk_session_savings.py
Normal file
70
tests/test_rtk_session_savings.py
Normal file
|
|
@ -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)
|
||||
Loading…
Add table
Add a link
Reference in a new issue