mirror of
https://github.com/AgentSeal/codeburn.git
synced 2026-08-23 07:25:16 +00:00
8ec2753cbd
The second half of #940 (@ozymandiashh): upstream `main` measures Codex
throughput — a task's wall time minus its recorded tool wait, divided across
the task's calls by generated tokens — and none of it exists on this branch.
Added on one side only, so a `main` merge would land `src/codex-throughput.ts`
at a path npm workspaces does not build.
Rehomed against main as it ships today, with one deliberate divergence from
#940, which the maintainer decided: main's resume design wins.
- Timing state is captured ONLY at a `task_started` boundary, where every
per-task accumulator is provably empty, and a task's calls are buffered
until its window is known. No recorded call is ever mutated after it has
been handed to the host. #940's alternative — threading the open task
window through the serialized state and back-patching earlier-pass calls
via applyCodexTimingPatches — is dropped in full.
- The branch's Phase-4 token-decode resume is untouched: it stays any-offset
and round-trip proven. Marrying the two needed one adaptation, since core
decodes records and never sees bytes: the decoder now reports its last
task_started as a `checkpoint` (record index + call count + state), and the
CLI turns that index into a byte offset and replays only the calls before
it, letting the still-open task re-derive. A pass that crosses no boundary
keeps the previous one; a cold decode of a file with no task_started at all
falls back to end-of-file with `taskOpen: false`, so a task_complete whose
window this pass never saw attributes nothing rather than spreading a whole
task's active time over part of its tokens.
Restores the three fad84662 review fixes that #940 reverted: the discovery
fast path already short-circuits on cachedProject before isValidCodexSession
(unchanged here, verified); payload-level `duration_ms` outranks any nested one
(`timingDuration ?? timingNumber('duration_ms')`), so a duration buried in an
oversized mcp_tool_call_end's invocation.arguments can no longer inflate tool
wait; and MIN_WIDE stays 90 with the Tok/s column behind a showTps gate rather
than jumping to 130 and costing 90-129 column terminals their two-column
dashboard. Also ports the fork-suppressed-task_started regression test and the
depth-1 payloadString helper (main 1d36f444/497f6556), which the branch lacked.
Scope discipline: main's codex pricing work (billableOutputTokens, #1078) is
NOT dragged along — that is #1083 — and neither are its unported parser
changes (custom-tool transport, exact token counts and MCP names on oversized
lines), so cost, calls and tokens are untouched. Verified on a 1326-session
real corpus: codex totals byte-identical to the base branch, with 1302 of 1328
model slices now carrying timing (36.5 Tok/s on GPT-5.5).
CODEX_CACHE_VERSION takes 12, clear of main's ladder (11 as of #1078) so a
cache written by either line can never be read as current by the other, and
the codex parse version bumps in lockstep so session-cache.json cannot keep
serving timing-less turns without invoking the parser.
124 lines
8.4 KiB
TypeScript
124 lines
8.4 KiB
TypeScript
import { appendFile, mkdtemp, writeFile } from 'node:fs/promises'
|
|
import { tmpdir } from 'node:os'
|
|
import { join } from 'node:path'
|
|
import { describe, expect, it } from 'vitest'
|
|
import { CodexThroughputReader, readCodexThroughput, renderCodexThroughput } from '../src/codex-throughput.js'
|
|
|
|
describe('Codex throughput prototype', () => {
|
|
it('estimates generated tokens/sec between token_count checkpoints', async () => {
|
|
const dir = await mkdtemp(join(tmpdir(), 'codeburn-tps-'))
|
|
const path = join(dir, 'rollout.jsonl')
|
|
await writeFile(path, [
|
|
JSON.stringify({ type: 'session_meta', timestamp: '2026-07-25T00:00:00.000Z', payload: { model: 'gpt-5.6-sol' } }),
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:00.000Z', payload: { type: 'task_started' } }),
|
|
JSON.stringify({ type: 'response_item', timestamp: '2026-07-25T00:00:02.000Z', payload: { type: 'function_call', call_id: 'tool-1' } }),
|
|
JSON.stringify({ type: 'response_item', timestamp: '2026-07-25T00:00:05.000Z', payload: { type: 'function_call_output', call_id: 'tool-1' } }),
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:05.000Z', payload: { type: 'mcp_tool_call_end', duration: { secs: 3, nanos: 0 } } }),
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:10.000Z', payload: { type: 'token_count', info: { last_token_usage: { output_tokens: 80, reasoning_output_tokens: 20 }, total_token_usage: { total_tokens: 100, output_tokens: 80, reasoning_output_tokens: 20 } } } }),
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:15.000Z', payload: { type: 'token_count', info: { last_token_usage: { output_tokens: 40, reasoning_output_tokens: 10 }, total_token_usage: { total_tokens: 150, output_tokens: 120, reasoning_output_tokens: 30 } } } }),
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:16.000Z', payload: { type: 'task_complete', duration_ms: 10000 } }),
|
|
].join('\n'))
|
|
|
|
const points = await readCodexThroughput(path)
|
|
expect(points).toHaveLength(2)
|
|
expect(points[1]).toMatchObject({ generatedTokens: 50, elapsedSeconds: 5, generatedTokensPerSecond: 10, activeDurationSeconds: 7, activeGeneratedTokensPerSecond: 21.428571428571427, toolWaitSeconds: 3, model: 'gpt-5.6-sol' })
|
|
expect(renderCodexThroughput(points, path)).toContain('21.4 generated tokens/sec')
|
|
})
|
|
|
|
it('parses only appended complete lines while watching a growing rollout', async () => {
|
|
const dir = await mkdtemp(join(tmpdir(), 'codeburn-tps-watch-'))
|
|
const path = join(dir, 'rollout.jsonl')
|
|
const first = JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:00.000Z', payload: { type: 'token_count', info: { last_token_usage: { output_tokens: 8, reasoning_output_tokens: 2 }, total_token_usage: { total_tokens: 10, output_tokens: 8, reasoning_output_tokens: 2 } } } })
|
|
const second = JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:01.000Z', payload: { type: 'token_count', info: { last_token_usage: { output_tokens: 4, reasoning_output_tokens: 1 }, total_token_usage: { total_tokens: 15, output_tokens: 12, reasoning_output_tokens: 3 } } } })
|
|
await writeFile(path, first.slice(0, 40))
|
|
const reader = new CodexThroughputReader()
|
|
expect(await reader.update(path)).toEqual([])
|
|
await appendFile(path, first.slice(40) + '\n' + second + '\n')
|
|
const points = await reader.update(path)
|
|
expect(points).toHaveLength(2)
|
|
expect(points[1]).toMatchObject({ generatedTokens: 5, generatedTokensPerSecond: 5 })
|
|
})
|
|
|
|
it('ignores replayed pre-fork checkpoints before estimating new work', async () => {
|
|
const dir = await mkdtemp(join(tmpdir(), 'codeburn-tps-fork-'))
|
|
const path = join(dir, 'rollout.jsonl')
|
|
const line = (timestamp: string, payload: Record<string, unknown>) => JSON.stringify({ type: 'event_msg', timestamp, payload })
|
|
await writeFile(path, [
|
|
JSON.stringify({ type: 'session_meta', timestamp: '2026-07-25T00:00:00.000Z', payload: { model: 'gpt-5.6-sol', forked_from_id: 'parent' } }),
|
|
line('2026-07-25T00:00:01.000Z', { type: 'task_started' }),
|
|
line('2026-07-25T00:00:02.000Z', { type: 'token_count', info: { last_token_usage: { output_tokens: 100 }, total_token_usage: { total_tokens: 100, output_tokens: 100 } } }),
|
|
line('2026-07-25T00:00:03.000Z', { type: 'task_complete', duration_ms: 1000 }),
|
|
line('2026-07-25T00:00:06.000Z', { type: 'task_started' }),
|
|
line('2026-07-25T00:00:08.000Z', { type: 'token_count', info: { last_token_usage: { output_tokens: 20 }, total_token_usage: { total_tokens: 20, output_tokens: 20 } } }),
|
|
line('2026-07-25T00:00:10.000Z', { type: 'task_complete', duration_ms: 4000 }),
|
|
].join('\n'))
|
|
|
|
const points = await readCodexThroughput(path)
|
|
expect(points).toHaveLength(1)
|
|
expect(points[0]).toMatchObject({ generatedTokens: 20, activeGeneratedTokensPerSecond: 5 })
|
|
})
|
|
|
|
it('keeps oversized rollout lines bounded while extracting token usage', async () => {
|
|
const dir = await mkdtemp(join(tmpdir(), 'codeburn-tps-large-'))
|
|
const path = join(dir, 'rollout.jsonl')
|
|
const largeResult = JSON.stringify({
|
|
type: 'event_msg',
|
|
timestamp: '2026-07-25T00:00:01.000Z',
|
|
payload: {
|
|
type: 'token_count',
|
|
info: { last_token_usage: { output_tokens: 12 }, total_token_usage: { total_tokens: 12, output_tokens: 12 } },
|
|
result: 'x'.repeat(5 * 1024 * 1024),
|
|
},
|
|
})
|
|
await writeFile(path, largeResult)
|
|
const points = await readCodexThroughput(path)
|
|
expect(points).toHaveLength(1)
|
|
expect(points[0]?.generatedTokens).toBe(12)
|
|
})
|
|
|
|
it('keeps MCP duration when arguments and result surround the middle field', async () => {
|
|
const dir = await mkdtemp(join(tmpdir(), 'codeburn-tps-mcp-large-'))
|
|
const path = join(dir, 'rollout.jsonl')
|
|
const mcp = JSON.stringify({
|
|
type: 'event_msg', timestamp: '2026-07-25T00:00:05.000Z',
|
|
payload: {
|
|
type: 'mcp_tool_call_end',
|
|
invocation: { server: 'github', tool: 'get_issue', arguments: { body: 'x'.repeat(5 * 1024 * 1024) } },
|
|
duration: { secs: 3, nanos: 0 },
|
|
result: { duration: '9s', text: 'x'.repeat(5 * 1024 * 1024) },
|
|
},
|
|
})
|
|
await writeFile(path, [
|
|
JSON.stringify({ type: 'session_meta', timestamp: '2026-07-25T00:00:00.000Z', payload: { model: 'gpt-5.6-sol' } }),
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:00.000Z', payload: { type: 'task_started' } }),
|
|
mcp,
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:08.000Z', payload: { type: 'token_count', info: { last_token_usage: { output_tokens: 100 }, total_token_usage: { total_tokens: 100, output_tokens: 100 } } } }),
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:10.000Z', payload: { type: 'task_complete', duration_ms: 10000 } }),
|
|
].join('\n'))
|
|
const points = await readCodexThroughput(path)
|
|
expect(points[0]).toMatchObject({ toolWaitSeconds: 3, activeDurationSeconds: 7, activeGeneratedTokensPerSecond: 100 / 7 })
|
|
})
|
|
|
|
it('keeps a streamed string MCP duration when arguments and result surround the middle field', async () => {
|
|
const dir = await mkdtemp(join(tmpdir(), 'codeburn-tps-mcp-string-large-'))
|
|
const path = join(dir, 'rollout.jsonl')
|
|
const mcp = JSON.stringify({
|
|
type: 'event_msg', timestamp: '2026-07-25T00:00:05.000Z',
|
|
payload: {
|
|
type: 'mcp_tool_call_end',
|
|
invocation: { server: 'github', tool: 'get_issue', arguments: { body: 'x'.repeat(5 * 1024 * 1024) } },
|
|
duration: '3s',
|
|
result: { duration: '9s', text: 'x'.repeat(5 * 1024 * 1024) },
|
|
},
|
|
})
|
|
await writeFile(path, [
|
|
JSON.stringify({ type: 'session_meta', timestamp: '2026-07-25T00:00:00.000Z', payload: { model: 'gpt-5.6-sol' } }),
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:00.000Z', payload: { type: 'task_started' } }),
|
|
mcp,
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:08.000Z', payload: { type: 'token_count', info: { last_token_usage: { output_tokens: 100 }, total_token_usage: { total_tokens: 100, output_tokens: 100 } } } }),
|
|
JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:10.000Z', payload: { type: 'task_complete', duration_ms: 10000 } }),
|
|
].join('\n'))
|
|
const points = await readCodexThroughput(path)
|
|
expect(points[0]).toMatchObject({ toolWaitSeconds: 3, activeDurationSeconds: 7, activeGeneratedTokensPerSecond: 100 / 7 })
|
|
})
|
|
})
|