94b8d5d118
Docker / docker-build (map[name:amd64 platform:linux/amd64 runs_on:ubuntu-24.04], map[bake_target:runtime-slim name:slim]) (push) Waiting to run
Docker / docker-build (map[name:amd64 platform:linux/amd64 runs_on:ubuntu-24.04], map[bake_target:runtime-slim-nonroot name:slim-nonroot]) (push) Waiting to run
Docker / docker-build (map[name:arm64 platform:linux/arm64 runs_on:ubuntu-24.04-arm], map[bake_target:runtime name:]) (push) Waiting to run
Docker / docker-build (map[name:arm64 platform:linux/arm64 runs_on:ubuntu-24.04-arm], map[bake_target:runtime-code name:code]) (push) Waiting to run
Docker / docker-build (map[name:amd64 platform:linux/amd64 runs_on:ubuntu-24.04], map[bake_target:runtime name:]) (push) Waiting to run
Docker / docker-build (map[name:amd64 platform:linux/amd64 runs_on:ubuntu-24.04], map[bake_target:runtime-code name:code]) (push) Waiting to run
Docker / docker-build (map[name:amd64 platform:linux/amd64 runs_on:ubuntu-24.04], map[bake_target:runtime-code-nonroot name:code-nonroot]) (push) Waiting to run
Docker / docker-build (map[name:amd64 platform:linux/amd64 runs_on:ubuntu-24.04], map[bake_target:runtime-code-slim name:code-slim]) (push) Waiting to run
Docker / docker-build (map[name:amd64 platform:linux/amd64 runs_on:ubuntu-24.04], map[bake_target:runtime-code-slim-nonroot name:code-slim-nonroot]) (push) Waiting to run
Docker / docker-build (map[name:amd64 platform:linux/amd64 runs_on:ubuntu-24.04], map[bake_target:runtime-nonroot name:nonroot]) (push) Waiting to run
Docker / docker-build (map[name:arm64 platform:linux/arm64 runs_on:ubuntu-24.04-arm], map[bake_target:runtime-code-nonroot name:code-nonroot]) (push) Waiting to run
Docker / docker-build (map[name:arm64 platform:linux/arm64 runs_on:ubuntu-24.04-arm], map[bake_target:runtime-code-slim name:code-slim]) (push) Waiting to run
Docker / docker-build (map[name:arm64 platform:linux/arm64 runs_on:ubuntu-24.04-arm], map[bake_target:runtime-slim name:slim]) (push) Waiting to run
Docker / docker-build (map[name:arm64 platform:linux/arm64 runs_on:ubuntu-24.04-arm], map[bake_target:runtime-slim-nonroot name:slim-nonroot]) (push) Waiting to run
Docker / docker-manifest (map[bake_target:runtime name:]) (push) Blocked by required conditions
Docker / docker-manifest (map[bake_target:runtime-code name:code]) (push) Blocked by required conditions
Docker / docker-manifest (map[bake_target:runtime-code-nonroot name:code-nonroot]) (push) Blocked by required conditions
Docker / docker-manifest (map[bake_target:runtime-code-slim name:code-slim]) (push) Blocked by required conditions
Docker / docker-manifest (map[bake_target:runtime-code-slim-nonroot name:code-slim-nonroot]) (push) Blocked by required conditions
Docker / docker-build (map[name:arm64 platform:linux/arm64 runs_on:ubuntu-24.04-arm], map[bake_target:runtime-code-slim-nonroot name:code-slim-nonroot]) (push) Waiting to run
Docker / docker-build (map[name:arm64 platform:linux/arm64 runs_on:ubuntu-24.04-arm], map[bake_target:runtime-nonroot name:nonroot]) (push) Waiting to run
Docker / docker-manifest (map[bake_target:runtime-nonroot name:nonroot]) (push) Blocked by required conditions
Docker / docker-manifest (map[bake_target:runtime-slim name:slim]) (push) Blocked by required conditions
Docker / docker-manifest (map[bake_target:runtime-slim-nonroot name:slim-nonroot]) (push) Blocked by required conditions
Docker / promote-latest (push) Blocked by required conditions
Init Native E2E / init-native (macos-latest, claude) (push) Waiting to run
Init Native E2E / init-native (macos-latest, codex) (push) Waiting to run
Init Native E2E / init-native (macos-latest, copilot) (push) Waiting to run
Install Native E2E / install-native (macos-latest) (push) Waiting to run
Wrap Native E2E / wrap-native (macos-latest) (push) Waiting to run
Security / Dependency audit (pip-audit) (push) Has been cancelled
Security / CodeQL (javascript-typescript) (push) Has been cancelled
Security / CodeQL (python) (push) Has been cancelled
Security / Secret scan (gitleaks) (push) Has been cancelled
rust / test (ubuntu) (push) Has been cancelled
rust / simulator e2e (macos-latest) (push) Has been cancelled
rust / simulator e2e (ubuntu-latest) (push) Has been cancelled
rust / simulator e2e (windows-latest) (push) Has been cancelled
rust / wheels (aarch64-apple-darwin) (push) Has been cancelled
rust / wheels (x86_64-unknown-linux-gnu) (push) Has been cancelled
rust / wheels (x86_64-apple-darwin) (push) Has been cancelled
rust / audit (push) Has been cancelled
rust / parity (nightly, allowed to fail during Phase 0) (push) Has been cancelled
CI / changes (push) Failing after 2s
Deploy Documentation / deploy (push) Failing after 0s
CI / commitlint (push) Has been skipped
Dev Containers / validate (.devcontainer/devcontainer.json, default) (push) Failing after 1s
Dev Containers / validate-worktree (push) Failing after 1s
Dev Containers / validate (.devcontainer/memory-stack/devcontainer.json, memory-stack) (push) Failing after 1s
Wrap Native E2E / wrap-native (ubuntu-latest) (push) Failing after 4s
Deploy Documentation / validate (push) Has been skipped
Init E2E / docker-init-e2e (push) Failing after 1s
Init Native E2E / init-native (ubuntu-latest, claude) (push) Failing after 1s
Init Native E2E / init-native (ubuntu-latest, codex) (push) Failing after 0s
Install Native E2E / install-native (ubuntu-latest) (push) Failing after 1s
Release Please / release-please (push) Failing after 0s
Wrap E2E / docker-wrap-e2e (push) Failing after 1s
Merge Conflicts / merge-conflicts (push) Failing after 2s
OpenCode Plugin / typecheck + build + test (push) Failing after 2s
Init Native E2E / init-native (ubuntu-latest, copilot) (push) Failing after 3s
CI / test (1) (push) Has been cancelled
CI / test (2) (push) Has been cancelled
CI / test (3) (push) Has been cancelled
CI / test (4) (push) Has been cancelled
CI / test-extras (push) Has been cancelled
CI / test-agno (push) Has been cancelled
CI / test-dashboard-ui (push) Has been cancelled
CI / docker-native-e2e (push) Has been cancelled
CI / lint (push) Has been cancelled
CI / build-wheel (push) Has been cancelled
CI / build-wheel-windows (push) Has been cancelled
CI / prefetch-model (push) Has been cancelled
CI / windows-native-wrapper (push) Has been cancelled
CI / build (push) Has been cancelled
CI / workflow-validation (push) Has been cancelled
CI / macos-native-wrapper (push) Has been cancelled
315 lines
12 KiB
Python
315 lines
12 KiB
Python
"""Tests for `headroom perf --format {text,json,csv}` (issue #595)."""
|
|
|
|
from __future__ import annotations
|
|
|
|
import csv
|
|
import io
|
|
import json
|
|
|
|
import pytest
|
|
from click.testing import CliRunner
|
|
|
|
from headroom.cli.main import main
|
|
from headroom.perf import analyzer
|
|
from headroom.perf.analyzer import (
|
|
PerfRecord,
|
|
PerfReport,
|
|
TransformRecord,
|
|
build_perf_summary,
|
|
perf_records_as_dicts,
|
|
)
|
|
|
|
|
|
@pytest.fixture
|
|
def runner() -> CliRunner:
|
|
return CliRunner()
|
|
|
|
|
|
def _sample_report() -> PerfReport:
|
|
"""A small report with two models, cache numbers, and a transform."""
|
|
return PerfReport(
|
|
perf_records=[
|
|
PerfRecord(
|
|
timestamp="2026-06-05 10:00:00,000",
|
|
request_id="hr_1",
|
|
model="claude-sonnet-4.5",
|
|
num_messages=10,
|
|
tokens_before=1000,
|
|
tokens_after=400,
|
|
tokens_saved=600,
|
|
cache_read=800,
|
|
cache_write=200,
|
|
cache_hit_pct=80,
|
|
optimization_ms=12.0,
|
|
transforms=["content_router"],
|
|
),
|
|
PerfRecord(
|
|
timestamp="2026-06-05 11:00:00,000",
|
|
request_id="hr_2",
|
|
model="claude-opus-4-8",
|
|
num_messages=4,
|
|
tokens_before=1000,
|
|
tokens_after=600,
|
|
tokens_saved=400,
|
|
cache_read=200,
|
|
cache_write=0,
|
|
cache_hit_pct=100,
|
|
optimization_ms=8.0,
|
|
transforms=["content_router"],
|
|
),
|
|
],
|
|
transform_records=[
|
|
TransformRecord(
|
|
timestamp="2026-06-05 10:00:00,000",
|
|
name="content_router",
|
|
tokens_before=2000,
|
|
tokens_after=1000,
|
|
tokens_saved=1000,
|
|
),
|
|
],
|
|
log_files_read=1,
|
|
total_lines_parsed=42,
|
|
requested_hours=24.0,
|
|
oldest_kept_ts="2026-06-05 10:00:00,000",
|
|
newest_kept_ts="2026-06-05 11:00:00,000",
|
|
)
|
|
|
|
|
|
# ---------------------------------------------------------------------------
|
|
# Pure builders
|
|
# ---------------------------------------------------------------------------
|
|
|
|
|
|
def test_build_perf_summary_totals_and_pct():
|
|
summary = build_perf_summary(_sample_report())
|
|
|
|
assert summary["total_requests"] == 2
|
|
assert summary["total_tokens_before"] == 2000
|
|
assert summary["total_tokens_after"] == 1000
|
|
assert summary["tokens_saved"] == 1000
|
|
# 1000 / 2000 == 50.0%
|
|
assert summary["savings_pct"] == 50.0
|
|
# cache: read 1000, write 200 -> 1000 / 1200 == 83.3%
|
|
assert summary["cache_read_tokens"] == 1000
|
|
assert summary["cache_write_tokens"] == 200
|
|
assert summary["cache_hit_pct"] == 83.3
|
|
assert summary["window_hours"] == 24.0
|
|
|
|
|
|
def test_build_perf_summary_by_model_and_transform():
|
|
summary = build_perf_summary(_sample_report())
|
|
|
|
models = {m["model"]: m for m in summary["by_model"]}
|
|
assert set(models) == {"claude-sonnet-4.5", "claude-opus-4-8"}
|
|
assert models["claude-sonnet-4.5"]["tokens_saved"] == 600
|
|
assert models["claude-sonnet-4.5"]["savings_pct"] == 60.0
|
|
assert models["claude-opus-4-8"]["savings_pct"] == 40.0
|
|
|
|
assert summary["by_transform"][0]["transform"] == "content_router"
|
|
assert summary["by_transform"][0]["tokens_saved"] == 1000
|
|
assert summary["by_transform"][0]["uses"] == 1
|
|
|
|
|
|
def test_build_perf_summary_empty_report_no_zero_division():
|
|
summary = build_perf_summary(PerfReport(requested_hours=168.0))
|
|
assert summary["total_requests"] == 0
|
|
assert summary["savings_pct"] == 0.0
|
|
assert summary["cache_hit_pct"] == 0.0
|
|
assert summary["by_model"] == []
|
|
|
|
|
|
def test_perf_records_as_dicts_roundtrips_fields():
|
|
dicts = perf_records_as_dicts(_sample_report())
|
|
assert len(dicts) == 2
|
|
assert dicts[0]["request_id"] == "hr_1"
|
|
assert dicts[0]["tokens_saved"] == 600
|
|
# transforms stays a list for JSON consumers
|
|
assert dicts[0]["transforms"] == ["content_router"]
|
|
|
|
|
|
# ---------------------------------------------------------------------------
|
|
# CLI integration
|
|
# ---------------------------------------------------------------------------
|
|
|
|
|
|
def _patch_report(monkeypatch, report: PerfReport) -> None:
|
|
monkeypatch.setattr(analyzer, "parse_log_files", lambda last_n_hours=168.0: report)
|
|
|
|
|
|
def test_perf_json_format(runner, monkeypatch):
|
|
_patch_report(monkeypatch, _sample_report())
|
|
result = runner.invoke(main, ["perf", "--format", "json"])
|
|
assert result.exit_code == 0, result.output
|
|
data = json.loads(result.output)
|
|
assert data["savings_pct"] == 50.0
|
|
assert "by_model" in data
|
|
assert data["total_requests"] == 2
|
|
|
|
|
|
def test_perf_json_raw_is_array(runner, monkeypatch):
|
|
_patch_report(monkeypatch, _sample_report())
|
|
result = runner.invoke(main, ["perf", "--format", "json", "--raw"])
|
|
assert result.exit_code == 0, result.output
|
|
data = json.loads(result.output)
|
|
assert isinstance(data, list)
|
|
assert len(data) == 2
|
|
assert data[0]["request_id"] == "hr_1"
|
|
|
|
|
|
def test_perf_json_raw_preserves_client_field(runner, monkeypatch):
|
|
report = _sample_report()
|
|
report.perf_records[0].client = "codex"
|
|
_patch_report(monkeypatch, report)
|
|
|
|
result = runner.invoke(main, ["perf", "--format", "json", "--raw"])
|
|
|
|
assert result.exit_code == 0, result.output
|
|
data = json.loads(result.output)
|
|
assert data[0]["client"] == "codex"
|
|
|
|
|
|
def test_parse_perf_line_preserves_client_field(monkeypatch, tmp_path):
|
|
log_dir = tmp_path / "logs"
|
|
log_dir.mkdir()
|
|
(log_dir / "proxy.log").write_text(
|
|
"2026-06-10 10:00:00,000 - headroom.proxy - INFO - "
|
|
"[hr_codex] PERF model=gpt-5 msgs=3 tok_before=1000 "
|
|
"tok_after=90 tok_saved=910 cache_read=0 cache_write=0 "
|
|
"cache_hit_pct=0 opt_ms=12 transforms=content_router client=codex\n"
|
|
)
|
|
monkeypatch.setattr(analyzer, "LOG_DIR", log_dir)
|
|
|
|
report = analyzer.parse_log_files(last_n_hours=0)
|
|
|
|
assert len(report.perf_records) == 1
|
|
assert report.perf_records[0].client == "codex"
|
|
|
|
|
|
def test_perf_csv_by_model(runner, monkeypatch):
|
|
_patch_report(monkeypatch, _sample_report())
|
|
result = runner.invoke(main, ["perf", "--format", "csv"])
|
|
assert result.exit_code == 0, result.output
|
|
rows = list(csv.DictReader(io.StringIO(result.output)))
|
|
assert {r["model"] for r in rows} == {"claude-sonnet-4.5", "claude-opus-4-8"}
|
|
sonnet = next(r for r in rows if r["model"] == "claude-sonnet-4.5")
|
|
assert sonnet["tokens_saved"] == "600"
|
|
|
|
|
|
def test_perf_csv_raw_per_record(runner, monkeypatch):
|
|
report = _sample_report()
|
|
report.perf_records[0].client = "codex"
|
|
_patch_report(monkeypatch, report)
|
|
result = runner.invoke(main, ["perf", "--format", "csv", "--raw"])
|
|
assert result.exit_code == 0, result.output
|
|
rows = list(csv.DictReader(io.StringIO(result.output)))
|
|
assert len(rows) == 2
|
|
assert rows[0]["request_id"] == "hr_1"
|
|
assert rows[0]["client"] == "codex"
|
|
# transforms flattened to a string cell
|
|
assert rows[0]["transforms"] == "content_router"
|
|
|
|
|
|
def test_perf_text_default_unchanged(runner, monkeypatch):
|
|
_patch_report(monkeypatch, _sample_report())
|
|
result = runner.invoke(main, ["perf"])
|
|
assert result.exit_code == 0, result.output
|
|
assert "Headroom Performance Report" in result.output
|
|
|
|
|
|
def test_perf_rejects_unknown_format(runner, monkeypatch):
|
|
_patch_report(monkeypatch, _sample_report())
|
|
result = runner.invoke(main, ["perf", "--format", "xml"])
|
|
assert result.exit_code != 0
|
|
|
|
|
|
def test_parse_perf_line_preserves_blank_client_field(
|
|
tmp_path, monkeypatch: pytest.MonkeyPatch
|
|
) -> None:
|
|
logs_dir = tmp_path / "logs"
|
|
logs_dir.mkdir()
|
|
monkeypatch.setattr(analyzer, "LOG_DIR", logs_dir)
|
|
(logs_dir / "proxy.log").write_text(
|
|
"2026-06-10 10:00:00,000 - headroom.proxy - INFO - [req-blank] PERF "
|
|
"model=gpt-5 msgs=1 tok_before=100 tok_after=50 tok_saved=50 "
|
|
"cache_read=0 cache_write=0 cache_hit_pct=0 opt_ms=1 transforms=test client=\n",
|
|
encoding="utf-8",
|
|
)
|
|
|
|
report = analyzer.parse_log_files(last_n_hours=0)
|
|
|
|
assert len(report.perf_records) == 1
|
|
assert report.perf_records[0].client == ""
|
|
|
|
|
|
def test_throughput_parsing_and_calculations(monkeypatch, tmp_path):
|
|
logs_dir = tmp_path / "logs"
|
|
logs_dir.mkdir()
|
|
monkeypatch.setattr(analyzer, "LOG_DIR", logs_dir)
|
|
|
|
log_content = (
|
|
'2026-06-10 10:00:00,000 - headroom.proxy - INFO - [req1] STAGE_TIMINGS {"event": "stage_timings", "stages": {"compression_first_stage": 100.0, "upstream_connect": 50.0}}\n'
|
|
"2026-06-10 10:00:01,000 - headroom.proxy - INFO - [req1] PERF model=gpt-5 msgs=1 tok_before=1000 tok_after=400 tok_saved=600 opt_ms=10 total_ms=500 tok_out=500 ttfb_ms=100 transforms=test client=codex\n"
|
|
'2026-06-10 10:00:02,000 - headroom.proxy - INFO - [req2] STAGE_TIMINGS {"event": "stage_timings", "stages": {"compression": 200.0, "upstream_connect": 50.0}}\n'
|
|
"2026-06-10 10:00:03,000 - headroom.proxy - INFO - [req2] PERF model=gpt-5 msgs=1 tok_before=2000 tok_after=1000 tok_saved=1000 opt_ms=20 total_ms=1000 tok_out=1000 ttfb_ms=200 transforms=test client=codex\n"
|
|
"2026-06-10 10:00:05,000 - headroom.proxy - INFO - [req3] PERF model=gpt-5 msgs=1 tok_before=1500 tok_after=500 tok_saved=1000 opt_ms=15 total_ms=600 tok_out=600 ttfb_ms=150 transforms=test client=codex\n"
|
|
'2026-06-10 10:00:06,000 - headroom.proxy - INFO - [req4] STAGE_TIMINGS {"event": "stage_timings", "stages": {"compression_first_stage": 150.0, "upstream_connect": 50.0}}\n'
|
|
"2026-06-10 10:00:07,000 - headroom.proxy - INFO - [req4] PERF model=gpt-5 msgs=1 tok_before=1200 tok_after=300 tok_saved=900 opt_ms=12 total_ms=400 tok_out=400 ttfb_ms=80 transforms=test client=codex\n"
|
|
'2026-06-10 10:00:08,000 - headroom.proxy - INFO - [req5] STAGE_TIMINGS {"event": "stage_timings", "stages": {"compression_first_stage": 50.0, "upstream_connect": 50.0}}\n'
|
|
"2026-06-10 10:00:09,000 - headroom.proxy - INFO - [req5] PERF model=gpt-5 msgs=1 tok_before=800 tok_after=200 tok_saved=600 opt_ms=5 total_ms=300 tok_out=300 ttfb_ms=50 transforms=test client=codex\n"
|
|
)
|
|
(logs_dir / "proxy.log").write_text(log_content, encoding="utf-8")
|
|
|
|
report = analyzer.parse_log_files(last_n_hours=0)
|
|
|
|
assert len(report.perf_records) == 5
|
|
|
|
assert report.perf_records[0].request_id == "req1"
|
|
assert report.perf_records[0].total_ms == 500.0
|
|
assert report.perf_records[0].tokens_out == 500
|
|
assert report.perf_records[0].ttfb_ms == 100.0
|
|
assert report.perf_records[0].stages == {
|
|
"compression_first_stage": 100.0,
|
|
"upstream_connect": 50.0,
|
|
}
|
|
|
|
assert report.perf_records[2].request_id == "req3"
|
|
assert report.perf_records[2].stages == {}
|
|
|
|
summary = build_perf_summary(report)
|
|
assert "throughput" in summary
|
|
tp = summary["throughput"]
|
|
|
|
rolling = tp["rolling"]
|
|
assert rolling["input_wall_clock"] > 0
|
|
assert rolling["input_active_p50"] == 2500.0
|
|
assert rolling["compression_p50"] == 10000.0
|
|
|
|
|
|
def test_throughput_empty_and_percentiles():
|
|
from headroom.perf.analyzer import (
|
|
PerfReport,
|
|
_calculate_throughput_stats,
|
|
_percentile,
|
|
calculate_throughput,
|
|
)
|
|
|
|
# Empty percentiles
|
|
assert _percentile([], 0.5) == 0.0
|
|
|
|
# Percentiles boundary checks
|
|
assert _percentile([10.0], 0.5) == 10.0
|
|
assert _percentile([10.0, 20.0], 0.5) == 15.0
|
|
assert _percentile([10.0, 20.0], 0.0) == 10.0
|
|
assert _percentile([10.0, 20.0], 1.0) == 20.0
|
|
assert _percentile([10.0, 20.0], 1.5) == 20.0
|
|
|
|
# Empty calculate_throughput
|
|
empty_report = PerfReport()
|
|
tp = calculate_throughput(empty_report)
|
|
assert tp["rolling"]["input_wall_clock"] == 0.0
|
|
assert tp["current"]["input_wall_clock"] == 0.0
|
|
|
|
# _calculate_throughput_stats with empty records
|
|
stats = _calculate_throughput_stats([], 10.0)
|
|
assert stats["input_wall_clock"] == 0.0
|