diff --git a/packages/cli/src/pricing-pass.ts b/packages/cli/src/pricing-pass.ts index c611c97b..46bce774 100644 --- a/packages/cli/src/pricing-pass.ts +++ b/packages/cli/src/pricing-pass.ts @@ -34,7 +34,11 @@ export function priceProviderCall(call: ParsedProviderCall): ParsedProviderCall outputForCost, call.cacheCreationInputTokens, call.cacheReadInputTokens, - call.webSearchRequests, + // cline-cli's `webSearchRequests` counts `fetch_web_content` page fetches, + // not billable provider-side searches: upstream reports the count on the + // call but passes a hardcoded 0 to the price table. Billing it here would + // add $0.01 per fetch on top of tokens. + call.provider === 'cline-cli' ? 0 : call.webSearchRequests, call.speed, ) // Seam extension: some decoders prefer the table price but fall back to a diff --git a/packages/cli/src/providers/cline-cli.ts b/packages/cli/src/providers/cline-cli.ts index aa09bf22..831117fe 100644 --- a/packages/cli/src/providers/cline-cli.ts +++ b/packages/cli/src/providers/cline-cli.ts @@ -73,11 +73,7 @@ function toProviderCall(rich: ClineCliDecodedCall): ParsedProviderCall { cacheReadInputTokens: rich.cacheReadInputTokens, cachedInputTokens: rich.cachedInputTokens, reasoningTokens: rich.reasoningTokens, - // Upstream prices the estimated path with a hardcoded 0 web-search requests, - // so the decoded count must not reach the pricing pass (which bills - // $0.01 each). A metered call carries the CLI's own dollar figure, so its - // real count rides along without touching cost. - webSearchRequests: measured ? rich.webSearchRequests : 0, + webSearchRequests: rich.webSearchRequests, ...(measured ? { costUSD: rich.reportedCost, costBasis: 'measured' as const } : { costBasis: 'estimated' as const }), diff --git a/packages/cli/tests/codex-checkpoint-resume.test.ts b/packages/cli/tests/codex-checkpoint-resume.test.ts new file mode 100644 index 00000000..f5f67f57 --- /dev/null +++ b/packages/cli/tests/codex-checkpoint-resume.test.ts @@ -0,0 +1,155 @@ +// Cold-vs-warm equivalence for the codex task_started checkpoint resume, at +// EVERY line split point of a rollout carrying two complete tasks (one with a +// function_call wait, one with an mcp_tool_call_end wait and two token_counts +// to split proportionally) plus a third task left OPEN at end of file. +// +// This is the gate the checkpoint design has to clear: an incremental parse of +// a growing rollout must produce exactly what a cold parse of the finished file +// produces — cost, tokens, turns AND timing. It mutation-kills both ways of +// getting the resume point wrong: replaying past the boundary (`callCount` not +// truncated, so the open task's calls are served stale and never re-derived) +// and resuming at end of file (the open task's window is lost, so its +// task_complete attributes nothing). +import { describe, it, expect, beforeEach, afterAll, vi } from 'vitest' +import { mkdir, rm, writeFile, appendFile, stat, utimes } from 'fs/promises' +import { join } from 'path' +import { clearSessionCache, parseAllSessions } from '../src/parser.js' + +const testRoot = vi.hoisted(() => { + const root = `${process.env['TMPDIR'] || '/tmp'}/codex-ckpt-${process.pid}-${Date.now()}` + process.env['HOME'] = `${root}/home` + process.env['USERPROFILE'] = `${root}/home` + process.env['CODEX_HOME'] = `${root}/codex` + return root +}) +const CODEX_HOME = join(testRoot, 'codex') +beforeEach(() => { + process.env['HOME'] = join(testRoot, 'home') + process.env['USERPROFILE'] = join(testRoot, 'home') + process.env['CODEX_HOME'] = CODEX_HOME + process.env['CODEBURN_CACHE_DIR'] = join(testRoot, 'cache') +}) + +afterAll(async () => { await rm(testRoot, { recursive: true, force: true }) }) + +const ts = (n: number) => new Date(Date.UTC(2026, 3, 14, 10, 0, 0) + n * 1000).toISOString() + +// A rollout with: 2 complete tasks (one with a function_call tool wait, one +// with an mcp_tool_call_end wait) + a 3rd task left OPEN at EOF. +function buildLines(): string[] { + const L: unknown[] = [] + L.push({ type: 'session_meta', timestamp: ts(0), payload: { session_id: 'sess-adv', model: 'gpt-5.5', cwd: '/Users/test/proj', originator: 'codex-cli' } }) + // --- task 1: 10s total, 3s function_call wait + L.push({ type: 'event_msg', timestamp: ts(10), payload: { type: 'task_started' } }) + L.push({ type: 'response_item', timestamp: ts(11), payload: { type: 'function_call', call_id: 'c1', name: 'shell' } }) + L.push({ type: 'response_item', timestamp: ts(14), payload: { type: 'function_call_output', call_id: 'c1' } }) + L.push({ type: 'event_msg', timestamp: ts(15), payload: { type: 'token_count', info: { last_token_usage: { input_tokens: 10, output_tokens: 100, reasoning_output_tokens: 20, total_tokens: 130 }, total_token_usage: { input_tokens: 10, output_tokens: 100, reasoning_output_tokens: 20, total_tokens: 130 } } } }) + L.push({ type: 'event_msg', timestamp: ts(20), payload: { type: 'task_complete', duration_ms: 10000 } }) + // --- task 2: 8s total, 2s mcp wait, TWO token_counts (proportional split) + L.push({ type: 'event_msg', timestamp: ts(30), payload: { type: 'task_started' } }) + L.push({ type: 'event_msg', timestamp: ts(33), payload: { type: 'mcp_tool_call_end', duration_ms: 2000, invocation: { server: 's', tool: 't' } } }) + L.push({ type: 'event_msg', timestamp: ts(34), payload: { type: 'token_count', info: { last_token_usage: { input_tokens: 5, output_tokens: 40, reasoning_output_tokens: 10, total_tokens: 55 }, total_token_usage: { input_tokens: 15, output_tokens: 140, reasoning_output_tokens: 30, total_tokens: 185 } } } }) + L.push({ type: 'event_msg', timestamp: ts(36), payload: { type: 'token_count', info: { last_token_usage: { input_tokens: 5, output_tokens: 60, reasoning_output_tokens: 0, total_tokens: 65 }, total_token_usage: { input_tokens: 20, output_tokens: 200, reasoning_output_tokens: 30, total_tokens: 250 } } } }) + L.push({ type: 'event_msg', timestamp: ts(38), payload: { type: 'task_complete', duration_ms: 8000 } }) + // --- task 3: OPEN at EOF (task_started + tokens, no task_complete) + L.push({ type: 'event_msg', timestamp: ts(50), payload: { type: 'task_started' } }) + L.push({ type: 'event_msg', timestamp: ts(52), payload: { type: 'token_count', info: { last_token_usage: { input_tokens: 7, output_tokens: 70, reasoning_output_tokens: 5, total_tokens: 82 }, total_token_usage: { input_tokens: 27, output_tokens: 270, reasoning_output_tokens: 35, total_tokens: 332 } } } }) + return L.map(o => JSON.stringify(o)) +} + +type Shot = Record + +async function snapshot(): Promise { + clearSessionCache() + const projects = await parseAllSessions() + const mb: Record = {} + let turns = 0, cost = 0, outTok = 0, inTok = 0 + for (const p of projects) for (const s of p.sessions) { + turns += (s.turns ?? []).length + for (const [model, d] of Object.entries(s.modelBreakdown)) { + const prev = (mb[model] as any) ?? { calls: 0, costUSD: 0, out: 0, activeDurationMs: 0, activeGeneratedTokens: 0, toolWaitMs: 0 } + mb[model] = { + calls: prev.calls + d.calls, + costUSD: +(prev.costUSD + d.costUSD).toFixed(10), + out: prev.out + d.tokens.outputTokens, + activeDurationMs: +(prev.activeDurationMs + (d.activeDurationMs ?? 0)).toFixed(6), + activeGeneratedTokens: prev.activeGeneratedTokens + (d.activeGeneratedTokens ?? 0), + toolWaitMs: +(prev.toolWaitMs + (d.toolWaitMs ?? 0)).toFixed(6), + } + cost += d.costUSD; outTok += d.tokens.outputTokens; inTok += d.tokens.inputTokens + } + } + return { modelBreakdown: mb, turns, cost: +cost.toFixed(10), outTok, inTok } +} + +const SESSION_DIR = join(CODEX_HOME, 'sessions', '2026', '04', '14') +const CACHE_DIR = join(testRoot, 'cache') +const ROLLOUT = join(SESSION_DIR, 'rollout-2026-04-14T10-00-00-adv.jsonl') + +// CODEX_HOME / CODEBURN_CACHE_DIR resolve at import time, so the roots stay +// fixed and each scenario wipes their CONTENTS instead of repointing them. +async function freshEnv(_tag: string) { + await rm(SESSION_DIR, { recursive: true, force: true }) + await rm(CACHE_DIR, { recursive: true, force: true }) + await mkdir(SESSION_DIR, { recursive: true }) + await mkdir(CACHE_DIR, { recursive: true }) + return ROLLOUT +} + +async function bump(file: string, n: number) { + const t = new Date(Date.now() + n * 60_000) + await utimes(file, t, t) +} + +describe('codex checkpoint resume: warm append equals cold parse', () => { + const lines = buildLines() + + it('cold full parse equals warm append parse at EVERY line split point', async () => { + const f0 = await freshEnv('cold') + await writeFile(f0, lines.join('\n') + '\n') + const cold = await snapshot() + expect((cold as any).outTok).toBeGreaterThan(0) + // sanity: timing actually got attributed somewhere + expect(Object.values((cold as any).modelBreakdown).some((d: any) => d.activeDurationMs > 0)).toBe(true) + + for (let split = 1; split < lines.length; split++) { + const f = await freshEnv(`warm-${split}`) + await writeFile(f, lines.slice(0, split).join('\n') + '\n') + await snapshot() // pass 1: prefix + await appendFile(f, lines.slice(split).join('\n') + '\n') + await bump(f, split + 1) + const warm = await snapshot() // pass 2: appended tail + expect({ split, warm }).toEqual({ split, warm: cold }) + } + }, 300_000) + + it('cold full parse equals a THREE-pass incremental parse across both task boundaries', async () => { + const f0 = await freshEnv('cold3') + await writeFile(f0, lines.join('\n') + '\n') + const cold = await snapshot() + + // Cuts that land mid-task on both appends, so every pass has to rebuild a + // window it did not open. The full cross product adds ~90 more parses for + // no extra mutation coverage. + for (const [a, b] of [[4, 9], [3, 12], [9, 13]] as const) { + const f = await freshEnv(`w3-${a}-${b}`) + await writeFile(f, lines.slice(0, a).join('\n') + '\n') + await snapshot() + await appendFile(f, lines.slice(a, b).join('\n') + '\n'); await bump(f, 1) + await snapshot() + await appendFile(f, lines.slice(b).join('\n') + '\n'); await bump(f, 2) + const warm = await snapshot() + expect({ a, b, warm }).toEqual({ a, b, warm: cold }) + } + }, 300_000) + + it('re-running warm twice is stable (idempotent)', async () => { + const f = await freshEnv('stable') + await writeFile(f, lines.slice(0, 9).join('\n') + '\n') + await snapshot() + await appendFile(f, lines.slice(9).join('\n') + '\n'); await bump(f, 1) + const first = await snapshot() + const second = await snapshot() + expect(second).toEqual(first) + }, 120_000) +}) diff --git a/packages/cli/tests/providers/cline-cli.test.ts b/packages/cli/tests/providers/cline-cli.test.ts index 1d197f85..ba082a25 100644 --- a/packages/cli/tests/providers/cline-cli.test.ts +++ b/packages/cli/tests/providers/cline-cli.test.ts @@ -509,30 +509,41 @@ describe('cline-cli provider - rollup fallback', () => { expect(calls[0]?.costUSD).toBeGreaterThan(0) }) - it('keeps web-search requests out of the estimated-cost path', async () => { + it('reports web-search requests but never bills them, on either cost path', async () => { const fetchTool = { name: 'fetch_web_content', input: { url: 'https://example.com' } } + const metrics = { inputTokens: 1000, outputTokens: 100 } await writeSession(tmpDir, 'sess-a', { messages: [ { role: 'user', text: 'go' }, - { role: 'assistant', text: 'ok', metrics: { inputTokens: 1000, outputTokens: 100 }, toolUse: fetchTool }, + { role: 'assistant', text: 'ok', metrics, toolUse: fetchTool }, ], }) + // Same tokens, no fetch: the estimated cost must not move between the two. await writeSession(tmpDir, 'sess-b', { messages: [ { role: 'user', text: 'go' }, - { role: 'assistant', text: 'ok', metrics: { inputTokens: 1000, outputTokens: 100, cost: 0.02 }, toolUse: fetchTool }, + { role: 'assistant', text: 'ok', metrics }, + ], + }) + await writeSession(tmpDir, 'sess-c', { + messages: [ + { role: 'user', text: 'go' }, + { role: 'assistant', text: 'ok', metrics: { ...metrics, cost: 0.02 }, toolUse: fetchTool }, ], }) const calls = await collect(tmpDir) - const estimated = calls.find(c => c.costIsEstimated) - const metered = calls.find(c => !c.costIsEstimated) + const [withFetch, withoutFetch, metered] = calls - expect(estimated?.tools).toContain('WebFetch') - // Upstream prices this path with a hardcoded 0 requests; routing the real - // count into the pricing pass would bill $0.01 per fetch on top of tokens. - expect(estimated?.webSearchRequests).toBe(0) + // Upstream reports the count on every per-message call (it is an analytics + // field, not a billing input). + expect(withFetch?.tools).toContain('WebFetch') + expect(withFetch?.webSearchRequests).toBe(1) expect(metered?.webSearchRequests).toBe(1) + // ...and prices it with a hardcoded 0 requests: routing the count into the + // pricing pass would add $0.01 per fetch on top of the token cost. + expect(withFetch?.costUSD).toBe(withoutFetch?.costUSD) + expect(metered?.costUSD).toBe(0.02) }) it('emits nothing for a session with neither message metrics nor a rollup', async () => { diff --git a/packages/core/src/providers/codex/decode.ts b/packages/core/src/providers/codex/decode.ts index 7cd064fb..62f4e04a 100644 --- a/packages/core/src/providers/codex/decode.ts +++ b/packages/core/src/providers/codex/decode.ts @@ -579,10 +579,19 @@ export function decodeCodex({ records, state: prevState, seenKeys: liveSeen, ses continue } - // Closes a tool-wait interval opened by the matching function_call. Tool - // names and files were already collected there, so this branch is timing - // only. - if (entry.type === 'response_item' && entry.payload?.type === 'function_call_output') { + // Opens a tool-wait interval for Codex Desktop's custom-tool transport, + // which the branch's tool-name collection above does not speak yet. Timing + // only, exactly as codex-throughput.ts counts it. + if (entry.type === 'response_item' && entry.payload?.type === 'custom_tool_call') { + const callId = entry.payload.call_id + const started = entry.timestamp ? Date.parse(entry.timestamp) : NaN + if (!isForkReplay && callId && Number.isFinite(started)) openToolStarts.set(callId, started) + continue + } + + // Closes a tool-wait interval opened by the matching call. Tool names and + // files were already collected there, so this branch is timing only. + if (entry.type === 'response_item' && (entry.payload?.type === 'function_call_output' || entry.payload?.type === 'custom_tool_call_output')) { if (isForkReplay) continue const callId = entry.payload.call_id const ended = entry.timestamp ? Date.parse(entry.timestamp) : NaN diff --git a/packages/core/tests/providers/codex-decode.test.ts b/packages/core/tests/providers/codex-decode.test.ts index 515e1215..86bfb90b 100644 --- a/packages/core/tests/providers/codex-decode.test.ts +++ b/packages/core/tests/providers/codex-decode.test.ts @@ -418,3 +418,52 @@ describe('codex decoder — task-timing checkpoint', () => { expect(calls[1]!.toolWaitMs).toBeUndefined() }) }) + +// One task carrying TWO token_counts, so a pass that resumes INSIDE it holds +// only part of the task's generated tokens. +const SPLIT_TASK_CORPUS: string[] = [ + sessionMeta({ session_id: 'sess-split', timestamp: '2026-04-14T10:00:00Z' }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:00Z', payload: { type: 'task_started' } }), + userMessage('two checkpoints', '2026-04-14T10:00:01Z'), + tokenCount({ timestamp: '2026-04-14T10:00:02Z', last: { input: 100, output: 100 }, total: { input: 100, output: 100, total: 200 } }), + tokenCount({ timestamp: '2026-04-14T10:00:04Z', last: { input: 100, output: 100 }, total: { input: 200, output: 200, total: 400 } }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:06Z', payload: { type: 'task_complete', duration_ms: 6_000 } }), +] + +describe('codex decoder — timing never lands on a partial task window', () => { + it('attributes the whole window across both calls in one pass', () => { + const cold = decodeCold(SPLIT_TASK_CORPUS) + expect(cold).toHaveLength(2) + expect(cold[0]!.activeDurationMs).toBe(3000) + expect(cold[1]!.activeDurationMs).toBe(3000) + }) + + it('attributes nothing when the pass holding task_complete never opened the window', () => { + // Resume from an end-of-file state (taskOpen false) with the tail carrying + // the task's SECOND token_count and its task_complete. Without the gate the + // tail would take the full 6s window for the one call it happens to hold — + // double its real share, and the first call would stay unattributed. + const first = decodeCodex({ records: SPLIT_TASK_CORPUS.slice(0, 4), context }) + const serialized: CodexDecodeState = JSON.parse(JSON.stringify(first.state)) + expect(serialized.taskOpen).toBe(false) + const second = decodeCodex({ records: SPLIT_TASK_CORPUS.slice(4), context, state: serialized }) + expect(second.calls).toHaveLength(1) + expect(second.calls[0]!.activeDurationMs).toBeUndefined() + expect(second.calls[0]!.toolWaitMs).toBeUndefined() + }) + + it('excludes custom-tool wait from active time, like a function_call pair', () => { + const records = [ + sessionMeta({ session_id: 'sess-custom', timestamp: '2026-04-14T10:00:00Z' }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:00Z', payload: { type: 'task_started' } }), + userMessage('run the tool', '2026-04-14T10:00:01Z'), + JSON.stringify({ type: 'response_item', timestamp: '2026-04-14T10:00:02Z', payload: { type: 'custom_tool_call', call_id: 'c1', name: 'exec' } }), + JSON.stringify({ type: 'response_item', timestamp: '2026-04-14T10:00:05Z', payload: { type: 'custom_tool_call_output', call_id: 'c1', output: 'ok' } }), + tokenCount({ timestamp: '2026-04-14T10:00:08Z', last: { input: 300, output: 100 }, total: { input: 300, output: 100, total: 400 } }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:10Z', payload: { type: 'task_complete', duration_ms: 10_000 } }), + ] + const calls = decodeCold(records) + expect(calls).toHaveLength(1) + expect(calls[0]).toMatchObject({ activeDurationMs: 7000, toolWaitMs: 3000 }) + }) +})