|
| 1 | +#!/usr/bin/env python3 |
| 2 | +"""Aggregate compaction + reflection telemetry from a conversation.jsonl log. |
| 3 | +
|
| 4 | +Usage: |
| 5 | + python3 scripts/compaction_stats.py <path-to-conversation.jsonl> |
| 6 | +
|
| 7 | +Reads `BusMessage::Telemetry` entries written by `LoggingActor::write_conversation` |
| 8 | +(see src/logging.rs:192) and prints aggregate stats for the Phase 0 compaction + |
| 9 | +reflection variants: |
| 10 | +
|
| 11 | +- CompactionTriggered / CompactionCompleted / CompactionFailed |
| 12 | +- ReflectionStarted / ReflectionCompleted |
| 13 | +
|
| 14 | +Reports counts, failure rate, median + p99 wall_ms, median compression ratio. |
| 15 | +Skips other telemetry variants silently. Designed to run on any modern Python 3. |
| 16 | +""" |
| 17 | + |
| 18 | +from __future__ import annotations |
| 19 | + |
| 20 | +import json |
| 21 | +import statistics |
| 22 | +import sys |
| 23 | +from collections import Counter |
| 24 | +from pathlib import Path |
| 25 | + |
| 26 | + |
| 27 | +VARIANT_KEYS = { |
| 28 | + "CompactionTriggered", |
| 29 | + "CompactionCompleted", |
| 30 | + "CompactionFailed", |
| 31 | + "ReflectionStarted", |
| 32 | + "ReflectionCompleted", |
| 33 | + # PR-6.1: AgentUsage carries cache_read_tokens / cache_creation_tokens so we |
| 34 | + # can compute the cache-hit ratio that PR-6 enables. |
| 35 | + "AgentUsage", |
| 36 | +} |
| 37 | + |
| 38 | + |
| 39 | +def iter_events(path: Path): |
| 40 | + """Yield (variant_name, payload_dict) for each compaction/reflection event in the file.""" |
| 41 | + with path.open("r", encoding="utf-8") as fh: |
| 42 | + for lineno, raw in enumerate(fh, start=1): |
| 43 | + raw = raw.strip() |
| 44 | + if not raw: |
| 45 | + continue |
| 46 | + try: |
| 47 | + obj = json.loads(raw) |
| 48 | + except json.JSONDecodeError: |
| 49 | + # Conversation log mixes Inbound/Outbound/Telemetry; only Telemetry |
| 50 | + # variants emit as `{"VariantName": {...}}`. Other shapes are skipped. |
| 51 | + continue |
| 52 | + if not isinstance(obj, dict) or len(obj) != 1: |
| 53 | + continue |
| 54 | + variant, payload = next(iter(obj.items())) |
| 55 | + if variant in VARIANT_KEYS and isinstance(payload, dict): |
| 56 | + yield variant, payload |
| 57 | + |
| 58 | + |
| 59 | +def percentile(values: list[float], q: float) -> float: |
| 60 | + """Plain percentile (linear interp) without numpy. `q` in [0, 100].""" |
| 61 | + if not values: |
| 62 | + return float("nan") |
| 63 | + s = sorted(values) |
| 64 | + if len(s) == 1: |
| 65 | + return s[0] |
| 66 | + k = (len(s) - 1) * (q / 100.0) |
| 67 | + lo, hi = int(k), min(int(k) + 1, len(s) - 1) |
| 68 | + if lo == hi: |
| 69 | + return s[lo] |
| 70 | + return s[lo] + (s[hi] - s[lo]) * (k - lo) |
| 71 | + |
| 72 | + |
| 73 | +def main(argv: list[str]) -> int: |
| 74 | + if len(argv) != 2: |
| 75 | + sys.stderr.write(__doc__ or "") |
| 76 | + return 2 |
| 77 | + path = Path(argv[1]) |
| 78 | + if not path.is_file(): |
| 79 | + sys.stderr.write(f"error: {path} is not a file\n") |
| 80 | + return 1 |
| 81 | + |
| 82 | + counts: Counter[str] = Counter() |
| 83 | + compaction_wall_ms: list[int] = [] |
| 84 | + compaction_tokens_before: list[int] = [] |
| 85 | + compaction_tokens_after: list[int] = [] |
| 86 | + compaction_preprocess_ratios: list[float] = [] |
| 87 | + compaction_failure_reasons: Counter[str] = Counter() |
| 88 | + reflection_wall_ms_short: list[int] = [] |
| 89 | + reflection_wall_ms_long: list[int] = [] |
| 90 | + # PR-6.1 cache accounting (across all `AgentUsage` events) |
| 91 | + cache_total_prompt = 0 |
| 92 | + cache_total_read = 0 |
| 93 | + cache_total_creation = 0 |
| 94 | + |
| 95 | + for variant, payload in iter_events(path): |
| 96 | + counts[variant] += 1 |
| 97 | + if variant == "AgentUsage": |
| 98 | + cache_total_prompt += int(payload.get("prompt_tokens", 0)) |
| 99 | + cache_total_read += int(payload.get("cache_read_tokens", 0)) |
| 100 | + cache_total_creation += int(payload.get("cache_creation_tokens", 0)) |
| 101 | + if variant == "CompactionTriggered": |
| 102 | + # PR-1: track preprocess ratio (`tokens_after_preprocess / tokens_before`) |
| 103 | + # when present. Older logs predating PR-1 omit the field — `#[serde(default)]` |
| 104 | + # on the Rust side fills it as 0, so we skip the ratio computation in that case. |
| 105 | + tokens_before = int(payload.get("tokens_before", 0)) |
| 106 | + after = int(payload.get("tokens_after_preprocess", 0)) |
| 107 | + if tokens_before > 0 and after > 0: |
| 108 | + compaction_preprocess_ratios.append(after / tokens_before) |
| 109 | + elif variant == "CompactionCompleted": |
| 110 | + compaction_wall_ms.append(int(payload.get("wall_ms", 0))) |
| 111 | + compaction_tokens_before.append(int(payload.get("tokens_before", 0))) |
| 112 | + compaction_tokens_after.append(int(payload.get("tokens_after", 0))) |
| 113 | + elif variant == "CompactionFailed": |
| 114 | + compaction_failure_reasons[str(payload.get("reason", "unknown"))] += 1 |
| 115 | + elif variant == "ReflectionCompleted": |
| 116 | + kind = payload.get("kind", "") |
| 117 | + if kind == "ShortTerm": |
| 118 | + reflection_wall_ms_short.append(int(payload.get("wall_ms", 0))) |
| 119 | + elif kind == "LongTerm": |
| 120 | + reflection_wall_ms_long.append(int(payload.get("wall_ms", 0))) |
| 121 | + |
| 122 | + print(f"== Compaction telemetry — {path} ==") |
| 123 | + print() |
| 124 | + print("Event counts:") |
| 125 | + for variant in sorted(VARIANT_KEYS): |
| 126 | + print(f" {variant:<25} {counts[variant]}") |
| 127 | + print() |
| 128 | + |
| 129 | + triggered = counts["CompactionTriggered"] |
| 130 | + completed = counts["CompactionCompleted"] |
| 131 | + failed = counts["CompactionFailed"] |
| 132 | + accounted = completed + failed |
| 133 | + if triggered: |
| 134 | + failure_rate = failed / triggered if triggered else 0.0 |
| 135 | + print(f"Compaction failure rate: {failure_rate:.1%} ({failed}/{triggered})") |
| 136 | + orphan = triggered - accounted |
| 137 | + if orphan: |
| 138 | + print( |
| 139 | + f" WARN: {orphan} CompactionTriggered without matching Completed/Failed " |
| 140 | + "(see Phase 0 acceptance criteria)" |
| 141 | + ) |
| 142 | + |
| 143 | + if compaction_wall_ms: |
| 144 | + p50 = percentile([float(x) for x in compaction_wall_ms], 50) |
| 145 | + p99 = percentile([float(x) for x in compaction_wall_ms], 99) |
| 146 | + print(f"Compaction wall_ms: p50={p50:.0f}ms p99={p99:.0f}ms n={len(compaction_wall_ms)}") |
| 147 | + |
| 148 | + if compaction_tokens_before and compaction_tokens_after: |
| 149 | + ratios = [ |
| 150 | + (a / b) if b else 0.0 |
| 151 | + for a, b in zip(compaction_tokens_after, compaction_tokens_before) |
| 152 | + ] |
| 153 | + median_ratio = statistics.median(ratios) |
| 154 | + median_before = statistics.median(compaction_tokens_before) |
| 155 | + median_after = statistics.median(compaction_tokens_after) |
| 156 | + print( |
| 157 | + f"Compaction compression: median tokens {median_before:.0f} → {median_after:.0f} " |
| 158 | + f"(ratio {median_ratio:.3f})" |
| 159 | + ) |
| 160 | + |
| 161 | + if compaction_preprocess_ratios: |
| 162 | + # PR-1 acceptance criterion target: ≥30% reduction on image-/tool-heavy |
| 163 | + # workloads, i.e. preprocess_ratio ≤ 0.70. Lower is better. |
| 164 | + median_pp = statistics.median(compaction_preprocess_ratios) |
| 165 | + print( |
| 166 | + f"Compaction preprocess ratio (after/before): median={median_pp:.3f} " |
| 167 | + f"n={len(compaction_preprocess_ratios)}" |
| 168 | + ) |
| 169 | + |
| 170 | + if cache_total_prompt > 0: |
| 171 | + # PR-6.1 cache effectiveness across all AgentUsage events. A high cache_read |
| 172 | + # ratio means PR-6's system-prompt caching is hitting; cache_creation only |
| 173 | + # spikes on cold sessions. OpenAI providers leave cache_creation at 0 (no |
| 174 | + # separate billing), so the ratio is most meaningful for Anthropic traffic. |
| 175 | + read_ratio = cache_total_read / cache_total_prompt |
| 176 | + create_ratio = cache_total_creation / cache_total_prompt |
| 177 | + print( |
| 178 | + f"\nProvider prompt-cache (all AgentUsage events, n={counts['AgentUsage']}):" |
| 179 | + ) |
| 180 | + print( |
| 181 | + f" prompt_tokens={cache_total_prompt} " |
| 182 | + f"cache_read={cache_total_read} ({read_ratio:.1%}) " |
| 183 | + f"cache_create={cache_total_creation} ({create_ratio:.1%})" |
| 184 | + ) |
| 185 | + |
| 186 | + if compaction_failure_reasons: |
| 187 | + print() |
| 188 | + print("Failure reasons:") |
| 189 | + for reason, n in compaction_failure_reasons.most_common(): |
| 190 | + print(f" {n:>4} {reason}") |
| 191 | + |
| 192 | + if reflection_wall_ms_short: |
| 193 | + p50 = percentile([float(x) for x in reflection_wall_ms_short], 50) |
| 194 | + p99 = percentile([float(x) for x in reflection_wall_ms_short], 99) |
| 195 | + print( |
| 196 | + f"\nShort-term reflection wall_ms: p50={p50:.0f}ms p99={p99:.0f}ms " |
| 197 | + f"n={len(reflection_wall_ms_short)}" |
| 198 | + ) |
| 199 | + if reflection_wall_ms_long: |
| 200 | + p50 = percentile([float(x) for x in reflection_wall_ms_long], 50) |
| 201 | + p99 = percentile([float(x) for x in reflection_wall_ms_long], 99) |
| 202 | + print( |
| 203 | + f"Long-term reflection wall_ms: p50={p50:.0f}ms p99={p99:.0f}ms " |
| 204 | + f"n={len(reflection_wall_ms_long)}" |
| 205 | + ) |
| 206 | + |
| 207 | + return 0 |
| 208 | + |
| 209 | + |
| 210 | +if __name__ == "__main__": |
| 211 | + raise SystemExit(main(sys.argv)) |
0 commit comments