From 2dc3f80457fe4f714564127d8b5d9f65e025474d Mon Sep 17 00:00:00 2001 From: DavidKoleczek <45405824+DavidKoleczek@users.noreply.github.com> Date: Wed, 5 Aug 2026 14:08:20 -0400 Subject: [PATCH] chore(eval): pin all agents to Sonnet 5 and de-duplicate LLM response metrics MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Pin every agent-under-test to claude-sonnet-5 so cross-agent comparisons differ only by agent stack, not by model. Drop the `routing.matrix: opus48` reference from the amplifier-foundation settings: no such matrix exists in the routing-matrix bundle, so the model was already coming from `default_model` alone. Enable `debug.rawLlmPayloads` for amplifier-agent-local. The full request and response payloads ride on the `llm:request` / `llm:response` events that extraction already pulls, so no extraction change is needed. Fix double-counted metrics. A session that composes more than one logging hook writes each LLM call to disk once per hook, and the metrics pass summed across every extracted events.jsonl. The anchors bundle composes two such hooks, so the amplifier-foundation agent reported exactly double its real calls, tokens and cost. The two copies use different envelope shapes and share no identical lines, so they are de-duplicated by response identity: the provider response id when raw capture is on, otherwise a session/timestamp/usage fingerprint. Events carrying neither are counted rather than dropped, since understating cost is the worse failure. The correction is reported in the metrics notes. Add regression tests for the de-duplication, and a dev dependency group so they run with `uv run python -m pytest tests/`. pytest-asyncio is required by amplifier-core's pytest plugin, which loads via entry point at startup. 🤖 Generated with [Amplifier](https://github.com/microsoft/amplifier) Co-Authored-By: Amplifier <240397093+microsoft-amplifier@users.noreply.github.com> --- .amplifier/evaluation/.gitignore | 14 ++ .../agents/amplifier-agent-local/install.yaml | 10 +- .../agents/amplifier-foundation/install.yaml | 36 ++- .../agents/amplifier-foundation/invocation.md | 8 +- .../agents/amplifier-foundation/meta.yaml | 8 +- .../opencode-amplifier-agent/invocation.md | 4 +- .../agents/opencode-amplifier-agent/meta.yaml | 2 +- .../agents/opencode-vanilla/install.yaml | 12 +- .../agents/opencode-vanilla/invocation.md | 4 +- .../agents/opencode-vanilla/meta.yaml | 4 +- .amplifier/evaluation/pyproject.toml | 10 + .amplifier/evaluation/src/eval/metrics.py | 106 ++++++++- .../evaluation/tests/test_metrics_dedup.py | 214 ++++++++++++++++++ .amplifier/evaluation/uv.lock | 77 +++++++ 14 files changed, 478 insertions(+), 31 deletions(-) create mode 100644 .amplifier/evaluation/tests/test_metrics_dedup.py diff --git a/.amplifier/evaluation/.gitignore b/.amplifier/evaluation/.gitignore index a4c12a55..d11aabeb 100644 --- a/.amplifier/evaluation/.gitignore +++ b/.amplifier/evaluation/.gitignore @@ -2,6 +2,20 @@ # Never source controlled (matches the existing per-harness runs/ convention). runs/ +# Personal analysis tooling and scratch. Useful locally, not part of the +# harness contract, so it stays out of the tracked tree. +local/ + +# Scratch the AI User is instructed to write when a prompt contains a double +# quote (see agents/*/invocation.md). It belongs at /workspace/eval-prompt.txt +# INSIDE the DTU, but the AI User drives from this directory on the host, so a +# missing path prefix drops it here instead. swe_bench_lifecycle.DRIVER_SCRATCH +# already cleans these in-DTU; this keeps a host-side leak out of the repo. +eval-prompt.txt +eval-run.out +eval-run.done +answer.txt + # Python / uv .venv/ __pycache__/ diff --git a/.amplifier/evaluation/agents/amplifier-agent-local/install.yaml b/.amplifier/evaluation/agents/amplifier-agent-local/install.yaml index 26fdabb6..90227d22 100644 --- a/.amplifier/evaluation/agents/amplifier-agent-local/install.yaml +++ b/.amplifier/evaluation/agents/amplifier-agent-local/install.yaml @@ -23,9 +23,17 @@ setup_cmds: # Write the host-config JSON that every task invocation passes via --config. # It sets headless approval, pins the provider/model, and adds an extra skills # source location (/root/extra-skills) used by the skill-config-location task. + # + # `debug.rawLlmPayloads: true` folds into the provider config as `raw: true`, + # which makes the provider attach the FULL outbound request kwargs to + # `llm:request` and the accumulated final response to `llm:response`. Those + # events are written to the session events.jsonl that extract.yaml already + # pulls (glob **/events.jsonl), so no extraction change is needed. This is the + # analysis surface for the eval: the actual prompts and responses, not just + # token counts. Contract covered by tests/e2e/suites/raw_capture. - | cat > /root/host-config.json <<'JSON' - {"approval":{"mode":"yes"},"provider":{"module":"anthropic","config":{"default_model":"claude-sonnet-5"}},"skills":{"skills":["/root/extra-skills"]}} + {"approval":{"mode":"yes"},"provider":{"module":"anthropic","config":{"default_model":"claude-sonnet-5"}},"skills":{"skills":["/root/extra-skills"]},"debug":{"rawLlmPayloads":true}} JSON - mkdir -p /root/extra-skills # install setup_cmds run under a login shell. Writing this profile.d file diff --git a/.amplifier/evaluation/agents/amplifier-foundation/install.yaml b/.amplifier/evaluation/agents/amplifier-foundation/install.yaml index 4b052484..d352f41c 100644 --- a/.amplifier/evaluation/agents/amplifier-foundation/install.yaml +++ b/.amplifier/evaluation/agents/amplifier-foundation/install.yaml @@ -13,9 +13,19 @@ # `requires.env` is verified on the host before launch and merged into the task # profile's passthrough services, so ANTHROPIC_API_KEY reaches the agent. # -# Opus 4.8 is pinned via the opus48 routing matrix (routes all model_role -# mappings to claude-opus-4-8) so this variant runs the SAME model as the -# opencode + amplifier-agent stack; the only difference is the agent stack. +# Sonnet 5 is pinned via the provider's `default_model` so this variant runs the +# SAME model as the opencode + amplifier-agent stack; the only difference is the +# agent stack. +# +# NO `routing.matrix` is set, deliberately. A previous revision named a matrix +# (`opus48`) that does not exist in the routing-matrix bundle; the reference +# resolved to nothing and the pin silently came from `default_model` alone. That +# was verified against a real run: every one of the 84 LLM requests across three +# tasks -- including the delegated sub-agent sessions -- carried the +# `default_model` value. Naming a matrix here would only re-introduce a +# role-based fan-out (`reasoning`/`creative`/`writing` -> opus under the stock +# `anthropic` matrix), which is precisely what a single-model pin must avoid. +# `default_model` is the whole mechanism; keep it that way. requires: env: - ANTHROPIC_API_KEY @@ -37,12 +47,10 @@ setup_cmds: source: git+https://github.com/microsoft/amplifier-module-provider-anthropic@main config: api_key: $ANTHROPIC_API_KEY - default_model: claude-opus-4-8 + default_model: claude-sonnet-5 enable_1m_context: 'true' enable_prompt_caching: 'true' priority: 1 - routing: - matrix: opus48 EOF # Compose the anchors bundle as an app bundle (same mechanism the foundation @@ -56,8 +64,20 @@ setup_cmds: # `includes:` the FULL amplifier-foundation bundle, which would drag all of # foundation on top of the lean anchors variant and defeat its purpose. The # behaviors keep the composition lean: anchors stays the active bundle and only - # the two CI agents are added -- no full foundation, no design mode, no logging - # hook (that lives only in the separate -logging behavior). + # the two CI agents are added -- no full foundation, no design mode, and no + # ADDITIONAL logging hook (that lives in the separate -logging behavior, which + # we do not add here). + # + # To be precise about what IS logging, because it caught us out once: anchors + # itself already composes TWO loggers upstream -- + # `foundation:behaviors/logging` (hooks-logging -> /events.jsonl) and + # `context-intelligence:behaviors/context-intelligence-logging` + # (hook-context-intelligence -> /context-intelligence/events.jsonl). + # So every LLM call in this variant is written to disk TWICE, in two different + # envelope shapes. That is anchors' own design and is deliberately NOT patched + # here -- this agent evaluates anchors as published. The harness is what has to + # cope: `metrics.parse_events` de-duplicates by response identity. Before that + # fix this variant reported exactly double its real calls, tokens and cost. # # We add BOTH behavior files explicitly and on purpose: # - navigation (LAYER 1) registers session-navigator (reads local session diff --git a/.amplifier/evaluation/agents/amplifier-foundation/invocation.md b/.amplifier/evaluation/agents/amplifier-foundation/invocation.md index 66491b6c..3dd3a2e9 100644 --- a/.amplifier/evaluation/agents/amplifier-foundation/invocation.md +++ b/.amplifier/evaluation/agents/amplifier-foundation/invocation.md @@ -98,10 +98,10 @@ took. Do NOT judge correctness yourself -- the grader does that. ## Model pinning -Opus 4.8 is pinned at install time via the provider's `default_model: -claude-opus-4-8` plus the `opus48` routing matrix in -`/root/.amplifier/settings.yaml`. That is the single source of truth for which -model runs, so `amplifier run` needs no model flag -- just invoke it as shown. +Sonnet 5 is pinned at install time via the provider's `default_model: +claude-sonnet-5` in `/root/.amplifier/settings.yaml`, with no routing matrix +set. That is the single source of truth for which model runs, so `amplifier run` +needs no model flag -- just invoke it as shown. ## Notes diff --git a/.amplifier/evaluation/agents/amplifier-foundation/meta.yaml b/.amplifier/evaluation/agents/amplifier-foundation/meta.yaml index 607ebf9e..8366716f 100644 --- a/.amplifier/evaluation/agents/amplifier-foundation/meta.yaml +++ b/.amplifier/evaluation/agents/amplifier-foundation/meta.yaml @@ -12,8 +12,8 @@ id: amplifier-foundation description: > The Amplifier CLI with the anchors bundle (amplifier-foundation@main, bundles/anchors) plus the context-intelligence bundle (agents only, no server) - composed, driven via `amplifier run` on Claude Opus 4.8. A general-agent variant + composed, driven via `amplifier run` on Claude Sonnet 5. A general-agent variant under test, run on the same tasks as the opencode + amplifier-agent stack for - head-to-head comparison. Opus is pinned via the opus48 routing matrix so the - model matches the opencode agent. -model: claude-opus-4-8 + head-to-head comparison. Sonnet 5 is pinned via the provider's default_model + so the model matches every other agent-under-test. +model: claude-sonnet-5 diff --git a/.amplifier/evaluation/agents/opencode-amplifier-agent/invocation.md b/.amplifier/evaluation/agents/opencode-amplifier-agent/invocation.md index 6d054e61..2e87d187 100644 --- a/.amplifier/evaluation/agents/opencode-amplifier-agent/invocation.md +++ b/.amplifier/evaluation/agents/opencode-amplifier-agent/invocation.md @@ -8,7 +8,7 @@ already on PATH once you export the two tool directories. Run each turn with a single command. Note the PATH export (opencode and uv tools live in `$HOME/.opencode/bin` and `$HOME/.local/bin`) and the model pin: - export PATH="$HOME/.opencode/bin:$HOME/.local/bin:$PATH"; cd /workspace && amplifier-opencode launch -- run --auto --model amplifier/claude-opus-4-8 "" + export PATH="$HOME/.opencode/bin:$HOME/.local/bin:$PATH"; cd /workspace && amplifier-opencode launch -- run --auto --model amplifier/claude-sonnet-5 "" The CLI prints the agent's final response to stdout and exits. Capture the response from stdout. @@ -25,7 +25,7 @@ on every invocation. ## Model pinning -opus-4-8 is pinned via opencode's `--model amplifier/claude-opus-4-8` flag. The +sonnet-5 is pinned via opencode's `--model amplifier/claude-sonnet-5` flag. The amplifier adapter writes no default model, so the flag is the single source of truth for which model runs. Keep it on every invocation. diff --git a/.amplifier/evaluation/agents/opencode-amplifier-agent/meta.yaml b/.amplifier/evaluation/agents/opencode-amplifier-agent/meta.yaml index 3c47ec18..23380787 100644 --- a/.amplifier/evaluation/agents/opencode-amplifier-agent/meta.yaml +++ b/.amplifier/evaluation/agents/opencode-amplifier-agent/meta.yaml @@ -5,7 +5,7 @@ id: opencode-amplifier-agent description: > opencode driven by amplifier-agent (OpenAI-compatible backend), running Anthropic models. The agent-under-test for evaluation runs. -model: claude-opus-4-8 +model: claude-sonnet-5 # Agent-owned timing hints for clean agent-only wall clock. The AI User drives # this agent by shelling `amplifier-digital-twin diff --git a/.amplifier/evaluation/agents/opencode-vanilla/install.yaml b/.amplifier/evaluation/agents/opencode-vanilla/install.yaml index ba3ef95e..71fd1371 100644 --- a/.amplifier/evaluation/agents/opencode-vanilla/install.yaml +++ b/.amplifier/evaluation/agents/opencode-vanilla/install.yaml @@ -8,7 +8,7 @@ # opencode's anthropic provider reads ANTHROPIC_API_KEY from the environment # automatically -- no `opencode auth login` is needed. # -# Opus 4.8 (`claude-opus-4-8`) is not in opencode's models.dev catalog, so we +# Sonnet 5 (`claude-sonnet-5`) is not in opencode's models.dev catalog, so we # register it explicitly under the built-in anthropic provider (@ai-sdk/anthropic) # in ~/.config/opencode/opencode.json. opencode sends the id to the Anthropic API # verbatim. @@ -30,19 +30,19 @@ setup_cmds: export PATH="$HOME/.opencode/bin:$PATH"; opencode --version - echo 'export PATH="$HOME/.opencode/bin:$PATH"' > /etc/profile.d/opencode.sh - export PATH="$HOME/.opencode/bin:$PATH"; opencode --version - # Register Opus 4.8 on the anthropic provider and make it the default model. + # Register Sonnet 5 on the anthropic provider and make it the default model. - mkdir -p "$HOME/.config/opencode" - | cat > "$HOME/.config/opencode/opencode.json" <<'JSON' { "$schema": "https://opencode.ai/config.json", - "model": "anthropic/claude-opus-4-8", + "model": "anthropic/claude-sonnet-5", "provider": { "anthropic": { "npm": "@ai-sdk/anthropic", "models": { - "claude-opus-4-8": { - "name": "Claude Opus 4.8" + "claude-sonnet-5": { + "name": "Claude Sonnet 5" } } } @@ -51,4 +51,4 @@ setup_cmds: JSON # Best-effort warm-up: exercises the full path once (auth + model resolution) # so the operator's first real run is fast. Bounded and non-fatal. - - 'export PATH="$HOME/.opencode/bin:$PATH"; timeout 240 opencode run --model anthropic/claude-opus-4-8 --auto "reply with exactly: ok" || true' + - 'export PATH="$HOME/.opencode/bin:$PATH"; timeout 240 opencode run --model anthropic/claude-sonnet-5 --auto "reply with exactly: ok" || true' diff --git a/.amplifier/evaluation/agents/opencode-vanilla/invocation.md b/.amplifier/evaluation/agents/opencode-vanilla/invocation.md index 0c736288..9cecfba5 100644 --- a/.amplifier/evaluation/agents/opencode-vanilla/invocation.md +++ b/.amplifier/evaluation/agents/opencode-vanilla/invocation.md @@ -8,7 +8,7 @@ a one-shot per turn. Run each turn with a single command. Note the PATH export (opencode lives in `$HOME/.opencode/bin`), the model pin, and `--auto`: - export PATH="$HOME/.opencode/bin:$PATH"; cd /workspace && opencode run --model anthropic/claude-opus-4-8 --auto "" + export PATH="$HOME/.opencode/bin:$PATH"; cd /workspace && opencode run --model anthropic/claude-sonnet-5 --auto "" The CLI prints the agent's final response to stdout and exits. Capture the response from stdout. @@ -21,7 +21,7 @@ agent cannot complete web or file tasks. Always pass `--auto`. ## Model pinning -opus-4-8 is pinned via `--model anthropic/claude-opus-4-8`. It is also the +sonnet-5 is pinned via `--model anthropic/claude-sonnet-5`. It is also the default model in opencode's config, but keep the flag on every invocation as the single source of truth for which model runs. diff --git a/.amplifier/evaluation/agents/opencode-vanilla/meta.yaml b/.amplifier/evaluation/agents/opencode-vanilla/meta.yaml index cb98c826..81a83ed9 100644 --- a/.amplifier/evaluation/agents/opencode-vanilla/meta.yaml +++ b/.amplifier/evaluation/agents/opencode-vanilla/meta.yaml @@ -4,9 +4,9 @@ id: opencode-vanilla description: > Vanilla opencode talking directly to the Anthropic API (no amplifier-agent / - amplifier-app-opencode bridge), pinned to Claude Opus 4.8. A baseline + amplifier-app-opencode bridge), pinned to Claude Sonnet 5. A baseline agent-under-test for comparison against opencode-amplifier-agent. -model: claude-opus-4-8 +model: claude-sonnet-5 # Agent-owned timing hints for clean agent-only wall clock. The AI User drives # this agent by shelling `amplifier-digital-twin exec -- bash -c '... diff --git a/.amplifier/evaluation/pyproject.toml b/.amplifier/evaluation/pyproject.toml index 58568540..9a9045af 100644 --- a/.amplifier/evaluation/pyproject.toml +++ b/.amplifier/evaluation/pyproject.toml @@ -40,6 +40,16 @@ amplifier-bundle-evaluation = { git = "https://github.com/microsoft/amplifier-bu amplifier-core = { git = "https://github.com/microsoft/amplifier-core", branch = "main" } amplifier-foundation = { git = "https://github.com/microsoft/amplifier-foundation", branch = "main" } +# Test-only dependencies. pytest-asyncio is required not by these tests but by +# amplifier-core's pytest plugin, which loads via a pytest11 entry point as soon +# as pytest starts in this venv; without it collection fails before any test +# runs. Install with `uv sync --group dev`. +[dependency-groups] +dev = [ + "pytest>=8.0", + "pytest-asyncio>=0.23", +] + [tool.pyright] include = ["src"] extraPaths = ["src"] diff --git a/.amplifier/evaluation/src/eval/metrics.py b/.amplifier/evaluation/src/eval/metrics.py index 2bb0d742..d597ba43 100644 --- a/.amplifier/evaluation/src/eval/metrics.py +++ b/.amplifier/evaluation/src/eval/metrics.py @@ -53,6 +53,7 @@ import datetime import glob +import hashlib import json import re import sqlite3 @@ -278,6 +279,61 @@ def parse_opencode_db(db_paths: list[str], workspace_dir: str = "/workspace") -> } +def _response_identity(obj: dict) -> str | None: + """Return a stable identity for an `llm:response` event, or None. + + WHY THIS EXISTS. A single logical LLM call is written to disk more than once + whenever a session composes more than one logging hook. The published + `anchors` bundle does exactly this: it includes BOTH + `foundation:behaviors/logging` (hooks-logging -> `/events.jsonl`) + and `context-intelligence:behaviors/context-intelligence-logging` + (hook-context-intelligence -> `/context-intelligence/events.jsonl`). + Both files are legitimate telemetry and both are pulled by extraction, so + summing across them counted every call, token and dollar TWICE. + + The two copies are not detectable by comparing bytes: the loggers use + different envelope shapes (`ts` vs `timestamp`, metadata at the top level vs + nested under `data`), so the files share zero identical lines. They are only + recognisable by what they DESCRIBE. Hence identity, not equality: + + strong the provider's own response id (`data.raw.id`). Globally unique + per call, present whenever raw payload capture is on. + fallback session id + event timestamp + usage, hashed. Used when raw + capture is off. The timestamp is sub-microsecond and is byte + identical across both loggers (verified on real run artifacts), + so it discriminates distinct calls reliably. + None neither is available -- see the caller. We do NOT guess. + + Returning None on a weak signal is deliberate. Over-de-duplicating would + silently UNDERSTATE cost, which is a worse failure than the overcount this + function exists to fix: an inflated number invites scrutiny, a deflated one + does not. + """ + # Bind before narrowing: `x.get(k) if isinstance(x.get(k), dict) else {}` + # calls get() twice, and the isinstance on the first call does not narrow + # the second, so the result stays `Any | None`. + raw_data = obj.get("data") + data: dict[str, Any] = raw_data if isinstance(raw_data, dict) else {} + + raw_payload = data.get("raw") + if isinstance(raw_payload, dict): + rid = raw_payload.get("id") + if isinstance(rid, str) and rid: + return f"id:{rid}" + + # Fallback fingerprint. Require a timestamp: without one, two genuinely + # distinct calls that happened to use the same token counts would collide. + ts = data.get("timestamp") or obj.get("ts") or obj.get("timestamp") + if not isinstance(ts, (str, int, float)) or isinstance(ts, bool): + return None + + session_id = data.get("session_id") or obj.get("session_id") + raw_usage = data.get("usage") + usage: dict[str, Any] = raw_usage if isinstance(raw_usage, dict) else {} + fingerprint = json.dumps([session_id, str(ts), usage], sort_keys=True, default=str) + return "fp:" + hashlib.sha1(fingerprint.encode()).hexdigest() + + def parse_events(events_paths: list[str]) -> dict[str, Any]: """Sum token/cost usage and compute wallclock from Amplifier events.jsonl. @@ -295,7 +351,9 @@ def parse_events(events_paths: list[str]) -> dict[str, Any]: (count of files that existed and were readable), had_timestamps (bool), agent_wallclock_s (float, 0.0 when no timestamps were found -- callers must consult had_timestamps to distinguish that from a genuine 0-length - span). + span), duplicate_responses (count of duplicate `llm:response` events + dropped), unidentified_responses (count that carried no usable identity + and were therefore counted without de-duplication). """ input_tokens = 0 output_tokens = 0 @@ -305,6 +363,9 @@ def parse_events(events_paths: list[str]) -> dict[str, Any]: saw_cost = False llm_responses = 0 files_read = 0 + duplicate_responses = 0 + unidentified_responses = 0 + seen_responses: set[str] = set() min_ts: float | None = None max_ts: float | None = None @@ -338,6 +399,20 @@ def parse_events(events_paths: list[str]) -> dict[str, Any]: if obj.get("event") != "llm:response": continue + # De-duplicate by identity. The same call reaches this loop once per + # logging hook the session composed (see _response_identity), and + # summing every copy is what inflated cost, tokens and call counts. + identity = _response_identity(obj) + if identity is None: + # No usable identity: count it rather than risk collapsing two + # genuinely distinct calls. Surfaced in the notes. + unidentified_responses += 1 + elif identity in seen_responses: + duplicate_responses += 1 + continue + else: + seen_responses.add(identity) + data = obj.get("data") usage = data.get("usage") if isinstance(data, dict) else None if not isinstance(usage, dict): @@ -375,6 +450,8 @@ def parse_events(events_paths: list[str]) -> dict[str, Any]: "files_read": files_read, "had_timestamps": had_timestamps, "agent_wallclock_s": agent_wallclock_s, + "duplicate_responses": duplicate_responses, + "unidentified_responses": unidentified_responses, } @@ -384,6 +461,13 @@ def find_events_files(output_dir: Path | str) -> list[str]: The extractor pulls session logs under `output_dir/sessions/`, preserving each session's `context-intelligence/events.jsonl`. We glob the whole tree so nested session directories are all found, sorted for determinism. + + This deliberately returns EVERY events.jsonl, including the several a single + session can produce when it composes more than one logging hook. Narrowing + the glob to pick a "primary" file would be fragile -- the layout differs per + agent and would silently yield zero on any change. Duplicates are handled + where they can be handled correctly: `parse_events` de-duplicates by + response identity. """ root = Path(output_dir).expanduser().resolve() return sorted(str(p) for p in root.rglob("events.jsonl")) @@ -508,6 +592,10 @@ def _finalize( Shared by both the events.jsonl and opencode.db branches: they produce the same `parsed` shape, so the `not_available` discipline, rounding, and note assembly live here once. Branch-specific wording is passed in. + + `duplicate_responses` / `unidentified_responses` are read with `.get()` + because they are meaningful only for the events.jsonl branch -- the opencode + branch reads one row per session from SQLite and cannot double-count. """ files_read = parsed["files_read"] notes_parts: list[str] = [] @@ -534,6 +622,22 @@ def _finalize( f"Parsed {parsed['llm_responses']} {response_label}(s) across " f"{files_read} {source_label}(s). {parse_note_suffix}" ) + # State the de-duplication explicitly. Without this the corrected figure + # is indistinguishable from a run that simply made fewer calls. + dupes = parsed.get("duplicate_responses") or 0 + if dupes: + notes_parts.append( + f"Dropped {dupes} duplicate {response_label}(s): this session composes more " + f"than one logging hook, so each call was written to disk more than once. " + f"Counted once each by response identity." + ) + unknown = parsed.get("unidentified_responses") or 0 + if unknown: + notes_parts.append( + f"{unknown} {response_label}(s) carried no response id and no timestamp, so " + f"they could not be de-duplicated and are counted as-is; if this session " + f"composes multiple logging hooks these may be overcounted." + ) notes_parts.append(cost_absent_note if cost_val == NOT_AVAILABLE else cost_present_note) if agent_wc == NOT_AVAILABLE: notes_parts.append("agent_wallclock_s is not_available: no timestamps found.") diff --git a/.amplifier/evaluation/tests/test_metrics_dedup.py b/.amplifier/evaluation/tests/test_metrics_dedup.py new file mode 100644 index 00000000..cc74da8d --- /dev/null +++ b/.amplifier/evaluation/tests/test_metrics_dedup.py @@ -0,0 +1,214 @@ +"""Regression tests for `llm:response` de-duplication in the metrics pass. + +WHY THIS FILE EXISTS. A session that composes more than one logging hook writes +every LLM call to disk more than once. The published `anchors` bundle does this: +it includes both `foundation:behaviors/logging` (-> `/events.jsonl`) +and `context-intelligence:behaviors/context-intelligence-logging` (-> +`/context-intelligence/events.jsonl`). Extraction pulls both files and +the metrics pass summed across them, so the amplifier-foundation agent reported +exactly DOUBLE its real calls, tokens and cost -- 20 calls at $2.98 for a trial +that actually made 10 calls at $1.49. + +The bug was invisible to every cheap check. The two files share zero identical +lines, because the loggers use different envelope shapes (`ts` vs `timestamp`, +metadata at the top level vs nested under `data`). Only the payload identity +gives it away. These tests pin that behaviour: + + - the two real envelope shapes, carrying one call, count as one + - distinct calls are still counted separately (the fix must not over-collapse) + - de-duplication works with raw capture OFF, via the timestamp fingerprint + - an event with no usable identity is counted rather than silently dropped + - the correction is stated in `notes`, not applied silently + +Run: uv run python -m pytest tests/ -q +""" + +from __future__ import annotations + +import json +import sys +from pathlib import Path + +import pytest + +sys.path.insert(0, str(Path(__file__).resolve().parent.parent / "src")) + +from eval.metrics import normalize_metrics, parse_events + +# One LLM call, as each of the two loggers actually writes it. Shapes copied +# from real run artifacts (runs/ab-3x3/.../amplifier-foundation__*). +RESPONSE_ID = "msg_011CdjqAotUMQC2DjuMppaYo" +TIMESTAMP = "2026-08-05T15:23:15.602291443+00:00" +SESSION = "fa3b1b70-e043-406a-8c8f-1fbc3edd24f0" +USAGE = { + "input_tokens": 2, + "output_tokens": 398, + "cache_write_tokens": 16534, + "cost_usd": "0.1132975", +} + + +def ci_shape( + response_id: str = RESPONSE_ID, ts: str = TIMESTAMP, usage: dict | None = None +) -> dict: + """hook-context-intelligence: `timestamp` inside `data`, `workspace` on top.""" + return { + "event": "llm:response", + "timestamp": ts, + "workspace": "-workspace", + "data": { + "session_id": SESSION, + "timestamp": ts, + "model": "claude-sonnet-5", + "provider": "anthropic", + "status": "ok", + "duration_ms": 8812, + "usage": dict(usage or USAGE), + "raw": {"id": response_id, "role": "assistant", "content": []}, + }, + } + + +def logging_shape( + response_id: str = RESPONSE_ID, ts: str = TIMESTAMP, usage: dict | None = None +) -> dict: + """foundation hooks-logging: `ts` on top, metadata hoisted out of `data`.""" + return { + "event": "llm:response", + "ts": ts, + "lvl": "INFO", + "status": "ok", + "duration_ms": 8812, + "session_id": SESSION, + "schema": {"name": "amplifier.log", "ver": "1.0.0"}, + "data": { + "model": "claude-sonnet-5", + "provider": "anthropic", + "usage": dict(usage or USAGE), + "raw": {"id": response_id, "role": "assistant", "content": []}, + }, + } + + +def write_events(path: Path, events: list[dict]) -> str: + path.parent.mkdir(parents=True, exist_ok=True) + path.write_text("".join(json.dumps(e) + "\n" for e in events)) + return str(path) + + +def test_two_loggers_one_call_counts_once(tmp_path): + """The exact production bug: same call, two files, two envelope shapes.""" + a = write_events(tmp_path / "s" / "context-intelligence" / "events.jsonl", [ci_shape()]) + b = write_events(tmp_path / "s" / "events.jsonl", [logging_shape()]) + + parsed = parse_events([a, b]) + + assert parsed["llm_responses"] == 1 + assert parsed["duplicate_responses"] == 1 + assert parsed["output_tokens"] == 398 + assert parsed["cost_usd"] == pytest.approx(0.1132975) + + +def test_the_two_shapes_share_no_bytes(tmp_path): + """Guards the reason identity is required: equality cannot find these. + + If this ever fails, the loggers have converged and a cheaper de-duplication + would work -- but until then, byte comparison provably cannot catch the + duplicate, which is why `_response_identity` exists. + """ + assert json.dumps(ci_shape()) != json.dumps(logging_shape()) + assert set(ci_shape()) != set(logging_shape()) + + +def test_distinct_calls_are_not_collapsed(tmp_path): + """The fix must not over-collapse: understating cost is the worse failure.""" + events = [ + ci_shape(response_id="msg_A", ts="2026-08-05T15:23:15.000000001+00:00"), + ci_shape(response_id="msg_B", ts="2026-08-05T15:23:16.000000002+00:00"), + ci_shape(response_id="msg_C", ts="2026-08-05T15:23:17.000000003+00:00"), + ] + path = write_events(tmp_path / "events.jsonl", events) + + parsed = parse_events([path]) + + assert parsed["llm_responses"] == 3 + assert parsed["duplicate_responses"] == 0 + assert parsed["output_tokens"] == 398 * 3 + + +def test_dedup_without_raw_capture_uses_timestamp_fingerprint(tmp_path): + """Raw capture is opt-in; de-duplication must still hold when it is off.""" + + def strip_raw(event: dict) -> dict: + event["data"].pop("raw", None) + return event + + a = write_events(tmp_path / "a" / "events.jsonl", [strip_raw(ci_shape())]) + b = write_events(tmp_path / "b" / "events.jsonl", [strip_raw(logging_shape())]) + + parsed = parse_events([a, b]) + + assert parsed["llm_responses"] == 1 + assert parsed["duplicate_responses"] == 1 + + +def test_distinct_calls_without_raw_still_distinct(tmp_path): + """Fingerprint must discriminate on timestamp, not collapse on equal usage.""" + first = ci_shape(ts="2026-08-05T15:23:15.000000001+00:00") + second = ci_shape(ts="2026-08-05T15:23:16.000000002+00:00") + for e in (first, second): + e["data"].pop("raw") + path = write_events(tmp_path / "events.jsonl", [first, second]) + + parsed = parse_events([path]) + + assert parsed["llm_responses"] == 2 + assert parsed["duplicate_responses"] == 0 + + +def test_unidentifiable_event_is_counted_not_dropped(tmp_path): + """No id and no timestamp: count it, flag it, never silently discard it. + + Dropping here would understate cost invisibly. Counting may overstate, which + is the failure mode that gets noticed and investigated. + """ + event = {"event": "llm:response", "data": {"usage": {"output_tokens": 10}}} + path = write_events(tmp_path / "events.jsonl", [event, dict(event)]) + + parsed = parse_events([path]) + + assert parsed["llm_responses"] == 2 + assert parsed["unidentified_responses"] == 2 + assert parsed["duplicate_responses"] == 0 + + +def test_notes_state_the_correction(tmp_path): + """A silent correction is one nobody can audit. It must appear in notes.""" + a = write_events(tmp_path / "a" / "events.jsonl", [ci_shape()]) + b = write_events(tmp_path / "b" / "events.jsonl", [logging_shape()]) + + record = normalize_metrics([a, b], total_wallclock_s=1.0, source="test") + + assert record["llm_responses"] == 1 + assert "Dropped 1 duplicate" in record["notes"] + assert "more than one logging hook" in record["notes"] + + +def test_wallclock_unaffected_by_duplicates(tmp_path): + """Duplicates share timestamps, so the span must not change.""" + early, late = "2026-08-05T15:23:15.000000+00:00", "2026-08-05T15:23:45.000000+00:00" + single = write_events( + tmp_path / "one" / "events.jsonl", + [ci_shape(response_id="a", ts=early), ci_shape(response_id="b", ts=late)], + ) + dupe = write_events( + tmp_path / "two" / "events.jsonl", + [logging_shape(response_id="a", ts=early), logging_shape(response_id="b", ts=late)], + ) + + one_logger = parse_events([single]) + two_loggers = parse_events([single, dupe]) + + assert two_loggers["llm_responses"] == one_logger["llm_responses"] == 2 + assert two_loggers["agent_wallclock_s"] == pytest.approx(one_logger["agent_wallclock_s"]) + assert two_loggers["agent_wallclock_s"] == pytest.approx(30.0) diff --git a/.amplifier/evaluation/uv.lock b/.amplifier/evaluation/uv.lock index 176a1e15..113a804e 100644 --- a/.amplifier/evaluation/uv.lock +++ b/.amplifier/evaluation/uv.lock @@ -76,6 +76,12 @@ dependencies = [ { name = "pyyaml" }, ] +[package.dev-dependencies] +dev = [ + { name = "pytest" }, + { name = "pytest-asyncio" }, +] + [package.metadata] requires-dist = [ { name = "amplifier-bundle-evaluation", git = "https://github.com/microsoft/amplifier-bundle-evaluation?rev=ec9f4ca3a23e74a519fced2fe0e2a9ec39e5764d" }, @@ -85,6 +91,12 @@ requires-dist = [ { name = "pyyaml", specifier = ">=6.0" }, ] +[package.metadata.requires-dev] +dev = [ + { name = "pytest", specifier = ">=8.0" }, + { name = "pytest-asyncio", specifier = ">=0.23" }, +] + [[package]] name = "duckdb" version = "1.5.4" @@ -121,6 +133,33 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/dc/82/4d52f3f9f9703a226b26b80bdae3f6905aeefe5221bf1815fc93ff02ca25/duckdb-1.5.4-cp314-cp314-win_arm64.whl", hash = "sha256:0f8722346024e5d9f02b58bf7b0491a629f97fdc8a04a10e432940f471ee387a", size = 14449863, upload-time = "2026-06-17T10:48:50.18Z" }, ] +[[package]] +name = "iniconfig" +version = "2.3.0" +source = { registry = "https://pypi.org/simple" } +sdist = { url = "https://files.pythonhosted.org/packages/72/34/14ca021ce8e5dfedc35312d08ba8bf51fdd999c576889fc2c24cb97f4f10/iniconfig-2.3.0.tar.gz", hash = "sha256:c76315c77db068650d49c5b56314774a7804df16fee4402c1f19d6d15d8c4730", size = 20503, upload-time = "2025-10-18T21:55:43.219Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/cb/b1/3846dd7f199d53cb17f49cba7e651e9ce294d8497c8c150530ed11865bb8/iniconfig-2.3.0-py3-none-any.whl", hash = "sha256:f631c04d2c48c52b84d0d0549c99ff3859c98df65b3101406327ecc7d53fbf12", size = 7484, upload-time = "2025-10-18T21:55:41.639Z" }, +] + +[[package]] +name = "packaging" +version = "26.3" +source = { registry = "https://pypi.org/simple" } +sdist = { url = "https://files.pythonhosted.org/packages/7d/fa/3944b40b07da9ce895c0e6303a5ab7d53da063554f534556b134a54d6093/packaging-26.3.tar.gz", hash = "sha256:94edc256424af38762eb31306eed28beb9f0efc50a8837492c9d6fd6004aed79", size = 313412, upload-time = "2026-08-04T18:15:28.737Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/63/34/ba1c580383c9eada3711951fef0795c80b829a078d72188184bcab9dd527/packaging-26.3-py3-none-any.whl", hash = "sha256:d7193f7c8e4e93f444fde0262bf90af30e16fa0ad0ad44cb553c87339b23cd1c", size = 129956, upload-time = "2026-08-04T18:15:27.159Z" }, +] + +[[package]] +name = "pluggy" +version = "1.6.0" +source = { registry = "https://pypi.org/simple" } +sdist = { url = "https://files.pythonhosted.org/packages/f9/e2/3e91f31a7d2b083fe6ef3fa267035b518369d9511ffab804f839851d2779/pluggy-1.6.0.tar.gz", hash = "sha256:7dcc130b76258d33b90f61b658791dede3486c3e6bfb003ee5c9bfb396dd22f3", size = 69412, upload-time = "2025-05-15T12:30:07.975Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/54/20/4d324d65cc6d9205fabedc306948156824eb9f0ee1633355a8f7ec5c66bf/pluggy-1.6.0-py3-none-any.whl", hash = "sha256:e920276dd6813095e9377c0bc5566d94c932c33b27a3e3945d8389c374dd4746", size = 20538, upload-time = "2025-05-15T12:30:06.134Z" }, +] + [[package]] name = "pydantic" version = "2.13.4" @@ -238,6 +277,44 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/4b/2d/69abac8f838090bbecd5df894befb2c2619e7996a98ddb949db9f3b93225/pydantic_core-2.46.4-pp311-pypy311_pp73-win_amd64.whl", hash = "sha256:d51026d73fcfd93610abc7b27789c26b313920fcfb20e27462d74a7f8b06e983", size = 2193071, upload-time = "2026-05-06T13:38:08.682Z" }, ] +[[package]] +name = "pygments" +version = "2.20.0" +source = { registry = "https://pypi.org/simple" } +sdist = { url = "https://files.pythonhosted.org/packages/c3/b2/bc9c9196916376152d655522fdcebac55e66de6603a76a02bca1b6414f6c/pygments-2.20.0.tar.gz", hash = "sha256:6757cd03768053ff99f3039c1a36d6c0aa0b263438fcab17520b30a303a82b5f", size = 4955991, upload-time = "2026-03-29T13:29:33.898Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/f4/7e/a72dd26f3b0f4f2bf1dd8923c85f7ceb43172af56d63c7383eb62b332364/pygments-2.20.0-py3-none-any.whl", hash = "sha256:81a9e26dd42fd28a23a2d169d86d7ac03b46e2f8b59ed4698fb4785f946d0176", size = 1231151, upload-time = "2026-03-29T13:29:30.038Z" }, +] + +[[package]] +name = "pytest" +version = "9.1.1" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "colorama", marker = "sys_platform == 'win32'" }, + { name = "iniconfig" }, + { name = "packaging" }, + { name = "pluggy" }, + { name = "pygments" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/e4/47/b9efed96c114afcfa3c9d3fe98a76a1d14c74a9e266d397cf6eb64be5e01/pytest-9.1.1.tar.gz", hash = "sha256:1088fbde8f2b49d95a549a195707afa7a76a3ce9bcadc26b6d71f0ffda5fe313", size = 1636369, upload-time = "2026-06-19T10:58:32.857Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/24/25/1de2678b631f5a49215c6c96fff41ba892b0a34df68d6d80292b1b48aa7f/pytest-9.1.1-py3-none-any.whl", hash = "sha256:37a86b45efb9a47a61a36449063e8e18d0cab3161329fc099eb21783169c4f0c", size = 386536, upload-time = "2026-06-19T10:58:31.347Z" }, +] + +[[package]] +name = "pytest-asyncio" +version = "1.4.0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "pytest" }, + { name = "typing-extensions", marker = "python_full_version < '3.13'" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/43/7c/d36d04db312ecf4298932ef77e6e4a9e8ad017906e24e34f0b0c361a2473/pytest_asyncio-1.4.0.tar.gz", hash = "sha256:c6c0d2259945122819f171a32ecea2c349ead889ee28176caaf492143424be42", size = 58514, upload-time = "2026-05-26T09:56:04.083Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/03/e2/08a497ef684b88559c9cc5f4ad53a37e7b99e727094a86d6ea32536d5d3c/pytest_asyncio-1.4.0-py3-none-any.whl", hash = "sha256:933ca923a23075a87fb7070c0ec272a6848489824d887c85c812670932835aa1", size = 16930, upload-time = "2026-05-26T09:56:02.576Z" }, +] + [[package]] name = "pyyaml" version = "6.0.3"