diff --git a/.claude/skills/debug-evals/SKILL.md b/.claude/skills/debug-evals/SKILL.md index 4a279e75..5fc6ebc7 100644 --- a/.claude/skills/debug-evals/SKILL.md +++ b/.claude/skills/debug-evals/SKILL.md @@ -1,6 +1,6 @@ --- name: debug-evals -description: Debug haiku.rag evaluation runs in Logfire. Use when asked to look at Logfire for an eval run, find failing or low-scoring eval cases, compare runs, check citation quality (cited_map) or judge pass rate (answer_equivalent), or explain why an eval case failed. Drives the Logfire MCP against the `evals` service. +description: Debug haiku.rag evaluation runs in Logfire. Use when asked to look at Logfire for an eval run, find failing or low-scoring eval cases, compare runs, check citation quality (cited_map) or judge pass rate (answer_equivalent), or explain why an eval case failed. Drives the Logfire MCP against the `evals` service, or the Logfire HTTP query API when the MCP is not loaded. Also covers monitoring a run that is still in flight. --- # Debug eval runs in Logfire @@ -22,6 +22,72 @@ single case. Read-only. 4. Hand back a clickable trace with `mcp__logfire__project_logfire_link(trace_id, project="haiku")`. +## When the Logfire MCP is not available + +The `mcp__logfire__*` tools are not loaded in every session. The HTTP query API is +the fallback and needs no MCP: + +``` +POST https://logfire-eu.pydantic.dev/v2/query # EU projects +POST https://logfire-us.pydantic.dev/v2/query # US projects +Authorization: Bearer +Content-Type: application/json +{"sql": "...", "min_timestamp": "2026-08-23T00:00:00Z"} +``` + +- **`min_timestamp` is mandatory** and silently bounds every result. Too recent a + value is indistinguishable from "no data". +- Read tokens are being replaced by **API keys** (`pylf_v2__...`). Same + `Authorization: Bearer` header; the region is in the prefix. +- Keep the key in `~/.logfire-read-key` (mode 600) and read it from there so it never + lands in a transcript. Helper next to this skill: `.claude/skills/debug-evals/lf-query.sh "" [min_ts]`. +- The API is **project-scoped**. A key for the wrong project authenticates fine and + returns zero rows — it does not error. Diagnose in this order: + 1. wrong region → `HTTP 401 Invalid read token` on the other host; + 2. wrong project → auth succeeds, `count(*)` over months is 0; + 3. right project → `SELECT service_name, count(*) ... GROUP BY service_name` shows + `evals`, `haiku-rag`, `haiku-ingester`. + Eval runs live in project **`haiku`**. There is an empty project named `evals`, + which is the natural wrong guess. +- **The API caps returned rows and does not say so.** Aggregate server-side + (`count(*)`, `avg(...)`, `sum(CASE WHEN ...)`) rather than pulling rows and counting + them locally. A pass rate computed from a clipped page is wrong and looks fine. + +### JSON access via the HTTP API + +`assertions`, `scores`, `metrics` and `case_name` are **keys inside the `attributes` +column, not columns** — `SELECT assertions` fails with `column not found`. Both of +these work: + +```sql +attributes->'assertions'->'answer_equivalent' -- returns JSON +json_get_bool(attributes,'assertions','answer_equivalent','value') +json_get_float(attributes,'scores','cited_map','value') +json_get_int(attributes,'attributes','n_searches') +json_get_str(attributes,'attributes','citation_status') +``` + +Prefer the `json_get_*` form inside aggregates — it yields a typed value, so no cast +is needed and `sum(CASE WHEN ...)` behaves. + +## Counting cases, not spans + +**One exception appears once per span level.** A single failing case emits the same +`exception_type` on `case: {case_name}`, `execute {task}` and `invoke_agent agent` +(and often `chat {model}`), so a raw count over-reports by 3-4x. Always add +`AND span_name='case: {case_name}'` when counting failures. Cross-check that the +number equals the count of unjudged cases. + +## Always report floor as well as judged + +`assertion_pass_rate` **excludes unjudged cases from the denominator**, so cases that +died produce no verdict and silently inflate the headline. Report both: + +- judged rate = passed / (cases - unjudged) +- floor = passed / cases + +A run with 4.5% deaths reads ~3pp better than it is. Quote them together, always. + ## Vocabulary A run is one experiment span; its cases are direct children sharing its @@ -152,3 +218,78 @@ SELECT DISTINCT otel_scope_name, span_name FROM records WHERE service_name='evals' ORDER BY 1,2; ``` + +## Monitoring a run that is still in flight + +An eval prints nothing until it finishes, so a live run's only progress signal is its +case spans. Everything below works mid-run. + +Progress and ETA: + +```sql +SELECT count(*) AS cases_done, + min(start_timestamp) AS first_case, + max(start_timestamp) AS latest_case, + avg(duration) AS avg_case_s +FROM records +WHERE service_name='evals' AND span_name='case: {case_name}' + AND start_timestamp > ''; +``` + +**Cases run serially**, so `ETA_total = total_cases * avg_case_s`. Verify rather than +assume: wall-clock per case (`latest_case - first_case` over `cases_done`) should equal +`avg_case_s`. If it does, concurrency is 1 and the multiplication is valid. Concurrent +requests seen on the model endpoint (`vllm:num_requests_running` > 1) are parallel +searches *within* one case, not parallel cases. + +**Never estimate a run's length from a `--limit N` smoke.** Its "avg task time per +case" is a per-case duration on the easiest N cases of a deterministic prefix; the full +set ran 32% slower (72.7s vs 55.2s) on FRAMES. Smokes validate wiring, not wall-clock. + +Live headline, behaviour and failure composition in one pass: + +```sql +SELECT count(*) AS cases, + sum(CASE WHEN json_get_bool(attributes,'assertions','answer_equivalent','value') + THEN 1 ELSE 0 END) AS passed, + sum(CASE WHEN json_get(attributes,'assertions','answer_equivalent') IS NULL + THEN 1 ELSE 0 END) AS unjudged, + avg(json_get_float(attributes,'scores','cited_map','value')) AS cited_map, + avg(json_get_int(attributes,'attributes','n_requests')) AS req_per_case, + avg(json_get_int(attributes,'attributes','n_searches')) AS searches, + avg(json_get_int(attributes,'attributes','n_executions')) AS execs, + sum(json_get_int(attributes,'attributes','n_rejected_searches')) AS rejected, + sum(CASE WHEN json_get_str(attributes,'attributes','citation_status')='grounded' + THEN 1 ELSE 0 END) AS grounded +FROM records +WHERE service_name='evals' AND span_name='case: {case_name}' + AND start_timestamp > ''; +``` + +Why a case died, counted correctly: + +```sql +SELECT sum(CASE WHEN exception_message LIKE '%token limit%' THEN 1 ELSE 0 END) AS token_limit, + sum(CASE WHEN exception_message NOT LIKE '%token limit%' THEN 1 ELSE 0 END) AS other, + count(*) AS dead_cases +FROM records +WHERE service_name='evals' AND is_exception + AND span_name='case: {case_name}' + AND start_timestamp > ''; +``` + +`ToolFailedError` is mostly **not** a defect — an exhausted search or code budget +reports failure to the model on purpose. `UnexpectedModelBehavior` is the one that +kills a case. + +### The per-case diagnostic attributes + +`attributes->'attributes'` on a case span carries what the capability actually did: +`n_requests`, `n_searches`, `n_search_calls`, `n_rejected_searches`, `n_failed_tools`, +`n_executions`, `cited_uris`, `cited_chunk_ids`, `searched_uris`, `citation_status` +(`grounded` | `missing` | `ungrounded`). `attributes->'metrics'` carries `requests`, +`input_tokens`, `output_tokens` for the case. + +Cite rate comes from `citation_status`, not from `cited_map` — they answer different +questions, and conflating them has produced wrong claims before. And never steer on +raw cite rate: it is confounded by task success, so measure it among *correct* answers. diff --git a/.claude/skills/debug-evals/lf-query.sh b/.claude/skills/debug-evals/lf-query.sh new file mode 100755 index 00000000..416a69ab --- /dev/null +++ b/.claude/skills/debug-evals/lf-query.sh @@ -0,0 +1,25 @@ +#!/usr/bin/env bash +# Query the Logfire API. Key is read from ~/.logfire-read-key and never echoed. +# usage: lf-query.sh "" [min_timestamp] +set -uo pipefail +KEY_FILE="$HOME/.logfire-read-key" +[ -r "$KEY_FILE" ] || { echo "missing $KEY_FILE"; exit 2; } +SQL="${1:?need SQL}" +MIN="${2:-$(date -u -v-2d +%Y-%m-%dT%H:%M:%SZ 2>/dev/null || date -u -d '2 days ago' +%Y-%m-%dT%H:%M:%SZ)}" +python3 - "$SQL" "$MIN" <<'PY' +import json, os, sys, urllib.request, urllib.error +sql, min_ts = sys.argv[1], sys.argv[2] +key = open(os.path.expanduser("~/.logfire-read-key")).read().strip() +# region comes from the key prefix: pylf_v2__... +parts = key.split("_") +region = parts[2] if len(parts) > 3 and parts[0] == "pylf" else "eu" +req = urllib.request.Request( + f"https://logfire-{region}.pydantic.dev/v2/query", + data=json.dumps({"sql": sql, "min_timestamp": min_ts}).encode(), + headers={"Authorization": f"Bearer {key}", "Content-Type": "application/json"}, +) +try: + print(json.dumps(json.load(urllib.request.urlopen(req, timeout=120)), indent=2)[:6000]) +except urllib.error.HTTPError as e: + print(f"HTTP {e.code}: {e.read().decode()[:600]}") +PY