From bfcf63ce3a55162efd44f93dbcf95c10b4370281 Mon Sep 17 00:00:00 2001 From: iamtoruk Date: Fri, 21 Aug 2026 14:42:04 -0700 Subject: [PATCH 1/3] fix(codex): stop double-counting reasoning tokens in Tok/s throughput The same reasoning-inclusion bug #1075/#1078 fixed for cost also affected the throughput display: activeGeneratedTokens/taskGeneratedTokens in the Codex parser and generatedTokens in the live codex-tps reader summed outputTokens + reasoningTokens, but reasoning is already inside output. All three sites now route through the billableOutputTokens('codex', ...) helper #1078 introduced, so the throughput numerator can never drift from the billed one. Cost and every token count are unchanged (verified byte-identical on a real 51,753-call corpus); Tok/s drops 20-42% depending on how reasoning-heavy the model is. activeGeneratedTokens/activeDurationMs/toolWaitMs are stored verbatim in both the Codex result cache and the session cache rather than re-derived on read, so neither self-heals: CODEX_CACHE_VERSION moves 11 -> 13 (12 is claimed by feat/core-extraction's own port of this feature) and PROVIDER_PARSE_VERSIONS.codex gains a codex-tps-v1 suffix, forcing Codex sessions to re-parse once. Closes #1079 --- CHANGELOG.md | 1 + src/codex-cache.ts | 9 +++++++- src/codex-throughput.ts | 6 +++++- src/parser.ts | 2 +- src/providers/codex.ts | 7 +++++-- src/session-cache.ts | 6 +++++- tests/codex-throughput.test.ts | 38 +++++++++++++++++++++++++++++++--- tests/providers/codex.test.ts | 4 +++- 8 files changed, 63 insertions(+), 10 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b741c511a..034eb6a68 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -40,6 +40,7 @@ ### Fixed - **Mixed-version installs no longer thrash the Codex / Cursor / Antigravity result caches.** Daily and session caches already own a version-suffixed file so an old desktop binary and a newer CLI cannot clobber each other. The three per-provider result caches still used one unsuffixed filename with an internal version field, so a v10 and a v11 binary rewrote the same `codex-results.json` (and the Cursor / Antigravity siblings) on every run and each re-parsed its whole corpus. They now write `*-results.v.json` the same way the daily cache does. The unsuffixed file is left for older binaries; a matching-version copy is adopted once and never overwritten. (#1082) - **Codex spend no longer counts reasoning tokens twice, and cache writes are priced only where OpenAI actually charges for them.** OpenAI bills reasoning tokens as *part of* `output_tokens`, not on top of it — on a 1,396-rollout corpus all 134,316 events carrying a total satisfy `input + output == total` — but CodeBurn added `reasoning_output_tokens` to output when pricing a Codex call and again in the models, audit and per-model displays. Every Codex number was therefore too high: on that corpus **cost by $166.03 (3.5%)** and **displayed Output tokens by 34.6%** ($4,713.12 -> $4,547.09; 22.6M -> 16.8M output tokens). The raw `reasoningTokens` figure is unchanged and still reported on its own; only the double-count is gone. Both places that price a Codex call — the parser and the cache-rehydration re-price — now go through one shared `billableOutputTokens` helper, so a cold run and a warm run can never disagree. Separately, Codex's `cache_write_input_tokens` (new in codex PR #33454) was never read and cache-creation tokens were hardcoded to 0; they are now carved out of the uncached-input bucket and clamped so they can never exceed it. That carve-out happens **only on models whose pricing source publishes a real cache-write rate** — gpt-5.6 and its terra/sol/luna variants charge 1.25x input for a cache write, everything before it charges nothing extra — because CodeBurn fabricates a 1.25x rate when a source omits one, and charging that would have invented a surcharge on gpt-5.5, gpt-5.4, gpt-5.3-codex and gpt-5. On models without an explicit rate the tokens stay in the plain input bucket and the price is unchanged to the cent. The field is new enough that today's impact is $0 on that corpus. Codex sessions re-parse once and the daily cache re-derives once off the warm session cache (a global re-derivation of every day and every provider, since it has no per-provider invalidation); no other provider's numbers move. Days whose Codex transcripts have since aged out are held by the same never-lose guard #1040 relies on: a re-derivation that finds fewer calls than the settled baseline keeps the older, pre-fix (double-counted) total rather than truncating it, so those days do not pick up the repricing until their sources are re-derived with equal or greater evidence. Long-context pricing tiers from the same report are tracked separately in #1076 and the missing `gpt-5.6-codex` snapshot rows in #1077. Thanks @chr-evensen. (#1075) +- **Codex Tok/s no longer counts reasoning tokens twice.** #1075 fixed the same double-count for cost, but `activeGeneratedTokens`/`taskGeneratedTokens` in the Codex parser and `generatedTokens` in the `codex-tps` live-throughput reader still summed `outputTokens + reasoningTokens`, so the displayed Tok/s (and the dashboard's per-model `Tok/s` column) read high for every reasoning-heavy call — display only, no cost impact. All three sites now go through the same `billableOutputTokens('codex', …)` helper #1075 introduced, so the throughput numerator can never drift from the billed one. On a real 51,753-call Codex corpus, cost and every token count are unchanged to the last digit; Tok/s drops **20-42% depending on how reasoning-heavy the model is**: GPT-5.5 37.8 -> 28.1 tok/s (-25.7%), GPT-5.6 Sol 43.2 -> 33.8 (-21.6%), GPT-5.6 Luna 53.5 -> 30.9 (-42.3%), GPT-5.4 68.0 -> 43.6 (-35.9%). `activeGeneratedTokens`/`activeDurationMs`/`toolWaitMs` are stored verbatim in both the Codex result cache and the session cache rather than re-derived on read, so neither self-heals: Codex sessions re-parse once. (#1079) - **Codex calls attributed from session metadata no longer carry a stale model.** The Buffer fast path scanned `session_meta` for the first `"model"` string anywhere in the payload, so a nested `base_instructions.provenance.model` was read as if it were `payload.model` — and since the model is last-writer-wins state, that wrong value was credited to every call before the rollout's first `turn_context` and to every call after any mid-file `session_meta` (29 of 1380 rollouts on one real corpus carry a late `session_meta`, and 57 record usage before any `turn_context`). Direct payload fields are now read depth-aware, which is what the non-fast `JSON.parse` path always did. Codex sessions re-parse once (~9s on a 4 GB rollout corpus) and the daily cache re-derives once off the warm session cache, a global re-derivation of every day and every provider since it has no per-provider invalidation; it moves per-model attribution, and clears any rollup an earlier parse change had left stale. Days whose transcripts have partly aged out are held by the never-lose guard: on a real 110-day cache no day lost value and none disappeared — 100 days came back identical and 9 grok days rose by $19.80 in total. Thanks @timdp. (#1040) - **Codex `session_meta` cwd / session id / originator follow the same depth-1 window as `model`.** #1040 fixed nested `provenance.model`; the compact Buffer path still took the first `cwd`, `session_id`, `originator`, `name`, `forked_from_id` or `model_provider` anywhere in the payload, so a `dynamic_tools[].name` (or any same-named nested key) could steal the top-level field. Those strings now use the existing payload-depth-1 scan. Function-call `name` on other event types is unchanged. Codex sessions re-parse once. (#1045) - **Plan rows for sticker-price presets read as a budget instead of live provider quota.** There is no Grok quota endpoint, so a SuperGrok row was parsed API-equivalent spend divided by the plan's sticker price on a monthly reset — but the TUI labelled that math "plan" and "reset", which next to a client showing xAI's real weekly window read as CodeBurn being wrong. The bars and the arithmetic are unchanged; the words are not. Both the dashboard and the desktop app now say the number is an API-equivalent monthly budget and not a live provider window, in the same wording on both surfaces, and for every preset rather than as a SuperGrok special case. The window is anniversary-based (`plan.resetDay`, settable with `codeburn plan set --reset-day`), so it is called a budget reset rather than a calendar one. The row was also shortened to fit 80 columns: at that width the percentage and the projected month were being truncated away, including on custom plans, whose label carries the provider. diff --git a/src/codex-cache.ts b/src/codex-cache.ts index 70cc8e2b6..a8e93d9e2 100644 --- a/src/codex-cache.ts +++ b/src/codex-cache.ts @@ -27,7 +27,14 @@ import type { ParsedProviderCall } from './providers/types.js' // output, and cache_write_input_tokens is carved out of the input bucket. This // file stores each call's costUSD and token buckets verbatim, so entries // written by v10 carry the old (overstated) cost and must be re-derived. -export const CODEX_CACHE_VERSION = 11 +// v13: codex throughput fix (#1079) - activeGeneratedTokens was summing +// output + reasoning, the same double-count Fix A removed from cost. This +// file stores activeGeneratedTokens/activeDurationMs/toolWaitMs verbatim (not +// re-derived on read), so v11 entries carry the overstated numerator and must +// re-parse. Not 12: v12 is claimed by feat/core-extraction's own port of this +// throughput feature (PR #1086), so reusing it would let two incompatible +// schemas share a filename. +export const CODEX_CACHE_VERSION = 13 export const CODEX_LEGACY_CACHE_FILE = 'codex-results.json' export function codexCacheFileName(version = CODEX_CACHE_VERSION): string { return `codex-results.v${version}.json` diff --git a/src/codex-throughput.ts b/src/codex-throughput.ts index 4796206d9..f4b7ca958 100644 --- a/src/codex-throughput.ts +++ b/src/codex-throughput.ts @@ -1,6 +1,8 @@ import { open, stat } from 'node:fs/promises' import { StringDecoder } from 'node:string_decoder' +import { billableOutputTokens } from './models.js' + export type CodexThroughputPoint = { timestamp: string model?: string @@ -400,7 +402,9 @@ export class CodexThroughputReader { state.previousOutput = total?.output_tokens ?? state.previousOutput state.previousReasoning = total?.reasoning_output_tokens ?? state.previousReasoning } - const generatedTokens = outputTokens + reasoningTokens + // Reasoning is already inside output_tokens (#1075/#1078); same numerator + // as the cost path so live Tok/s can't drift from billed tokens (#1079). + const generatedTokens = billableOutputTokens('codex', outputTokens, reasoningTokens) if (generatedTokens <= 0) return const timestampMs = Date.parse(entry.timestamp) if (!Number.isFinite(timestampMs)) return diff --git a/src/parser.ts b/src/parser.ts index 43137d74d..071bde686 100644 --- a/src/parser.ts +++ b/src/parser.ts @@ -1768,7 +1768,7 @@ function buildSessionSummary( modelBreakdown[modelKey].tokens.reasoningTokens += call.usage.reasoningTokens if (call.activeDurationMs !== undefined) { modelBreakdown[modelKey].activeDurationMs = (modelBreakdown[modelKey].activeDurationMs ?? 0) + call.activeDurationMs - modelBreakdown[modelKey].activeGeneratedTokens = (modelBreakdown[modelKey].activeGeneratedTokens ?? 0) + (call.activeGeneratedTokens ?? call.usage.outputTokens + call.usage.reasoningTokens) + modelBreakdown[modelKey].activeGeneratedTokens = (modelBreakdown[modelKey].activeGeneratedTokens ?? 0) + (call.activeGeneratedTokens ?? billableOutputTokens(call.provider, call.usage.outputTokens, call.usage.reasoningTokens)) modelBreakdown[modelKey].toolWaitMs = (modelBreakdown[modelKey].toolWaitMs ?? 0) + (call.toolWaitMs ?? 0) } diff --git a/src/providers/codex.ts b/src/providers/codex.ts index 7693c7fac..8c735b7e5 100644 --- a/src/providers/codex.ts +++ b/src/providers/codex.ts @@ -879,7 +879,10 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { const activeMs = durationMs - toolWaitMs if (activeMs <= 0) continue for (const call of pendingTaskCalls) { - const generated = call.outputTokens + call.reasoningTokens + // Reasoning is already inside output_tokens (#1075/#1078); the + // throughput numerator must agree with the cost numerator or + // Tok/s reads high for reasoning-heavy calls (#1079). + const generated = billableOutputTokens('codex', call.outputTokens, call.reasoningTokens) if (generated <= 0) continue call.activeGeneratedTokens = generated call.activeDurationMs = activeMs * (generated / taskGeneratedTokens) @@ -1140,7 +1143,7 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { ...(pendingLocRemoved ? { locRemoved: pendingLocRemoved } : {}), ...(pendingEditFailed ? { editFailed: pendingEditFailed } : {}), }) - taskGeneratedTokens += outputTokens + reasoningTokens + taskGeneratedTokens += billableOutputTokens('codex', outputTokens, reasoningTokens) pendingTools = [] pendingToolSequence = [] diff --git a/src/session-cache.ts b/src/session-cache.ts index 3a5f9751d..91929290d 100644 --- a/src/session-cache.ts +++ b/src/session-cache.ts @@ -286,7 +286,11 @@ export const PROVIDER_PARSE_VERSIONS: Record = { // models with an explicit cache-write rate. The bucket move does NOT self-heal // on read (cached entries store the buckets, not the raw event), so cached // sessions must re-parse. - codex: 'mcp-attribution-v5-est-cost-active-timing-mcp-wait-rich-capture-v1-cross-provider-pr-v1-session-meta-model-v1-session-meta-fields-v1-codex-pricing-v1', + // codex-tps-v1 (#1079): activeGeneratedTokens summed output + reasoning, the + // same double-count codex-pricing-v1 removed from cost. Cached entries store + // activeGeneratedTokens/activeDurationMs/toolWaitMs verbatim (cachedCallToApiCall + // passes them through without recomputing), so this does NOT self-heal either. + codex: 'mcp-attribution-v5-est-cost-active-timing-mcp-wait-rich-capture-v1-cross-provider-pr-v1-session-meta-model-v1-session-meta-fields-v1-codex-pricing-v1-codex-tps-v1', cursor: 'composer-anchored-crediting-v1-est-cost', 'cursor-agent': 'workspaceless-transcript-v1', // source-provenance-v1 (#944): CLI sessions were misread as VS Code diff --git a/tests/codex-throughput.test.ts b/tests/codex-throughput.test.ts index 1e0fd4da7..fa4fb2b5b 100644 --- a/tests/codex-throughput.test.ts +++ b/tests/codex-throughput.test.ts @@ -21,8 +21,38 @@ describe('Codex throughput prototype', () => { 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') + // Reasoning is a subset of output_tokens (#1075/#1078), not additive: the + // checkpoints report output 80/40 and reasoning 20/10, so the generated + // numerator is output alone (80, then 40), matching the cost path. + expect(points[1]).toMatchObject({ generatedTokens: 40, elapsedSeconds: 5, generatedTokensPerSecond: 8, activeDurationSeconds: 7, activeGeneratedTokensPerSecond: (80 + 40) / 7, toolWaitSeconds: 3, model: 'gpt-5.6-sol' }) + expect(renderCodexThroughput(points, path)).toContain('17.1 generated tokens/sec') + }) + + it('REGRESSION (#1079): does not add reasoning tokens on top of output for Tok/s', async () => { + // Reasoning tokens are a SUBSET of output_tokens (#1075/#1078), not a + // separate bucket. A single checkpoint reporting output=60, reasoning=40 + // must drive Tok/s off 60, not 100 -- summing them would double-count 40 + // tokens that are already inside the 60. If this ever reverts to + // `outputTokens + reasoningTokens`, activeGeneratedTokensPerSecond becomes + // 10 (100 tokens / 10s) instead of 6 (60 tokens / 10s). + const dir = await mkdtemp(join(tmpdir(), 'codeburn-tps-regression-')) + 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.5' } }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:00.000Z', payload: { type: 'task_started' } }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-07-25T00:00:10.000Z', payload: { type: 'token_count', info: { last_token_usage: { output_tokens: 60, reasoning_output_tokens: 40 }, total_token_usage: { total_tokens: 100, output_tokens: 60, reasoning_output_tokens: 40 } } } }), + 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).toHaveLength(1) + expect(points[0]).toMatchObject({ + outputTokens: 60, + reasoningTokens: 40, + generatedTokens: 60, + taskGeneratedTokens: 60, + activeGeneratedTokensPerSecond: 6, + }) }) it('parses only appended complete lines while watching a growing rollout', async () => { @@ -36,7 +66,9 @@ describe('Codex throughput prototype', () => { 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 }) + // second checkpoint: output 4 + reasoning 1 -> billable numerator is 4 + // (reasoning already inside output_tokens), not the additive 5. + expect(points[1]).toMatchObject({ generatedTokens: 4, generatedTokensPerSecond: 4 }) }) it('ignores replayed pre-fork checkpoints before estimating new work', async () => { diff --git a/tests/providers/codex.test.ts b/tests/providers/codex.test.ts index 66613174a..37325fa22 100644 --- a/tests/providers/codex.test.ts +++ b/tests/providers/codex.test.ts @@ -722,7 +722,9 @@ describe('codex provider - JSONL parsing', () => { reasoningTokens: 20, tools: ['Bash'], activeDurationMs: 7000, - activeGeneratedTokens: 120, + // Reasoning (20) is a subset of output_tokens (100), not additive + // (#1075/#1078/#1079): the billable/throughput numerator is 100, not 120. + activeGeneratedTokens: 100, toolWaitMs: 3000, }) }) From c7e754d3c02257ec5d4d808d6662854e251334cc Mon Sep 17 00:00:00 2001 From: iamtoruk Date: Fri, 21 Aug 2026 15:29:14 -0700 Subject: [PATCH 2/3] fix(codex): exclude harness startup and fix partial-dedup timing in Tok/s Extends #1079 (reasoning double-count) with three more findings from an exactness pass over the same throughput path: - BUG-1: task_started fires before Codex assembles the request, so the gap to the first request-context event (turn_context, world_state, event_msg/user_message, or response_item/message) was counted as active model time. The active window now starts at that event instead. - BUG-2: a token_count event dropped by fork-replay dedup lost its tokens from the numerator while the task's real duration still spanned it in the denominator, understating Tok/s for a partially (not fully) deduped task. The active window is now scaled down by the dropped tokens' proportional share. - BUG-8: the tool-interval clip/merge/cap logic was duplicated between providers/codex.ts and codex-throughput.ts and had already drifted (task_complete only read a plain-number duration, unlike mcp_tool_call_end). Now one shared mergeToolIntervals, and task_complete's duration parses the same permissive forms. Cost and every token count remain byte-identical. activeGeneratedTokens/ activeDurationMs/toolWaitMs are stored verbatim in both Codex caches, so none of this self-heals -- but the CODEX_CACHE_VERSION 13 bump already shipped for #1079 covers the same fields, so no further bump is needed. Dashboard's per-model column keeps the "Tok/s" header (zero width slack at the standard layout, verified against a real test); the legend now spells out "Effective Tok/s" with a decode-speed disclaimer. --- CHANGELOG.md | 2 +- src/codex-throughput.ts | 7 ++- src/dashboard.tsx | 7 ++- src/providers/codex.ts | 81 ++++++++++++++++++++++++++++------- tests/providers/codex.test.ts | 74 ++++++++++++++++++++++++++++++++ 5 files changed, 152 insertions(+), 19 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 034eb6a68..553f1148d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -40,7 +40,7 @@ ### Fixed - **Mixed-version installs no longer thrash the Codex / Cursor / Antigravity result caches.** Daily and session caches already own a version-suffixed file so an old desktop binary and a newer CLI cannot clobber each other. The three per-provider result caches still used one unsuffixed filename with an internal version field, so a v10 and a v11 binary rewrote the same `codex-results.json` (and the Cursor / Antigravity siblings) on every run and each re-parsed its whole corpus. They now write `*-results.v.json` the same way the daily cache does. The unsuffixed file is left for older binaries; a matching-version copy is adopted once and never overwritten. (#1082) - **Codex spend no longer counts reasoning tokens twice, and cache writes are priced only where OpenAI actually charges for them.** OpenAI bills reasoning tokens as *part of* `output_tokens`, not on top of it — on a 1,396-rollout corpus all 134,316 events carrying a total satisfy `input + output == total` — but CodeBurn added `reasoning_output_tokens` to output when pricing a Codex call and again in the models, audit and per-model displays. Every Codex number was therefore too high: on that corpus **cost by $166.03 (3.5%)** and **displayed Output tokens by 34.6%** ($4,713.12 -> $4,547.09; 22.6M -> 16.8M output tokens). The raw `reasoningTokens` figure is unchanged and still reported on its own; only the double-count is gone. Both places that price a Codex call — the parser and the cache-rehydration re-price — now go through one shared `billableOutputTokens` helper, so a cold run and a warm run can never disagree. Separately, Codex's `cache_write_input_tokens` (new in codex PR #33454) was never read and cache-creation tokens were hardcoded to 0; they are now carved out of the uncached-input bucket and clamped so they can never exceed it. That carve-out happens **only on models whose pricing source publishes a real cache-write rate** — gpt-5.6 and its terra/sol/luna variants charge 1.25x input for a cache write, everything before it charges nothing extra — because CodeBurn fabricates a 1.25x rate when a source omits one, and charging that would have invented a surcharge on gpt-5.5, gpt-5.4, gpt-5.3-codex and gpt-5. On models without an explicit rate the tokens stay in the plain input bucket and the price is unchanged to the cent. The field is new enough that today's impact is $0 on that corpus. Codex sessions re-parse once and the daily cache re-derives once off the warm session cache (a global re-derivation of every day and every provider, since it has no per-provider invalidation); no other provider's numbers move. Days whose Codex transcripts have since aged out are held by the same never-lose guard #1040 relies on: a re-derivation that finds fewer calls than the settled baseline keeps the older, pre-fix (double-counted) total rather than truncating it, so those days do not pick up the repricing until their sources are re-derived with equal or greater evidence. Long-context pricing tiers from the same report are tracked separately in #1076 and the missing `gpt-5.6-codex` snapshot rows in #1077. Thanks @chr-evensen. (#1075) -- **Codex Tok/s no longer counts reasoning tokens twice.** #1075 fixed the same double-count for cost, but `activeGeneratedTokens`/`taskGeneratedTokens` in the Codex parser and `generatedTokens` in the `codex-tps` live-throughput reader still summed `outputTokens + reasoningTokens`, so the displayed Tok/s (and the dashboard's per-model `Tok/s` column) read high for every reasoning-heavy call — display only, no cost impact. All three sites now go through the same `billableOutputTokens('codex', …)` helper #1075 introduced, so the throughput numerator can never drift from the billed one. On a real 51,753-call Codex corpus, cost and every token count are unchanged to the last digit; Tok/s drops **20-42% depending on how reasoning-heavy the model is**: GPT-5.5 37.8 -> 28.1 tok/s (-25.7%), GPT-5.6 Sol 43.2 -> 33.8 (-21.6%), GPT-5.6 Luna 53.5 -> 30.9 (-42.3%), GPT-5.4 68.0 -> 43.6 (-35.9%). `activeGeneratedTokens`/`activeDurationMs`/`toolWaitMs` are stored verbatim in both the Codex result cache and the session cache rather than re-derived on read, so neither self-heals: Codex sessions re-parse once. (#1079) +- **Codex Tok/s no longer counts reasoning tokens twice, credits harness startup as model time, or lets a partially fork-deduped task shrink only its numerator.** Three separate distortions in the same metric, found and fixed together because they share the same cache-invalidation and test surface. (1) #1075 fixed the reasoning-token double-count for cost, but `activeGeneratedTokens`/`taskGeneratedTokens` in the Codex parser and `generatedTokens` in the `codex-tps` live-throughput reader still summed `outputTokens + reasoningTokens`; both now go through the same `billableOutputTokens('codex', …)` helper #1075 introduced, so the numerator can never drift from the billed one. (2) Codex fires `task_started` before it assembles the request, so the gap up to the first request-context event (`turn_context`, `world_state`, `event_msg/user_message`, or a `response_item/message`) was pure CLI/harness startup counted as active model time — the active window now starts at that first event instead, which matters most for one-shot `codex exec` sessions that pay the gap on every task (GPT-5.6 Luna's active window shrank 8s->less on this corpus). (3) A `token_count` event dropped by fork-replay dedup (`seenKeys`) lost its tokens from the numerator while the task's real wall-clock duration still spanned it in the denominator, understating Tok/s for any task with SOME but not all events deduped (a fully-replayed task was already excluded by the existing `taskGeneratedTokens === 0` guard); the active window is now scaled down by the dropped tokens' proportional share instead. The duplicated tool-interval clip/merge/cap logic in `providers/codex.ts` and `codex-throughput.ts` is now one function (`mergeToolIntervals`, exported from `codex-throughput.ts`), which also closes a live trap where `task_complete`'s duration only parsed a plain number and silently dropped the `{secs,nanos}`/string forms `mcp_tool_call_end` already tolerated. Display only, no cost or token-count impact — verified byte-identical on the same real corpus. Combined effect on a real Codex corpus (original bug -> all fixes): GPT-5.5 37.8 -> 28.2 tok/s (-25.5%), Codex Auto Review 23.3 -> 20.0 (-14.2%), GPT-5.6 Sol 43.2 -> 33.9 (-21.4%), GPT-5.6 Luna 53.5 -> 49.0 (-8.5%), GPT-5.4 68.0 -> 43.6 (-35.9%), GPT-5.4 Mini 54.9 -> 55.6 (**+1.1%**, the harness-startup correction outweighing the reasoning-count correction for this model on this corpus). The partial-dedup fix is real and unit-tested but measured zero effect on this corpus — only 29 of thousands of session files are forks. `activeGeneratedTokens`/`activeDurationMs`/`toolWaitMs` are stored verbatim in both the Codex result cache and the session cache rather than re-derived on read, so none of this self-heals: Codex sessions re-parse once (one cache-version bump covers all three fixes, since they touch the same fields). The dashboard's per-model column stays labelled `Tok/s` — a wider label had zero room at the standard three-column layout, verified by breaking a real width-budget test — but the legend beneath it now reads "Effective Tok/s: generated tokens ÷ time the agent spent waiting on the model, tool execution excluded. Includes prefill, request assembly and reasoning. Not comparable to vendor decode-speed figures." (#1079, #1088) - **Codex calls attributed from session metadata no longer carry a stale model.** The Buffer fast path scanned `session_meta` for the first `"model"` string anywhere in the payload, so a nested `base_instructions.provenance.model` was read as if it were `payload.model` — and since the model is last-writer-wins state, that wrong value was credited to every call before the rollout's first `turn_context` and to every call after any mid-file `session_meta` (29 of 1380 rollouts on one real corpus carry a late `session_meta`, and 57 record usage before any `turn_context`). Direct payload fields are now read depth-aware, which is what the non-fast `JSON.parse` path always did. Codex sessions re-parse once (~9s on a 4 GB rollout corpus) and the daily cache re-derives once off the warm session cache, a global re-derivation of every day and every provider since it has no per-provider invalidation; it moves per-model attribution, and clears any rollup an earlier parse change had left stale. Days whose transcripts have partly aged out are held by the never-lose guard: on a real 110-day cache no day lost value and none disappeared — 100 days came back identical and 9 grok days rose by $19.80 in total. Thanks @timdp. (#1040) - **Codex `session_meta` cwd / session id / originator follow the same depth-1 window as `model`.** #1040 fixed nested `provenance.model`; the compact Buffer path still took the first `cwd`, `session_id`, `originator`, `name`, `forked_from_id` or `model_provider` anywhere in the payload, so a `dynamic_tools[].name` (or any same-named nested key) could steal the top-level field. Those strings now use the existing payload-depth-1 scan. Function-call `name` on other event types is unchanged. Codex sessions re-parse once. (#1045) - **Plan rows for sticker-price presets read as a budget instead of live provider quota.** There is no Grok quota endpoint, so a SuperGrok row was parsed API-equivalent spend divided by the plan's sticker price on a monthly reset — but the TUI labelled that math "plan" and "reset", which next to a client showing xAI's real weekly window read as CodeBurn being wrong. The bars and the arithmetic are unchanged; the words are not. Both the dashboard and the desktop app now say the number is an API-equivalent monthly budget and not a live provider window, in the same wording on both surfaces, and for every preset rather than as a SuperGrok special case. The window is anniversary-based (`plan.resetDay`, settable with `codeburn plan set --reset-day`), so it is called a budget reset rather than a calendar one. The row was also shortened to fit 80 columns: at that width the percentage and the projected month were being truncated away, including on custom plans, whose label carries the provider. diff --git a/src/codex-throughput.ts b/src/codex-throughput.ts index f4b7ca958..6bdb15835 100644 --- a/src/codex-throughput.ts +++ b/src/codex-throughput.ts @@ -107,7 +107,12 @@ function durationMs(payload: RolloutLine['payload']): number | undefined { return undefined } -function mergeToolIntervals(intervals: Array<[number, number]>, durationMs: number, taskStartedAt?: number, taskCompletedAt?: number): number { +// Shared with src/providers/codex.ts (#1088 BUG-8): both clip a task's tool +// intervals to its [taskStartedAt, taskStartedAt + durationMs] window, merge +// overlaps, and cap the sum at durationMs. Was copy-pasted inline in +// providers/codex.ts and had already drifted (duration parsing there accepted +// only a plain `duration_ms` number); one copy now, called from both. +export function mergeToolIntervals(intervals: Array<[number, number]>, durationMs: number, taskStartedAt?: number, taskCompletedAt?: number): number { const windowStart = taskStartedAt ?? (taskCompletedAt !== undefined ? taskCompletedAt - durationMs : undefined) const windowEnd = windowStart !== undefined ? windowStart + durationMs : undefined const clipped = intervals.map(([start, end]) => [ diff --git a/src/dashboard.tsx b/src/dashboard.tsx index 531836f38..0d8bf32e5 100644 --- a/src/dashboard.tsx +++ b/src/dashboard.tsx @@ -746,6 +746,11 @@ function ModelBreakdown({ projects, pw, bw }: { projects: ProjectSummary[]; pw: const anyEstimated = Object.values(modelTotals).some(d => d.estimatedCostUSD > 0) const sorted = Object.entries(modelTotals).sort(([, a], [, b]) => b.costUSD - a.costUSD) const costLabels = sorted.map(([, data]) => markEstimated(formatCost(data.costUSD), data.estimatedCostUSD > 0)) + // #1088: this column has zero width slack left at the standard 3-column + // breakpoint (verified: widening the header even one character clips + // 'cache'/'1-shot' and drops the value column entirely), so the header stays + // "Tok/s" -- the legend below carries the "Effective Tok/s" framing and the + // caveat that it is not a vendor decode-speed figure. const headers = ['cost', 'cache', 'calls', '1-shot', 'Tok/s'] const values = sorted.map(([model, data], index) => { const totalInput = data.freshInput + data.cacheRead + data.cacheWrite @@ -806,7 +811,7 @@ function ModelBreakdown({ projects, pw, bw }: { projects: ProjectSummary[]; pw: {anyEstimated && ( ~ estimated cost (priced from estimated tokens) )} - ~ Tok/s: generated tokens / active time; tool wait excluded + ~ Effective Tok/s: generated tokens ÷ time the agent spent waiting on the model, tool execution excluded. Includes prefill, request assembly and reasoning. Not comparable to vendor decode-speed figures. ) } diff --git a/src/providers/codex.ts b/src/providers/codex.ts index 8c735b7e5..8eebb4afa 100644 --- a/src/providers/codex.ts +++ b/src/providers/codex.ts @@ -7,6 +7,7 @@ import { homedir } from 'os' import { readSessionLines } from '../fs-utils.js' import { billableOutputTokens, calculateCost, getModelCosts } from '../models.js' import { readCachedCodexResults, writeCachedCodexResults, getCachedCodexProject, fingerprintFile, type CodexFileFingerprint } from '../codex-cache.js' +import { mergeToolIntervals } from '../codex-throughput.js' import { normalizeContentBlocks } from '../content-utils.js' import { estimateTokensFromChars } from '../token-estimate.js' import type { ToolCall } from '../types.js' @@ -612,6 +613,12 @@ type CodexResumeState = { turnCounter: number currentTurnId: string taskStartedAt?: number + // #1088 BUG-1: timestamp of the first request-context event (turn_context, + // world_state, event_msg/user_message, or response_item/message) seen since + // the last task_started. Codex fires task_started before it assembles the + // request, so the gap up to this event is CLI/harness startup, not model + // wait -- the active window for Tok/s starts here, not at task_started. + taskActiveStartedAt?: number } // The state comes back off our own JSON cache; a truncated or hand-edited file @@ -718,8 +725,13 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { // Bounded by one task's calls; flushed at the next task_started and at EOF. let pendingTaskCalls: ParsedProviderCall[] = [] let taskGeneratedTokens = 0 + // #1088 BUG-2: tokens from token_count events dropped by fork-replay + // dedup within the current (not-yet-completed) task. See the dedup site + // below for why this must offset the active-time window at task_complete. + let taskDedupedTokens = 0 let taskToolIntervals: Array<[number, number]> = [] let taskStartedAt: number | undefined = resume?.state.taskStartedAt + let taskActiveStartedAt: number | undefined = resume?.state.taskActiveStartedAt const openToolStarts = new Map() // Resume point for the NEXT run, refreshed at every task boundary. @@ -763,6 +775,22 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { continue } + // #1088 BUG-1: the first request-context event since task_started marks + // where model-request assembly actually began. Checked before any of + // these types `continue` below, and unconditionally (like turn_context's + // model capture above) so a forked replay's own request-context events + // still mark it -- matching how those events are already read regardless + // of isForkReplay, which only filters task boundaries and tool events. + if (taskActiveStartedAt === undefined && ( + entry.type === 'turn_context' + || entry.type === 'world_state' + || (entry.type === 'event_msg' && entry.payload?.type === 'user_message') + || (entry.type === 'response_item' && entry.payload?.type === 'message') + )) { + const ctxAt = entry.timestamp ? Date.parse(entry.timestamp) : NaN + if (Number.isFinite(ctxAt)) taskActiveStartedAt = ctxAt + } + if (entry.type === 'turn_context' && typeof entry.payload?.model === 'string') { sessionModel = entry.payload.model continue @@ -786,9 +814,11 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { results.push(...pendingTaskCalls) pendingTaskCalls = [] taskGeneratedTokens = 0 + taskDedupedTokens = 0 taskToolIntervals = [] const startedAt = entry.timestamp ? Date.parse(entry.timestamp) : NaN taskStartedAt = Number.isFinite(startedAt) ? startedAt : undefined + taskActiveStartedAt = undefined openToolStarts.clear() // Everything decoded so far is now in `results` and the per-task // accumulators are empty: a clean restart point for an appended tail. @@ -817,6 +847,7 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { turnCounter, currentTurnId, ...(taskStartedAt !== undefined ? { taskStartedAt } : {}), + ...(taskActiveStartedAt !== undefined ? { taskActiveStartedAt } : {}), } continue } @@ -860,23 +891,33 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { } if (entry.type === 'event_msg' && entry.payload?.type === 'task_complete') { - const durationMs = entry.payload.duration_ms + // #1088 BUG-8: task_complete's duration can arrive as {secs,nanos} or + // a string too (mcp_tool_call_end already tolerates both, below, via + // this same durationValueMs helper); read it the same permissive way + // instead of only the plain-number `duration_ms` field. + const durationMs = durationValueMs(entry.payload.duration_ms) ?? durationValueMs(entry.payload.duration) if (typeof durationMs === 'number' && durationMs > 0 && taskGeneratedTokens > 0 && pendingTaskCalls.length > 0) { const completedAt = entry.timestamp ? Date.parse(entry.timestamp) : NaN - const windowStart = taskStartedAt ?? (Number.isFinite(completedAt) ? completedAt - durationMs : undefined) - const windowEnd = windowStart !== undefined ? windowStart + durationMs : undefined - const clipped = taskToolIntervals.map(([start, end]) => [ - windowStart !== undefined ? Math.max(start, windowStart) : start, - windowEnd !== undefined ? Math.min(end, windowEnd) : end, - ] as [number, number]).filter(([start, end]) => end > start) - const merged = clipped.sort((a, b) => a[0] - b[0]).reduce>((acc, interval) => { - const previous = acc.at(-1) - if (previous && interval[0] <= previous[1]) previous[1] = Math.max(previous[1], interval[1]) - else acc.push([...interval]) - return acc - }, []) - const toolWaitMs = Math.min(durationMs, merged.reduce((sum, interval) => sum + interval[1] - interval[0], 0)) - const activeMs = durationMs - toolWaitMs + // #1088 BUG-1: Codex fires task_started before it assembles the + // request, so the gap up to the first request-context event is + // CLI/harness startup, not model wait. The active window starts + // there instead of at task_started; task completion (windowEnd, + // inside mergeToolIntervals) is unchanged. + const activeWindowStart = taskActiveStartedAt ?? taskStartedAt + const startupGapMs = activeWindowStart !== undefined && taskStartedAt !== undefined + ? activeWindowStart - taskStartedAt + : 0 + const effectiveDurationMs = Math.max(0, durationMs - startupGapMs) + // #1088 BUG-8: shared with codex-throughput.ts's live estimate + // instead of a second inline copy of the same clip/merge/cap. + const toolWaitMs = mergeToolIntervals(taskToolIntervals, effectiveDurationMs, activeWindowStart, Number.isFinite(completedAt) ? completedAt : undefined) + // #1088 BUG-2: a partially fork-deduped task's active window still + // spans the dropped events' real time even though their tokens + // never reached taskGeneratedTokens (see the dedup site above). + // Shrink the window by the dropped fraction so surviving calls + // aren't credited with time that covers discarded work. + const totalTaskTokens = taskGeneratedTokens + taskDedupedTokens + const activeMs = (effectiveDurationMs - toolWaitMs) * (taskGeneratedTokens / totalTaskTokens) if (activeMs <= 0) continue for (const call of pendingTaskCalls) { // Reasoning is already inside output_tokens (#1075/#1078); the @@ -1102,7 +1143,15 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { // key would spuriously diverge on a replay and double-count it. const dedupKey = `codex:${forkedFromId || sessionId}:${cumulativeTotal}:${total?.input_tokens ?? 0}:${total?.cached_input_tokens ?? 0}:${total?.output_tokens ?? 0}:${total?.reasoning_output_tokens ?? 0}` - if (seenKeys.has(dedupKey)) continue + if (seenKeys.has(dedupKey)) { + // #1088 BUG-2: this event's tokens are dropped from the numerator, + // but task_complete's duration_ms is real wall-clock time that + // still spans them -- track what was dropped so the active window + // can be scaled down to match, instead of crediting the surviving + // calls with time that covers work whose tokens were discarded. + taskDedupedTokens += billableOutputTokens('codex', outputTokens, reasoningTokens) + continue + } seenKeys.add(dedupKey) // Reasoning tokens are already inside output_tokens, so they are NOT diff --git a/tests/providers/codex.test.ts b/tests/providers/codex.test.ts index 37325fa22..cfd01c507 100644 --- a/tests/providers/codex.test.ts +++ b/tests/providers/codex.test.ts @@ -729,6 +729,80 @@ describe('codex provider - JSONL parsing', () => { }) }) + it('REGRESSION (#1088 BUG-1): excludes the task_started -> first request-context gap from active time', async () => { + // Codex fires task_started before it assembles the request; the 7s gap to + // the first request-context event (here, the user message) is CLI/harness + // startup, not model wait, and must not count toward active time. If this + // ever reverts to windowStart = taskStartedAt, activeDurationMs becomes + // 20000 (the full duration_ms) instead of 13000 (20000 - the 7s gap). + const filePath = await writeSession(tmpDir, '2026-04-14', 'rollout-startup-gap.jsonl', [ + sessionMeta({ session_id: 'sess-startup-gap', model: 'gpt-5.5' }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:00Z', payload: { type: 'task_started' } }), + userMessage('run the tool', '2026-04-14T10:00:07Z'), + tokenCount({ timestamp: '2026-04-14T10:00:20Z', last: { output: 100 }, total: { output: 100, total: 100 } }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:20Z', payload: { type: 'task_complete', duration_ms: 20_000 } }), + ]) + + const provider = createCodexProvider(tmpDir) + const source = { path: filePath, project: 'test', provider: 'codex' } + const calls: ParsedProviderCall[] = [] + for await (const call of provider.createSessionParser(source, new Set()).parse()) calls.push(call) + + expect(calls).toHaveLength(1) + expect(calls[0]).toMatchObject({ activeGeneratedTokens: 100, activeDurationMs: 13_000, toolWaitMs: 0 }) + }) + + it('REGRESSION (#1088 BUG-2): a partially fork-deduped task rate matches the undeduped rate', async () => { + // Two checkpoints generate 50 tokens each over a 10s task with no tool + // calls; the first is pre-marked as already-seen (as a fork replay would + // collide it) so only the second reaches pendingTaskCalls. The task's + // real active time (10s) still spans both checkpoints' work, so the + // survivor must be credited with only its proportional share (5s), not + // the full 10s -- giving 50 tokens / 5s = 10 tok/s, the same rate as if + // neither checkpoint had been deduped (100 tokens / 10s). If this ever + // reverts to crediting the full window, it reads 50 tokens / 10s = 5 tok/s. + const dedupedKey = 'codex:sess-dedup:50:0:0:50:0' + const filePath = await writeSession(tmpDir, '2026-04-14', 'rollout-partial-dedup.jsonl', [ + sessionMeta({ session_id: 'sess-dedup', model: 'gpt-5.5' }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:00Z', payload: { type: 'task_started' } }), + userMessage('run the tool', '2026-04-14T10:00:00Z'), + tokenCount({ timestamp: '2026-04-14T10:00:04Z', last: { output: 50 }, total: { output: 50, total: 50 } }), + tokenCount({ timestamp: '2026-04-14T10:00:08Z', last: { output: 50 }, total: { output: 100, total: 100 } }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:10Z', payload: { type: 'task_complete', duration_ms: 10_000 } }), + ]) + + const provider = createCodexProvider(tmpDir) + const source = { path: filePath, project: 'test', provider: 'codex' } + const seenKeys = new Set([dedupedKey]) + const calls: ParsedProviderCall[] = [] + for await (const call of provider.createSessionParser(source, seenKeys).parse()) calls.push(call) + + expect(calls).toHaveLength(1) + expect(calls[0]).toMatchObject({ outputTokens: 50, activeGeneratedTokens: 50, activeDurationMs: 5_000 }) + }) + + it('#1088 BUG-8: reads a task_complete duration reported as {secs,nanos}, not only a plain number', async () => { + // mcp_tool_call_end already tolerates {secs,nanos} and string durations + // (durationValueMs); task_complete only read the plain-number duration_ms + // field, so a task_complete reported the object form was silently dropped + // (no active timing at all) instead of parsed. + const filePath = await writeSession(tmpDir, '2026-04-14', 'rollout-object-duration.jsonl', [ + sessionMeta({ session_id: 'sess-object-duration', model: 'gpt-5.5' }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:00Z', payload: { type: 'task_started' } }), + userMessage('run the tool', '2026-04-14T10:00:00Z'), + tokenCount({ timestamp: '2026-04-14T10:00:10Z', last: { output: 100 }, total: { output: 100, total: 100 } }), + JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:10Z', payload: { type: 'task_complete', duration: { secs: 10, nanos: 0 } } }), + ]) + + const provider = createCodexProvider(tmpDir) + const source = { path: filePath, project: 'test', provider: 'codex' } + const calls: ParsedProviderCall[] = [] + for await (const call of provider.createSessionParser(source, new Set()).parse()) calls.push(call) + + expect(calls).toHaveLength(1) + expect(calls[0]).toMatchObject({ activeGeneratedTokens: 100, activeDurationMs: 10_000 }) + }) + it('keeps estimated output parsing for large token lines without usage info', async () => { // Some rollout variants put token_count metadata beyond the compact head // or omit `info` entirely. The line must still reach the character-based From fa8c008f71a661ad16f4a36fbd1fdc56e9649bed Mon Sep 17 00:00:00 2001 From: iamtoruk Date: Fri, 21 Aug 2026 15:37:57 -0700 Subject: [PATCH 3/3] revert(codex): retract the BUG-2 partial-dedup timing fix Re-instrumenting this exact head over the full corpus traced the original 12.5%/46% figures to a replication gap: the earlier prevCumulativeTotal guard (codex.ts) already discards any token_count event whose running total exactly repeats the previous kept one, so a drop at the seenKeys dedup site is always a byte-identical replay of already-counted tokens -- never a real loss. The condition BUG-2's fix guarded against does not occur in real Codex output. Removes taskDedupedTokens, its increment at the dedup site, the active-time scaling at task_complete, and the now-unexercisable unit test (its fixture forces a dedup collision that is not also a cumulative-total repeat, a state the real writer never produces). The dedup site keeps a short comment recording why no rescaling is needed, so the next investigator doesn't retrace this. Keeps: the reasoning double-count fix, the harness-startup exclusion (BUG-1, confirmed to the decimal), the shared mergeToolIntervals helper and permissive duration parsing (BUG-8), and the legend rename. The real-corpus table is unchanged -- BUG-2 measured zero effect on it before this revert too. --- CHANGELOG.md | 2 +- src/providers/codex.ts | 27 ++++++--------------------- tests/providers/codex.test.ts | 29 ----------------------------- 3 files changed, 7 insertions(+), 51 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 553f1148d..e27dced35 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -40,7 +40,7 @@ ### Fixed - **Mixed-version installs no longer thrash the Codex / Cursor / Antigravity result caches.** Daily and session caches already own a version-suffixed file so an old desktop binary and a newer CLI cannot clobber each other. The three per-provider result caches still used one unsuffixed filename with an internal version field, so a v10 and a v11 binary rewrote the same `codex-results.json` (and the Cursor / Antigravity siblings) on every run and each re-parsed its whole corpus. They now write `*-results.v.json` the same way the daily cache does. The unsuffixed file is left for older binaries; a matching-version copy is adopted once and never overwritten. (#1082) - **Codex spend no longer counts reasoning tokens twice, and cache writes are priced only where OpenAI actually charges for them.** OpenAI bills reasoning tokens as *part of* `output_tokens`, not on top of it — on a 1,396-rollout corpus all 134,316 events carrying a total satisfy `input + output == total` — but CodeBurn added `reasoning_output_tokens` to output when pricing a Codex call and again in the models, audit and per-model displays. Every Codex number was therefore too high: on that corpus **cost by $166.03 (3.5%)** and **displayed Output tokens by 34.6%** ($4,713.12 -> $4,547.09; 22.6M -> 16.8M output tokens). The raw `reasoningTokens` figure is unchanged and still reported on its own; only the double-count is gone. Both places that price a Codex call — the parser and the cache-rehydration re-price — now go through one shared `billableOutputTokens` helper, so a cold run and a warm run can never disagree. Separately, Codex's `cache_write_input_tokens` (new in codex PR #33454) was never read and cache-creation tokens were hardcoded to 0; they are now carved out of the uncached-input bucket and clamped so they can never exceed it. That carve-out happens **only on models whose pricing source publishes a real cache-write rate** — gpt-5.6 and its terra/sol/luna variants charge 1.25x input for a cache write, everything before it charges nothing extra — because CodeBurn fabricates a 1.25x rate when a source omits one, and charging that would have invented a surcharge on gpt-5.5, gpt-5.4, gpt-5.3-codex and gpt-5. On models without an explicit rate the tokens stay in the plain input bucket and the price is unchanged to the cent. The field is new enough that today's impact is $0 on that corpus. Codex sessions re-parse once and the daily cache re-derives once off the warm session cache (a global re-derivation of every day and every provider, since it has no per-provider invalidation); no other provider's numbers move. Days whose Codex transcripts have since aged out are held by the same never-lose guard #1040 relies on: a re-derivation that finds fewer calls than the settled baseline keeps the older, pre-fix (double-counted) total rather than truncating it, so those days do not pick up the repricing until their sources are re-derived with equal or greater evidence. Long-context pricing tiers from the same report are tracked separately in #1076 and the missing `gpt-5.6-codex` snapshot rows in #1077. Thanks @chr-evensen. (#1075) -- **Codex Tok/s no longer counts reasoning tokens twice, credits harness startup as model time, or lets a partially fork-deduped task shrink only its numerator.** Three separate distortions in the same metric, found and fixed together because they share the same cache-invalidation and test surface. (1) #1075 fixed the reasoning-token double-count for cost, but `activeGeneratedTokens`/`taskGeneratedTokens` in the Codex parser and `generatedTokens` in the `codex-tps` live-throughput reader still summed `outputTokens + reasoningTokens`; both now go through the same `billableOutputTokens('codex', …)` helper #1075 introduced, so the numerator can never drift from the billed one. (2) Codex fires `task_started` before it assembles the request, so the gap up to the first request-context event (`turn_context`, `world_state`, `event_msg/user_message`, or a `response_item/message`) was pure CLI/harness startup counted as active model time — the active window now starts at that first event instead, which matters most for one-shot `codex exec` sessions that pay the gap on every task (GPT-5.6 Luna's active window shrank 8s->less on this corpus). (3) A `token_count` event dropped by fork-replay dedup (`seenKeys`) lost its tokens from the numerator while the task's real wall-clock duration still spanned it in the denominator, understating Tok/s for any task with SOME but not all events deduped (a fully-replayed task was already excluded by the existing `taskGeneratedTokens === 0` guard); the active window is now scaled down by the dropped tokens' proportional share instead. The duplicated tool-interval clip/merge/cap logic in `providers/codex.ts` and `codex-throughput.ts` is now one function (`mergeToolIntervals`, exported from `codex-throughput.ts`), which also closes a live trap where `task_complete`'s duration only parsed a plain number and silently dropped the `{secs,nanos}`/string forms `mcp_tool_call_end` already tolerated. Display only, no cost or token-count impact — verified byte-identical on the same real corpus. Combined effect on a real Codex corpus (original bug -> all fixes): GPT-5.5 37.8 -> 28.2 tok/s (-25.5%), Codex Auto Review 23.3 -> 20.0 (-14.2%), GPT-5.6 Sol 43.2 -> 33.9 (-21.4%), GPT-5.6 Luna 53.5 -> 49.0 (-8.5%), GPT-5.4 68.0 -> 43.6 (-35.9%), GPT-5.4 Mini 54.9 -> 55.6 (**+1.1%**, the harness-startup correction outweighing the reasoning-count correction for this model on this corpus). The partial-dedup fix is real and unit-tested but measured zero effect on this corpus — only 29 of thousands of session files are forks. `activeGeneratedTokens`/`activeDurationMs`/`toolWaitMs` are stored verbatim in both the Codex result cache and the session cache rather than re-derived on read, so none of this self-heals: Codex sessions re-parse once (one cache-version bump covers all three fixes, since they touch the same fields). The dashboard's per-model column stays labelled `Tok/s` — a wider label had zero room at the standard three-column layout, verified by breaking a real width-budget test — but the legend beneath it now reads "Effective Tok/s: generated tokens ÷ time the agent spent waiting on the model, tool execution excluded. Includes prefill, request assembly and reasoning. Not comparable to vendor decode-speed figures." (#1079, #1088) +- **Codex Tok/s no longer counts reasoning tokens twice or credits harness startup as model time.** Two distortions in the same metric, found and fixed together because they share the same cache-invalidation and test surface. (1) #1075 fixed the reasoning-token double-count for cost, but `activeGeneratedTokens`/`taskGeneratedTokens` in the Codex parser and `generatedTokens` in the `codex-tps` live-throughput reader still summed `outputTokens + reasoningTokens`; both now go through the same `billableOutputTokens('codex', …)` helper #1075 introduced, so the numerator can never drift from the billed one. (2) Codex fires `task_started` before it assembles the request, so the gap up to the first request-context event (`turn_context`, `world_state`, `event_msg/user_message`, or a `response_item/message`) was pure CLI/harness startup counted as active model time — the active window now starts at that first event instead, which matters most for one-shot `codex exec` sessions that pay the gap on every task. The duplicated tool-interval clip/merge/cap logic in `providers/codex.ts` and `codex-throughput.ts` is now one function (`mergeToolIntervals`, exported from `codex-throughput.ts`), which also closes a live trap where `task_complete`'s duration only parsed a plain number and silently dropped the `{secs,nanos}`/string forms `mcp_tool_call_end` already tolerated. (A third suspected distortion — fork-replay dedup dropping a token_count event's tokens from the numerator without shrinking the window to match — was investigated and retracted: the earlier `prevCumulativeTotal` guard already discards a repeated running total before dedup is ever reached, so a real Codex writer never produces a partial drop; the dedup site now carries a comment recording this so the trip isn't repeated.) Display only, no cost or token-count impact — verified byte-identical on the same real corpus. Combined effect on a real Codex corpus (original bug -> all fixes): GPT-5.5 37.8 -> 28.2 tok/s (-25.5%), Codex Auto Review 23.3 -> 20.0 (-14.2%), GPT-5.6 Sol 43.2 -> 33.9 (-21.4%), GPT-5.6 Luna 53.5 -> 49.0 (-8.5%), GPT-5.4 68.0 -> 43.6 (-35.9%), GPT-5.4 Mini 54.9 -> 55.6 (**+1.1%**, the harness-startup correction outweighing the reasoning-count correction for this model on this corpus). `activeGeneratedTokens`/`activeDurationMs`/`toolWaitMs` are stored verbatim in both the Codex result cache and the session cache rather than re-derived on read, so none of this self-heals: Codex sessions re-parse once (one cache-version bump covers both fixes, since they touch the same fields). The dashboard's per-model column stays labelled `Tok/s` — a wider label had zero room at the standard three-column layout, verified by breaking a real width-budget test — but the legend beneath it now reads "Effective Tok/s: generated tokens ÷ time the agent spent waiting on the model, tool execution excluded. Includes prefill, request assembly and reasoning. Not comparable to vendor decode-speed figures." (#1079, #1088) - **Codex calls attributed from session metadata no longer carry a stale model.** The Buffer fast path scanned `session_meta` for the first `"model"` string anywhere in the payload, so a nested `base_instructions.provenance.model` was read as if it were `payload.model` — and since the model is last-writer-wins state, that wrong value was credited to every call before the rollout's first `turn_context` and to every call after any mid-file `session_meta` (29 of 1380 rollouts on one real corpus carry a late `session_meta`, and 57 record usage before any `turn_context`). Direct payload fields are now read depth-aware, which is what the non-fast `JSON.parse` path always did. Codex sessions re-parse once (~9s on a 4 GB rollout corpus) and the daily cache re-derives once off the warm session cache, a global re-derivation of every day and every provider since it has no per-provider invalidation; it moves per-model attribution, and clears any rollup an earlier parse change had left stale. Days whose transcripts have partly aged out are held by the never-lose guard: on a real 110-day cache no day lost value and none disappeared — 100 days came back identical and 9 grok days rose by $19.80 in total. Thanks @timdp. (#1040) - **Codex `session_meta` cwd / session id / originator follow the same depth-1 window as `model`.** #1040 fixed nested `provenance.model`; the compact Buffer path still took the first `cwd`, `session_id`, `originator`, `name`, `forked_from_id` or `model_provider` anywhere in the payload, so a `dynamic_tools[].name` (or any same-named nested key) could steal the top-level field. Those strings now use the existing payload-depth-1 scan. Function-call `name` on other event types is unchanged. Codex sessions re-parse once. (#1045) - **Plan rows for sticker-price presets read as a budget instead of live provider quota.** There is no Grok quota endpoint, so a SuperGrok row was parsed API-equivalent spend divided by the plan's sticker price on a monthly reset — but the TUI labelled that math "plan" and "reset", which next to a client showing xAI's real weekly window read as CodeBurn being wrong. The bars and the arithmetic are unchanged; the words are not. Both the dashboard and the desktop app now say the number is an API-equivalent monthly budget and not a live provider window, in the same wording on both surfaces, and for every preset rather than as a SuperGrok special case. The window is anniversary-based (`plan.resetDay`, settable with `codeburn plan set --reset-day`), so it is called a budget reset rather than a calendar one. The row was also shortened to fit 80 columns: at that width the percentage and the projected month were being truncated away, including on custom plans, whose label carries the provider. diff --git a/src/providers/codex.ts b/src/providers/codex.ts index 8eebb4afa..e6aafe851 100644 --- a/src/providers/codex.ts +++ b/src/providers/codex.ts @@ -725,10 +725,6 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { // Bounded by one task's calls; flushed at the next task_started and at EOF. let pendingTaskCalls: ParsedProviderCall[] = [] let taskGeneratedTokens = 0 - // #1088 BUG-2: tokens from token_count events dropped by fork-replay - // dedup within the current (not-yet-completed) task. See the dedup site - // below for why this must offset the active-time window at task_complete. - let taskDedupedTokens = 0 let taskToolIntervals: Array<[number, number]> = [] let taskStartedAt: number | undefined = resume?.state.taskStartedAt let taskActiveStartedAt: number | undefined = resume?.state.taskActiveStartedAt @@ -814,7 +810,6 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { results.push(...pendingTaskCalls) pendingTaskCalls = [] taskGeneratedTokens = 0 - taskDedupedTokens = 0 taskToolIntervals = [] const startedAt = entry.timestamp ? Date.parse(entry.timestamp) : NaN taskStartedAt = Number.isFinite(startedAt) ? startedAt : undefined @@ -911,13 +906,7 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { // #1088 BUG-8: shared with codex-throughput.ts's live estimate // instead of a second inline copy of the same clip/merge/cap. const toolWaitMs = mergeToolIntervals(taskToolIntervals, effectiveDurationMs, activeWindowStart, Number.isFinite(completedAt) ? completedAt : undefined) - // #1088 BUG-2: a partially fork-deduped task's active window still - // spans the dropped events' real time even though their tokens - // never reached taskGeneratedTokens (see the dedup site above). - // Shrink the window by the dropped fraction so surviving calls - // aren't credited with time that covers discarded work. - const totalTaskTokens = taskGeneratedTokens + taskDedupedTokens - const activeMs = (effectiveDurationMs - toolWaitMs) * (taskGeneratedTokens / totalTaskTokens) + const activeMs = effectiveDurationMs - toolWaitMs if (activeMs <= 0) continue for (const call of pendingTaskCalls) { // Reasoning is already inside output_tokens (#1075/#1078); the @@ -1143,15 +1132,11 @@ function createParser(source: SessionSource, seenKeys: Set, capture?: { // key would spuriously diverge on a replay and double-count it. const dedupKey = `codex:${forkedFromId || sessionId}:${cumulativeTotal}:${total?.input_tokens ?? 0}:${total?.cached_input_tokens ?? 0}:${total?.output_tokens ?? 0}:${total?.reasoning_output_tokens ?? 0}` - if (seenKeys.has(dedupKey)) { - // #1088 BUG-2: this event's tokens are dropped from the numerator, - // but task_complete's duration_ms is real wall-clock time that - // still spans them -- track what was dropped so the active window - // can be scaled down to match, instead of crediting the surviving - // calls with time that covers work whose tokens were discarded. - taskDedupedTokens += billableOutputTokens('codex', outputTokens, reasoningTokens) - continue - } + // A drop here can only be a byte-identical replay: the + // prevCumulativeTotal guard above already discards a repeated + // running total, so nothing reaching this point ever loses real + // tokens -- no active-time rescaling needed (#1088 investigation). + if (seenKeys.has(dedupKey)) continue seenKeys.add(dedupKey) // Reasoning tokens are already inside output_tokens, so they are NOT diff --git a/tests/providers/codex.test.ts b/tests/providers/codex.test.ts index cfd01c507..198eb411b 100644 --- a/tests/providers/codex.test.ts +++ b/tests/providers/codex.test.ts @@ -752,35 +752,6 @@ describe('codex provider - JSONL parsing', () => { expect(calls[0]).toMatchObject({ activeGeneratedTokens: 100, activeDurationMs: 13_000, toolWaitMs: 0 }) }) - it('REGRESSION (#1088 BUG-2): a partially fork-deduped task rate matches the undeduped rate', async () => { - // Two checkpoints generate 50 tokens each over a 10s task with no tool - // calls; the first is pre-marked as already-seen (as a fork replay would - // collide it) so only the second reaches pendingTaskCalls. The task's - // real active time (10s) still spans both checkpoints' work, so the - // survivor must be credited with only its proportional share (5s), not - // the full 10s -- giving 50 tokens / 5s = 10 tok/s, the same rate as if - // neither checkpoint had been deduped (100 tokens / 10s). If this ever - // reverts to crediting the full window, it reads 50 tokens / 10s = 5 tok/s. - const dedupedKey = 'codex:sess-dedup:50:0:0:50:0' - const filePath = await writeSession(tmpDir, '2026-04-14', 'rollout-partial-dedup.jsonl', [ - sessionMeta({ session_id: 'sess-dedup', model: 'gpt-5.5' }), - JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:00Z', payload: { type: 'task_started' } }), - userMessage('run the tool', '2026-04-14T10:00:00Z'), - tokenCount({ timestamp: '2026-04-14T10:00:04Z', last: { output: 50 }, total: { output: 50, total: 50 } }), - tokenCount({ timestamp: '2026-04-14T10:00:08Z', last: { output: 50 }, total: { output: 100, total: 100 } }), - JSON.stringify({ type: 'event_msg', timestamp: '2026-04-14T10:00:10Z', payload: { type: 'task_complete', duration_ms: 10_000 } }), - ]) - - const provider = createCodexProvider(tmpDir) - const source = { path: filePath, project: 'test', provider: 'codex' } - const seenKeys = new Set([dedupedKey]) - const calls: ParsedProviderCall[] = [] - for await (const call of provider.createSessionParser(source, seenKeys).parse()) calls.push(call) - - expect(calls).toHaveLength(1) - expect(calls[0]).toMatchObject({ outputTokens: 50, activeGeneratedTokens: 50, activeDurationMs: 5_000 }) - }) - it('#1088 BUG-8: reads a task_complete duration reported as {secs,nanos}, not only a plain number', async () => { // mcp_tool_call_end already tolerates {secs,nanos} and string durations // (durationValueMs); task_complete only read the plain-number duration_ms