Repository navigation
feat: align agent traces with Braintrust's span spec - #351
mattrossman merged 24 commits into
Conversation
…lign-eval-trace-structure-with-braintrusts-eval-span-spec
|
The latest updates on your projects. Learn more about Vercel for GitHub. |
This reverts commit f20d5ce.
This reverts commit 5a45e2a.
Rodriguespn
left a comment
There was a problem hiding this comment.
Thanks Matt, the overall shape looks right. Requesting changes for Grok tool calls. They seem to be off by one request.
I'd also fix this in the PR, though it's not a blocker: if Codex compacts the conversationor an subagent item, the enrichment is dropped for every tool in the run. It didn't happen in CI, but it's one long session away.
The OpenCode notes are nice-to-haves.
|
Thanks @Rodriguespn, all threads are addressed. Grok tool calls now land on the right request, Codex enrichment survives compaction, and steps with no text or tools get their own span. Other stuff I've deferred as needed to follow-up issues. |
Rodriguespn
left a comment
There was a problem hiding this comment.
Thx for addressing my comments Matt. I've confirmed it locally that when the assistant-message counts differ between stdout and the rollout, this loop adds an empty LLM span for each text-only request, usually the final report. That span carries the request's usage, while the real message has no id or usage, so one model call shows up as two spans.
I had Claude reproduced it on all 4 Codex CI runs by dropping one stdout assistant message: 0 empty spans before this PR, 1 per run after. It also goes against the doc comment ("any count or content mismatch leaves that kind of event untouched"). Skipping the loop when messages didn't pair fixes it and keeps the compaction test passing:
const messagesPaired = assistant.length === messages.length;
if (messagesPaired) { … }
// …
if (!messagesPaired) return;
const tagged = new Set(events.map((e) => e.requestId));It doesn't happen in normal runs, so not blocking. Feel free to merge it if you'd like it
|
@Rodriguespn I've applied your fix in 541aed1a, with minor tweak so compaction spans still show up when pairing fails. Added tests for both the message and tool mismatch cases. |
Stacked on #351. Adds `setup`, `teardown`, and a timed score span around `task`, so the whole run shows up in each Braintrust trace. Before, the root span ended at the result file's mtime with ~50s unexplained after `task` ([Slack](https://supabase.slack.com/archives/C051L8U2EJF/p1790884064955869)), and the first LLM span shrank to ~0s. ``` eval run start → scoring end ├─ setup CLI boot until it records the prompt ├─ task prompt → last transcript event ├─ teardown CLI exit until agent.run() returns └─ passed workspace export + checks + judge calls ``` ## Summary - Results record host epoch ms `agentRunStartedAt`, `agentPromptAt`, `agentRunEndedAt`, `scoringEndedAt` (all optional; older results keep the mtime fallback). - `agentRunDurationMs` now measures only agent time, the `task` span (prompt → last transcript event), falling back to CLI process time without transcript timestamps. The new timing fields stay out of the exported web snapshot. - Each harness reads the prompt time from its session files: Codex rollout user message, Claude Code first `user` record, Grok first `user_message_chunk`, OpenCode `opencode.db` via `node:sqlite` (new `enrichEvents`). It's clamped between run start and the first transcript event, since it comes from the sandbox clock. ## Review guide - Start with `logTranscript` in `apps/framework/scripts/upload-braintrust.ts` and its test. - Then `run-eval.ts` (where the times are taken) and the four `enrichEvents`/parser changes. ## Verification - `upload-braintrust` + core tests (195), `pnpm typecheck`, biome on changed files. - [Eval refresh run](https://github.com/supabase/evals/actions/runs/36940516457): 8/8 passed (4 harnesses × 2 evals). Every trace has `setup → task → teardown → passed`: | Experiment | setup | teardown | passed | |---|---|---|---| | [codex-gpt-6-luna](https://www.braintrust.dev/app/supabase.io/p/Evals/experiments/codex-gpt-6-luna%40b32ad0b-20261001T2331Z) | 1.5–2.3s | 0.2–0.3s | 2.9–3.0s | | [claude-code-sonnet-5](https://www.braintrust.dev/app/supabase.io/p/Evals/experiments/claude-code-sonnet-5%40b32ad0b-20261001T2331Z) | 3.6–3.8s | 0.4s | 2.1–4.1s | | [grok-4.7](https://www.braintrust.dev/app/supabase.io/p/Evals/experiments/grok-4.7%40b32ad0b-20261001T2331Z) | 0.7–0.9s | 0.3s | 3.4–4.0s | | [opencode-kimi-k3](https://www.braintrust.dev/app/supabase.io/p/Evals/experiments/opencode-kimi-k3%40b32ad0b-20261001T2331Z) | 1.8–2.5s | 0.4s | 2.6–4.3s | Compare with #351's [codex "After" trace](https://www.braintrust.dev/app/supabase.io/p/Evals/experiments/codex-gpt-6-luna%406ae97d5-20261001T1745Z?r=b83a66ddaf7f23bc2ce58695c14e873a), or browse [all experiments in this run](https://www.braintrust.dev/app/supabase.io/p/Evals/experiments?search=%7B%22filter%22%3A%5B%7B%22text%22%3A%22metadata.run_id%2520%253D%2520%252288acdbad-c59a-4d97-ba2a-af6121f52de5%2522%22%7D%5D%7D). ## Risk Sandbox/stack boot before the agent and stack teardown after scoring are still outside the trace. Judge calls inside `passed` get their own spans in AI-1271. Linear: [AI-1279](https://linear.app/supabase/issue/AI-1279/show-agent-setup-and-scoring-time-as-their-own-spans-in-braintrust) --------- Co-authored-by: Claude <noreply@anthropic.com> Co-authored-by: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com>
Conflicts in the codex parser/runner, engine, and agent types are resolved by taking main's #351 rollout enrichment; this PR's sessionLog plumbing and rollout parsing are dropped in favour of it.
Set each Codex tool call's cwd from the rollout item #351 already pairs it with, copy it and the result time onto ToolCallRecord, and read both directly in the CLI detour helpers.
### Motivation We want to understand how our scorers are judging eval outputs. Today we capture the final output of our judge, but not the input / usage details. We don't know how much $ we spend on judge inference or where inefficiencies are in our judge context (e.g. #366) ### Changes Scorers now ask for verdicts through `ctx.judge()` instead of plain `judge()`, which records each judge call's model, full prompt, output, tokens and timing in `result.json`. The uploader logs each call as an LLM span under the score span: ``` passed (score, purpose: scorer) ├─ gpt-6-sol (llm, purpose: scorer) └─ gpt-6-sol (llm, purpose: scorer) ``` > [!NOTE] > 23 of the changed eval files are just swapping `judge()` for `ctx.judge()` `purpose: "scorer"` is how Braintrust [keeps judge cost out of preset cost charts](https://braintrust.dev/docs/kb/total-llm-cost-preset-requirements#what-is-happening). Core no longer exports `judge()` so folks are encouraged to use `ctx.judge` as the preferred way to access the judge in scorers similar to `ctx.query`. As an incidental fix, the root eval span no longer logs agent tokens, since its LLM spans carry them. Braintrust [sums metrics across every span in a trace](https://braintrust.dev/docs/reference/sql/query-structure#summary), so with the initial approach in #351 the experiment table double counts tokens ([example](https://www.braintrust.dev/app/supabase.io/p/Evals/experiments/claude-code-sonnet-5%400a50211-20261002T1454Z)). Note `aiSdkAgent` has no per-request usage so its rows now show no tokens, but it's unused and slated for removal anyway. ### Verification See Braintrust [experiment](https://www.braintrust.dev/app/supabase.io/p/Evals/experiments/codex-gpt-6-luna%408c23101-20261006T1429Z) of the regression suite and this specific sample [trace](https://www.braintrust.dev/app/supabase.io/p/Evals/experiments/codex-gpt-6-luna%408c23101-20261006T1429Z?r=6450ec155246034da058a5e621834383) with LLM judge calls now visible under the scorer span. | Timeline | Messages | Span | |--------|--------|-----| | <img width="2056" height="1704" alt="CleanShot 2026-10-06 at 10 33 09 AM@2x" src="https://github.com/user-attachments/assets/e1f7a100-45ca-4716-8427-3427a133af86" /> | <img width="1196" height="1668" alt="CleanShot 2026-10-06 at 10 33 33 AM@2x" src="https://github.com/user-attachments/assets/e5d711db-d7da-4132-bf51-b982ba160067" /> | <img width="874" height="320" alt="CleanShot 2026-10-06 at 10 33 46 AM@2x" src="https://github.com/user-attachments/assets/fbe862b2-186c-4ce5-b0f3-8f678750f6b4" /> > [!TIP] > Braintrust hides scorer spans by default in the Timeline view, to see them enable "Include score spans in timeline" from the overflow menu: > <img width="200" alt="CleanShot 2026-10-06 at 9 53 33 AM@2x" src="https://github.com/user-attachments/assets/c21fd180-8df1-4da8-ba99-b29e820efcfb" /> ### Future improvements I'd like to more formally pair checks with `ctx.judge()` calls so we can attach nice labels to these spans, e.g. `judge: wrote safe RLS policy`. Today, we don't have that structural pairing so I've left it out of this PR. Closes AI-1271 --------- Co-authored-by: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com>
#356) ## Current Behavior Scorers can't tell which directory an agent ran a tool call in, or when it finished. `ToolCallRecord` has no `cwd`, so a CLI eval that runs `supabase start` from `client-a` and `client-b` can't attribute each call to a project. `adaptTranscript` also drops the result time that #351 already stamps on each tool result, so `evals/cli/lib/detours.ts` reads both fields through defensive `unknown` casts. ## Expected Behavior A small change on top of the rollout enrichment #351 added (no new rollout parsing, no `sessionLog` plumbing): - Codex: `enrichFromRollout` now pairs tool calls with rollout items per call instead of all-or-nothing. Each call takes the next rollout item (in order) that matches its command or MCP tool and sets `event.tool.cwd` from the item's `cwd` (a `file://` URL is converted to a path). Extra rollout items the `--json` stream omits, like a killed long-running command, are skipped, and a call with no match stays unenriched without affecting the others. This also improves #351's timestamp enrichment, since the same pairing drives it. File-change and web-search items now only pair with calls of the same kind, so scanning past an extra item can't mispair them. - Codex: a command's completion time (`resultTs`) comes from its rollout `item_completed` event instead of the `function_call_output`, which for a yielded long-running command marks the yield rather than the exit (the output arrives early and `write_stdin` polls the rest). It falls back to the output time when `item_completed` has no timestamp. - OpenCode: `bash`'s `workdir` is normalized to `cwd` through the shared arg extractor. - `adaptTranscript` copies `cwd` onto `ToolCallRecord`, and also the result time as `ToolCallRecord.resultTs`. It is the same value and name as `TranscriptPart.resultTs`, so no new `endedAt` field. - `evals/cli/lib/detours.ts` reads `record.cwd` and `record.resultTs` directly. The casts and the cast-based test helper are gone. ### Replay check I replayed the real `enrichFromRollout` against the Codex runs in the three most recent main CI `raw-results` artifacts (279 runs; calls rebuilt from each `result.json`, rollouts from `session-archive.tar.gz`), before and after the per-call pairing. Counts are command calls with a `cwd` and timestamp. | | all commands enriched | some enriched | none enriched | |---|---|---|---| | all-or-nothing (#351) | 249 | 0 | 30 | | per-call pairing | 274 | 5 | 0 | - The 249 runs that already paired are unchanged: their enriched events are identical before and after. - The 30 runs that were fully unenriched are all `build-functions-006` / `build-functions-007`. 25 had one extra rollout `CommandExecution` the stream never emitted (`failed`, exit -1: a long-running `supabase functions serve` killed after ~50s); they are now fully enriched. - 5 runs (all `build-functions-007`) are still partially enriched: 13 of their command calls stay unpaired, 12 of them `apply_patch` / `git apply` / `patch` / `cat >` heredoc commands whose rollout argv differs from the stream's command text, and 1 `docker exec ... sh -c '...'` command that also doesn't match its rollout argv. Everything around them is enriched. Matching those heredocs would need a looser comparison, which this PR doesn't attempt. ## Test plan - `pnpm format:check`, `pnpm typecheck` - `pnpm --filter @supabase-evals/core test` - `pnpm --filter @supabase-evals/framework exec vitest run --root ../.. evals/cli` - `pnpm --filter @supabase-evals/framework test:cli-lib` - New tests: per-call Codex pairing (extra rollout item, one mismatched command, fewer rollout items, order safety); Codex paired item with a path / `file://` / no `cwd`; OpenCode `workdir` to `cwd`; `adaptTranscript` copies `cwd` and `resultTs`; `extractCommandEntries` with typed records. - `packages/core/src/agents/codex/parser.test.ts`: the MCP transcript assertion now includes `id: 'item_7'`. It was failing on main since #351. 🤖 Generated with [Claude Code](https://claude.com/claude-code)
Each run's trace now follows the trace shape in Braintrust's eval span spec, with span naming that mirrors their Claude Code plugin.
So far we've populated transcripts from each harness' stdout but some data necessary to support this only lives in the on-disk session files, so this PR adds an
enrichEventshook to populate missing fields from the session files.Ran one resolve and one build benchmark eval per harness through the refresh workflow (Claude Code, Grok, OpenCode, Codex).
Judge calls will be traced as a follow-up in AI-1271. I also want to instrument the setup/teardown time so the run timing is more accurate in AI-1279. Reasoning token metrics are split out to AI-1281.
Closes AI-1264