feat: show agent setup, teardown, and scoring as Braintrust spans

apps/framework/harness/run-eval.ts

@@ -373,6 +373,10 @@ async function runOne(
     stepCount?: number;
     toolCallCount: number;
     agentRunDurationMs: number;
+    agentRunStartedAt: number;
+    agentPromptAt?: number;
+    agentRunEndedAt: number;
+    scoringEndedAt: number;
     cliVersion?: string;
   }
 > {
@@ -456,6 +460,7 @@ async function runOne(
       timeoutSec: TIMEOUT_SEC,
       sessionArchivePath: sessionArchivePath(expName, ev.id, runIndex),
     });
+    const agentRunEndedAt = Date.now();
     await session.ensureReady?.();
     // Exports the workspace so scorers can run host tooling (vite/vitest) against it.
     // Withheld tests are copied in lazily, only if the scorer asks to run Vitest.
@@ -481,6 +486,7 @@ async function runOne(
         return vitestRun(hostWorkspace);
       },
     });
+    const scoringEndedAt = Date.now();
 
     // Runs after scoring so the scorer sees what the agent actually saw, not rehydrated content.
     await rehydrateTruncatedDocsResults(session.sandbox, run.toolCalls);
@@ -503,6 +509,10 @@ async function runOne(
       stepCount: run.stepCount,
       toolCallCount: run.toolCalls.length,
       agentRunDurationMs: run.durationMs,
+      agentRunStartedAt: run.startedAt,
+      agentPromptAt: run.promptAt,
+      agentRunEndedAt,
+      scoringEndedAt,
       cliVersion: marker?.cliVersion ?? ev.metadata.cliVersion,
     };
   }
@@ -543,12 +553,14 @@ async function runOne(
     timeoutSec: TIMEOUT_SEC,
     sessionArchivePath: sessionArchivePath(expName, ev.id, runIndex),
   });
+  const agentRunEndedAt = Date.now();
   const last = await (scorer as ToolScorer)({
     ...session.scoringContext,
     toolCalls: run.toolCalls,
     transcript: run.transcript,
     agentReport: run.agentReport,
   });
+  const scoringEndedAt = Date.now();
 
   // Runs after scoring so the scorer sees what the agent actually saw, not rehydrated content.
   if (cliSandbox)
@@ -568,6 +580,10 @@ async function runOne(
     stepCount: run.stepCount,
     toolCallCount: run.toolCalls.length,
     agentRunDurationMs: run.durationMs,
+    agentRunStartedAt: run.startedAt,
+    agentPromptAt: run.promptAt,
+    agentRunEndedAt,
+    scoringEndedAt,
     // No sandbox in tools mode, so no marker to read; only the frontmatter pin applies.
     cliVersion: ev.metadata.cliVersion,
   };

apps/framework/scripts/upload-braintrust.test.ts

@@ -128,7 +128,7 @@ function recorder(node: RecordedSpan): SpanSink {
 }
 
 describe('logTranscript', () => {
-  it('logs back-to-back LLM spans per request, with tool calls as siblings under task', () => {
+  it('logs back-to-back LLM spans per request, with teardown and score after task', () => {
     const root: RecordedSpan = { children: [] };
     const ms = (s: number) => (100 + s) * 1000;
     logTranscript(recorder(root), {
@@ -138,7 +138,9 @@ describe('logTranscript', () => {
       passed: true,
       modelId: 'm',
       startTime: 100,
-      endTime: 170,
+      endTime: 150,
+      agentEndTime: 140,
+      scoringEndTime: 150,
       toolLabels: [],
       transcript: [
         {
@@ -230,7 +232,98 @@ describe('logTranscript', () => {
           input: [prompt, first, skillResult, second, bashResult],
         }
       ),
-      span('passed', 70, 70),
+      span('teardown', 38, 40),
+      span('passed', 40, 50),
+    ]);
+  });
+
+  it.each([
+    ['recorded prompt', 102, 102],
+    ['prompt before run start', 98, 100],
+    ['prompt after first event', 109, 108],
+  ])('starts task and the first LLM span at the %s', (_, promptTime, at) => {
+    const root: RecordedSpan = { children: [] };
+    logTranscript(recorder(root), {
+      prompt: 'go',
+      agentReport: '',
+      checks: [],
+      passed: true,
+      modelId: 'm',
+      startTime: 100,
+      endTime: 120,
+      promptTime,
+      agentEndTime: 110,
+      scoringEndTime: 120,
+      toolLabels: [],
+      transcript: [
+        { type: 'message', role: 'assistant', content: 'a', ts: 108_000 },
+      ],
+    });
+    expect(
+      root.children.map(({ name, start, end }) => [name, start, end])
+    ).toEqual([
+      ['setup', 100, at],
+      ['task', at, 108],
+      ['teardown', 108, 110],
+      ['passed', 110, 120],
+    ]);
+    expect(root.children[1]?.children[0]).toMatchObject({
+      name: 'm',
+      start: at,
+      end: 108,
+    });
+  });
+
+  it('ends setup at a leading non-assistant message and starts task there', () => {
+    const root: RecordedSpan = { children: [] };
+    logTranscript(recorder(root), {
+      prompt: '',
+      agentReport: '',
+      checks: [],
+      passed: false,
+      startTime: 100,
+      endTime: 120,
+      agentEndTime: 110,
+      scoringEndTime: 120,
+      toolLabels: [],
+      transcript: [
+        { type: 'message', role: 'system', content: 'init', ts: 103_000 },
+        { type: 'message', role: 'assistant', content: 'a', ts: 108_000 },
+      ],
+    });
+    expect(
+      root.children.map(({ name, start, end }) => [name, start, end])
+    ).toEqual([
+      ['setup', 100, 103],
+      ['task', 103, 108],
+      ['teardown', 108, 110],
+      ['passed', 110, 120],
+    ]);
+    expect(root.children[1]?.children.map((c) => c.name)).toEqual([
+      'system',
+      'assistant',
+    ]);
+  });
+
+  it('keeps a zero-length score at the run end for results without recorded times', () => {
+    const root: RecordedSpan = { children: [] };
+    logTranscript(recorder(root), {
+      prompt: '',
+      agentReport: '',
+      checks: [],
+      passed: true,
+      startTime: 100,
+      endTime: 170,
+      toolLabels: [],
+      transcript: [
+        { type: 'message', role: 'assistant', content: 'a', ts: 104_000 },
+      ],
+    });
+    expect(
+      root.children.map(({ name, start, end }) => [name, start, end])
+    ).toEqual([
+      ['task', 100, 104],
+      ['passed', 170, 170],
     ]);
   });
 });

apps/framework/scripts/upload-braintrust.ts

@@ -84,6 +84,11 @@ interface PendingRow {
   /** Unix seconds. */
   startTime?: number;
   endTime?: number;
+  /** When the CLI recorded the prompt; absent on older results. */
+  promptTime?: number;
+  /** When `agent.run()` returned and scoring began; absent on older results. */
+  agentEndTime?: number;
+  scoringEndTime?: number;
 }
 
 function git(...args: string[]): string | undefined {
@@ -267,11 +272,11 @@ async function collectRows(
     const durationMs =
       result.agentRunDurationMs ??
       (typeof result.durationMs === 'number' ? result.durationMs : undefined);
-    // Results record duration but no start time, so derive it from file mtime.
     const { mtimeMs } = await stat(absolutePath);
     if (mtimeMs < SINCE) {
       continue;
     }
+    // Older results record only a duration, so derive the window from mtime.
     const endTime = durationMs ? mtimeMs / 1000 : undefined;
     const transcript = transcriptSchema.parse(result.transcript);
     const sessionArchivePath = join(
@@ -323,11 +328,19 @@ async function collectRows(
           ? { tool_call_count: result.toolCallCount }
           : {}),
       },
+      promptTime: sec(result.agentPromptAt),
+      agentEndTime: sec(result.agentRunEndedAt),
+      scoringEndTime: sec(result.scoringEndedAt),
       ...runWindow(
         transcript,
-        endTime && durationMs
-          ? { startTime: endTime - durationMs / 1000, endTime }
-          : {}
+        result.agentRunStartedAt && result.scoringEndedAt
+          ? {
+              startTime: result.agentRunStartedAt / 1000,
+              endTime: result.scoringEndedAt / 1000,
+            }
+          : endTime && durationMs
+            ? { startTime: endTime - durationMs / 1000, endTime }
+            : {}
       ),
     };
 
@@ -339,8 +352,10 @@ async function collectRows(
 }
 
 /**
- * Widens the mtime-derived window to cover transcript timestamps, since mtime
- * lands after scoring and the agent clock can drift from the host's.
+ * Widens the run window to cover transcript timestamps, since the mtime
+ * fallback lands after scoring. Transcript times come from the sandbox clock,
+ * which Docker shares with the host (<300ms apart on Docker Desktop), so skew
+ * is absorbed by widening and clamping rather than corrected.
  */
 function runWindow(
   transcript: TranscriptPart[],
@@ -385,15 +400,21 @@ export interface SpanSink {
  * generation time as a gap. Their Codex translator does what we do.
  * https://github.com/braintrustdata/braintrust-coding-agent-plugins/blob/c0346dcdb16ae9f136b3abf83efb6458191f9300/bt-daemon/src/translate/codex.rs#L929-L932
  *
- *   task                    0s → 38s
- *   ├─ llm (text + Skill)   0s → 4s
- *   ├─ Skill                4s → 5s
- *   ├─ llm (Bash only)      5s → 8s
- *   ├─ Bash                 8s → 31s
- *   └─ llm (text)          31s → 38s
+ *   eval                      0s → 50s
+ *   ├─ setup                  0s → 2s   CLI boot until it records the prompt
+ *   ├─ task                   2s → 38s
+ *   │  ├─ llm (text + Skill)  2s → 4s
+ *   │  ├─ Skill               4s → 5s
+ *   │  ├─ llm (Bash only)     5s → 8s
+ *   │  ├─ Bash                8s → 31s
+ *   │  └─ llm (text)         31s → 38s
+ *   ├─ teardown              38s → 40s  CLI exit until `agent.run()` returns
+ *   └─ passed (score)        40s → 50s  workspace export, checks, judges
  *
- * Parts without a `requestId` each get their own LLM span. Transcripts without
- * timestamps collapse every span to the run start.
+ * Without a prompt time or a leading non-assistant message there is no setup
+ * span, and the first LLM span starts at the run start. Parts without a
+ * `requestId` each get their own LLM span. Transcripts without timestamps
+ * collapse every span to the run start.
  */
 export function logTranscript(
   parent: SpanSink,
@@ -409,16 +430,42 @@ export function logTranscript(
     | 'toolLabels'
     | 'startTime'
     | 'endTime'
+    | 'promptTime'
+    | 'agentEndTime'
+    | 'scoringEndTime'
   >
 ): void {
-  const sec = (ms: number | undefined) => (ms ? ms / 1000 : undefined);
+  const [first] = row.transcript;
+  const promptTime =
+    row.promptTime ??
+    (first?.type === 'message' && first.role !== 'assistant'
+      ? sec(first.ts)
+      : undefined);
+  const firstTime = sec(row.transcript.find((part) => part.ts)?.ts);
+  // The prompt time is on the sandbox clock, so keep it inside the run.
+  const setupEnd =
+    promptTime === undefined
+      ? undefined
+      : Math.min(
+          Math.max(row.startTime ?? promptTime, promptTime),
+          firstTime ?? Infinity
+        );
+  if (row.startTime !== undefined && setupEnd !== undefined) {
+    const setup = parent.startSpan({
+      name: 'setup',
+      type: 'task',
+      startTime: row.startTime,
+    });
+    setup.end({ endTime: setupEnd });
+  }
+  const taskStart = setupEnd ?? row.startTime;
   const task = parent.startSpan({
     name: 'task',
     type: 'task',
-    startTime: row.startTime,
+    startTime: taskStart,
   });
   task.log({ input: row.prompt, output: row.agentReport });
-  let latestTime = row.startTime;
+  let latestTime = taskStart;
   let toolIndex = 0;
   // Seeded with the prompt, which the transcript omits.
   const history: Record<string, unknown>[] = row.prompt
@@ -548,17 +595,31 @@ export function logTranscript(
   }
   task.end({ endTime: latestTime });
 
-  const scoredAt = row.endTime ?? latestTime;
+  const agentEnd = latest(latestTime, row.agentEndTime);
+  if (row.agentEndTime !== undefined) {
+    const teardown = parent.startSpan({
+      name: 'teardown',
+      type: 'task',
+      startTime: latestTime,
+    });
+    teardown.end({ endTime: agentEnd });
+  }
+  const scoreStart =
+    row.agentEndTime === undefined ? (row.endTime ?? latestTime) : agentEnd;
   const scorer = parent.startSpan({
     name: 'passed',
     type: 'score',
-    startTime: scoredAt,
+    startTime: scoreStart,
   });
   scorer.log({
     output: row.checks,
     scores: { passed: row.passed ? 1 : 0 },
   });
-  scorer.end({ endTime: scoredAt });
+  scorer.end({ endTime: latest(scoreStart, row.scoringEndTime) });
+}
+
+function sec(ms: number | undefined) {
+  return ms ? ms / 1000 : undefined;
 }
 
 function latest(a: number | undefined, b: number | undefined) {

packages/core/src/agents/claude-code/parser.test.ts

@@ -1,5 +1,9 @@
 import { describe, expect, it } from 'vitest';
-import { claudeCodeParser, sessionRequestUsage } from './parser.js';
+import {
+  claudeCodeParser,
+  sessionPromptAt,
+  sessionRequestUsage,
+} from './parser.js';
 import { adaptTranscript } from '../../parsers/adapt.js';
 
 /** A representative Claude Code `--print` JSONL session. */
@@ -277,3 +281,16 @@ describe('sessionRequestUsage', () => {
     );
   });
 });
+
+describe('sessionPromptAt', () => {
+  it('returns the first user record time, skipping queue records', () => {
+    const jsonl = [
+      { type: 'queue-operation', timestamp: '2026-09-30T20:31:32.391Z' },
+      { type: 'user', timestamp: '2026-09-30T20:31:34.374Z' },
+      { type: 'user', timestamp: '2026-09-30T20:31:40.000Z' },
+    ]
+      .map((r) => JSON.stringify(r))
+      .join('\n');
+    expect(sessionPromptAt(jsonl)).toBe(Date.parse('2026-09-30T20:31:34.374Z'));
+  });
+});

packages/core/src/agents/claude-code/parser.ts

@@ -225,6 +225,14 @@ export function sessionRequestUsage(jsonl: string): Map<string, RequestUsage> {
   return byRequest;
 }
 
+/** When the session recorded its first user record, in epoch ms. */
+export function sessionPromptAt(jsonl: string): number | undefined {
+  const prompt = parseJsonlRecords(jsonl).records.find(
+    (record) => record.type === 'user' && typeof record.timestamp === 'string'
+  );
+  return prompt ? Date.parse(String(prompt.timestamp)) : undefined;
+}
+
 function recordToEvents(data: Record<string, unknown>): TranscriptEvent[] {
   const events: TranscriptEvent[] = [];
   const timestamp =