Repository navigation
Count drifted Codex ledger mirrors once - #4290
Conversation
Upgrading an older Codex cache to the request-ledger parser looked up the replaced legacy row's saved pricing with the ledger event's timestamp. Codex writes token_usage_record and its token_count mirror a few hundred milliseconds apart, so the lookup missed and every upgraded request was marked unpriced, which dropped whole day/model costs to nil. The parser now records the replaced legacy row's pricing key for each ledger row, in both event orders and across bounded slices, and source pricing recovery falls back to that key. Stores written by 0.72.0 are adopted without a rebuild; ledger rows carrying that release's full markers are repaired, while authoritative amounts and files with invalidated evidence keep theirs.
A stored unpriced marker does not record whether it came from the 0.72.0 ledger timestamp mismatch or from deliberately invalidated source evidence, and invalidated files can contain only ledger rows. Adoption now keeps every row and marker and only drops the retained report. Caches already upgraded by 0.72.0 can be rebuilt from session logs with `codexbar cache clear --cost`.
…cting A saved unpriced request and a saved priced request can share one source pricing key (identical turn, timestamp, model, and tokens). The upgrade map skipped the unpriced row but kept the priced row's evidence, so the legacy-key fallback could price the unknown request. Such keys now invalidate the file's saved pricing, as other conflicting evidence does.
A replayed response links its later token_count to the original ledger row for deduplication. That mirror belongs to a different legacy request, so it must not supply the original row's saved pricing. Donation now requires the token_count to match the ledger row's own persisted mirror keys, which also holds across bounded slices.
When a resumed session's token_count totals follow the turn, a replay's mirror total can equal the original record's thread total and pass the counter-alias check. A mirror whose exact timestamped key belongs to this response but not to the ledger row itself is the replay's mirror, so it no longer supplies the original row's saved pricing.
After a resume, Codex's token_count counter can run behind the thread counter, so a response's token_count and token_usage_record no longer share a timestamp or cumulative total and were counted as two requests. Adjacent observations from the same turn with identical input, cached, and output tokens at most five seconds apart now reconcile as one request. Parser revision 9 reparses existing files once to remove stored duplicates while keeping saved prices, and 0.72.0 stores are adopted without a rebuild.
…daries A token_count written after a long tool run can follow its ledger record by more than the pairing window. When the ledger record comes first, it now pairs if both counters keep the offset learned from the previous pair. A resumed session or a counted bare usage line between two observations clears the pending candidates so they stay distinct.
…iring A replayed ledger record no longer pairs with, or seeds, a different token_count of equal size inside the mirror window. A bare usage line is counted when read, while subagent observations are buffered and processed later. When bare usage follows a buffered subagent observation, the rest of the file keeps exact pairing only, and the saved ledger state keeps that rule across bounded passes.
|
🦞👀 Pull request received. I will update this pull request when review starts. ClawSweeper review completeClawSweeper finished reviewing this revision. The review result is being finalized. |
|
Codex review: needs real behavior proof before merge. Reviewed October 6, 2026, 8:16 AM ET / 12:16 UTC (Revision 5). ClawSweeper reviewWhat this changesThe PR reconciles duplicate Codex usage observations using turn and counter continuity, handles deferred fork replay, and reparses older cost caches while preserving historical pricing evidence. Merge readiness⛔ Blocked before merge - 3 items remain This remains a useful fix that current main does not provide. No blocking code defect was found, but the recorded real-history proof explicitly excludes the final implementation and its cache-upgrade corrections. Priority: P2 Review scores
Verification
How this fits togetherCodexBar scans local Codex session logs into a persistent usage cache. Reconciled request rows feed token totals and cost reports in the CLI and app. flowchart TD
A[Codex session logs] --> B[Session and turn ownership]
B --> C[Mirror reconciliation]
D[Deferred fork observations] --> C
E[Existing usage cache] --> F[Bounded upgrade and pricing recovery]
C --> F
F --> G[Token and cost reports]
Before merge
Agent review detailsSecurityNone. Review metrics
Merge-risk optionsMaintainer options:
Technical reviewBest possible solution: Count each owned response once across compaction and deferred replay while retaining historical prices and explicit pricing uncertainty through cache upgrades. Do we have a high-confidence way to reproduce the issue? Yes: the linked issue supplies both event orders and failing scanner output, and current main retains the exact matching limitation. This review verified the source path without executing tests. Is this the best way to solve the issue? Yes: extending the existing reconciliation path with continuity evidence and persisted replay boundaries is a focused solution; current tests address the earlier pricing and distinct-request failures. AGENTS.md: found and applied where relevant. Codex review notes: model internal, reasoning medium; reviewed against ab32496d3c1f. LabelsLabel changes:
Label justifications:
EvidenceWhat I checked:
Likely related people:
Rank-up movesOptional improvements that raise the rating; they are not merge blockers.
Rating scale
Overall follows the weaker of proof and patch quality. Workflow
HistoryReview history (4 earlier review cycles)
|
…eparse A revision 8 file whose saved rows carry unpriced markers and no reusable saved price returned no migration evidence, so its reparsed rows took current prices. An empty evidence map now keeps them unpriced through bounded slices and store reopen.
Without turn evidence, equal request sizes close in time are not evidence of one request, so such observations keep exact pairing only. Covers the unpriced revision 8 reparse with a bounded, reopened migration test.
…eparse Two requests can share a saved-pricing key. When one was saved unpriced, the key cannot prove which request its price belongs to, so the revision 9 reparse now keeps both unpriced, matching the rule in steipete#4270.
|
Second history: same double count on a v0.72.0-based build, but here the counter offset starts at a context compaction. I tested c69dd8c with six synthetic fixtures: five with a compaction, plus one control. The control and three compaction fixtures pass, including a revision-8 cache repair. The other two each count one response twice. In both, the response is the first one after a compaction and its Build: b957e06b3 ( Where the offset starts (one real session, numbers only)Columns: kind, timestamp,
Real-history counts on the build aboveOct 1–5 (Oct 5 partial), America/New_York days, from my cache. "Ledger rows" are rows with a
c69dd8c against synthetic compaction fixturesIn the compaction fixtures (every row except the control), r1 pairs at an offset of zero: thread 1000/200/100 against total 1000/200/100. Then comes compaction record r2, with no
The real 5023 ms pair: record 2026-10-01T14:48:57.555Z,
Fixture file (drop into Tests/CodexBarTests)import Foundation
import Testing
@testable import CodexBarCore
/// Diagnostic repro shaped like one examined real session: after a context compaction there is a
/// token_usage_record for the compaction request and no token_count reporting it. From then on the
/// token_count counter (info.total_token_usage) trails the ledger's thread_token_usage by
/// that request. token_count events here carry no turn_id, as in the examined real session.
@Suite(.serialized)
struct CostUsageCodexCompactionMirrorReproTests {
private static func tokens(_ v: [Int]) -> [String: Int] {
["input_tokens": v[0], "cached_input_tokens": v[1], "output_tokens": v[2], "reasoning_output_tokens": v[3]]
}
private static func record(_ id: String, _ ts: String, usage: [Int], thread: [Int]) -> [String: Any] {
["type": "token_usage_record", "timestamp": ts, "payload": [
"thread_id": "repro-thread", "session_id": "repro-thread", "turn_id": "repro-turn",
"root_turn_id": "repro-turn", "response_id": id,
"usage": tokens(usage), "turn_token_usage": tokens(thread), "thread_token_usage": tokens(thread),
]]
}
private static func tokenCount(_ ts: String, last: [Int], total: [Int]) -> [String: Any] {
["type": "event_msg", "timestamp": ts, "payload": [
"type": "token_count", "info": ["last_token_usage": tokens(last), "total_token_usage": tokens(total)],
]]
}
private static func turnContext(_ ts: String) -> [String: Any] {
["type": "turn_context", "timestamp": ts, "payload": ["turn_id": "repro-turn", "model": "gpt-5"]]
}
private static func header() -> [[String: Any]] { [
["type": "session_meta", "timestamp": "2026-10-03T23:16:40.000Z", "payload": ["id": "repro-thread"]],
turnContext("2026-10-03T23:17:48.179Z"),
] }
/// r1 paired, then compaction request r2 (ledger only), then the repeated zero-delta token_count.
private static func prefix() -> [[String: Any]] {
header() + [
record("r1", "2026-10-03T23:17:56.136Z", usage: [1000, 200, 100, 0], thread: [1000, 200, 100, 0]),
tokenCount("2026-10-03T23:17:56.137Z", last: [1000, 200, 100, 0], total: [1000, 200, 100, 0]),
record("r2", "2026-10-03T23:52:16.672Z", usage: [5000, 0, 400, 0], thread: [6000, 200, 500, 0]),
["type": "compacted", "timestamp": "2026-10-03T23:52:16.678Z", "payload": ["message": ""]],
turnContext("2026-10-03T23:52:16.679Z"),
tokenCount("2026-10-03T23:52:16.681Z", last: [0, 0, 0, 0], total: [1000, 200, 100, 0]),
]
}
private static func calendar() throws -> Calendar {
var calendar = Calendar(identifier: .gregorian)
calendar.timeZone = try #require(TimeZone(identifier: "America/New_York"))
return calendar
}
private static func run(_ label: String, _ lines: [[String: Any]]) throws -> (rows: Int, tokens: Int) {
let env = try CostUsageTestEnvironment()
defer { env.cleanup() }
let file = env.root.appendingPathComponent("repro.jsonl")
try env.jsonl(lines).write(to: file, atomically: false, encoding: .utf8)
let day = try #require(ISO8601DateFormatter().date(from: "2026-10-03T23:00:00Z"))
let result = try CostUsageScanner.parseCodexFile(
fileURL: file, range: .init(since: day, until: day, calendar: Self.calendar()))
let tokens = result.rows.reduce(0) { $0 + $1.input + $1.output }
print("[compaction-repro] \(label) rows=\(result.rows.count) input+output=\(tokens) " +
"detail=\(result.rows.map { "\($0.responseID ?? "token_count"):\($0.input)+\($0.output)" })")
return (result.rows.count, tokens)
}
@Test
func `control without compaction counts each response once`() throws {
let result = try Self.run("control", Self.header() + [
Self.record("r1", "2026-10-03T23:17:56.136Z", usage: [1000, 200, 100, 0], thread: [1000, 200, 100, 0]),
Self.tokenCount("2026-10-03T23:17:56.137Z", last: [1000, 200, 100, 0], total: [1000, 200, 100, 0]),
Self.record("r3", "2026-10-03T23:52:20.591Z", usage: [300, 100, 30, 0], thread: [1300, 300, 130, 0]),
Self.tokenCount("2026-10-03T23:52:20.640Z", last: [300, 100, 30, 0], total: [1300, 300, 130, 0]),
])
#expect(result.rows == 2)
#expect(result.tokens == 1430)
}
@Test
func `responses after a compaction are counted once`() throws {
let result = try Self.run("near", Self.prefix() + [
Self.record("r3", "2026-10-03T23:52:20.591Z", usage: [300, 100, 30, 0], thread: [6300, 300, 530, 0]),
Self.tokenCount("2026-10-03T23:52:20.640Z", last: [300, 100, 30, 0], total: [1300, 300, 130, 0]),
Self.record("r4", "2026-10-03T23:52:33.856Z", usage: [400, 300, 40, 0], thread: [6700, 600, 570, 0]),
Self.tokenCount("2026-10-03T23:52:33.871Z", last: [400, 300, 40, 0], total: [1700, 600, 170, 0]),
])
#expect(result.rows == 4)
#expect(result.tokens == 7270)
}
/// First pair after a compaction, written 20 s apart: the offset just changed and the
/// pair is outside the near window.
@Test
func `first response after a compaction is counted once when its mirror is 20 s late`() throws {
let result = try Self.run("far-first", Self.prefix() + [
Self.record("r3", "2026-10-03T23:52:20.591Z", usage: [300, 100, 30, 0], thread: [6300, 300, 530, 0]),
Self.tokenCount("2026-10-03T23:52:40.640Z", last: [300, 100, 30, 0], total: [1300, 300, 130, 0]),
])
#expect(result.rows == 3)
#expect(result.tokens == 6830)
}
/// Same, with the 5,023 ms gap observed in a real history.
@Test
func `first response after a compaction is counted once when its mirror is 5023 ms late`() throws {
let result = try Self.run("far-first-5023ms", Self.prefix() + [
Self.record("r3", "2026-10-03T23:52:20.591Z", usage: [300, 100, 30, 0], thread: [6300, 300, 530, 0]),
Self.tokenCount("2026-10-03T23:52:25.614Z", last: [300, 100, 30, 0], total: [1300, 300, 130, 0]),
])
#expect(result.rows == 3)
#expect(result.tokens == 6830)
}
/// After a near pair established the post-compaction offset, a 20 s late mirror pairs by offset.
@Test
func `later late mirror after a compaction pairs by the learned offset`() throws {
let result = try Self.run("far-offset", Self.prefix() + [
Self.record("r3", "2026-10-03T23:52:20.591Z", usage: [300, 100, 30, 0], thread: [6300, 300, 530, 0]),
Self.tokenCount("2026-10-03T23:52:20.640Z", last: [300, 100, 30, 0], total: [1300, 300, 130, 0]),
Self.record("r4", "2026-10-03T23:52:33.856Z", usage: [400, 300, 40, 0], thread: [6700, 600, 570, 0]),
Self.tokenCount("2026-10-03T23:52:53.871Z", last: [400, 300, 40, 0], total: [1700, 600, 170, 0]),
])
#expect(result.rows == 4)
#expect(result.tokens == 7270)
}
/// Upgrade path: a revision 8 cache that already holds a doubled legacy row is repaired by the
/// revision 9 reparse (simulates an existing cache written by the unfixed build).
@Test(arguments: [false, true])
func `revision 8 cache with a doubled compaction mirror is repaired`(bounded: Bool) throws {
let env = try CostUsageTestEnvironment()
defer { env.cleanup() }
let calendar = try Self.calendar()
let start = try #require(ISO8601DateFormatter().date(from: "2026-10-03T23:00:00Z"))
let end = try #require(ISO8601DateFormatter().date(from: "2026-10-03T23:59:00Z"))
let file = try env.writeCodexSessionFile(
day: start,
filename: "rollout-2026-10-03T19-16-40-repro-thread.jsonl",
contents: env.jsonl(Self.prefix() + [
Self.record("r3", "2026-10-03T23:52:20.591Z", usage: [300, 100, 30, 0], thread: [6300, 300, 530, 0]),
Self.tokenCount("2026-10-03T23:52:20.640Z", last: [300, 100, 30, 0], total: [1300, 300, 130, 0]),
]))
var options = CostUsageScanner.Options(
codexSessionsRoot: env.codexSessionsRoot,
cacheRoot: env.cacheRoot,
codexTraceDatabaseURL: env.root.appendingPathComponent("missing-traces.sqlite"),
calendar: calendar)
options.refreshMinIntervalSeconds = 0
func report(_ now: Date) -> CostUsageDailyReport {
CostUsageScanner.loadDailyReport(provider: .codex, since: start, until: end, now: now, options: options)
}
#expect(report(end).summary?.totalTokens == 6830)
var stored = CostUsageStoreAccess.read(cacheRoot: env.cacheRoot, calendar: calendar)
var usageFile = try #require(stored.files[file.path])
var rows = try #require(usageFile.codexRows)
try #require(rows.count == 3)
let r3 = try #require(rows.first { $0.responseID == "r3" })
rows.append(CostUsageScanner.CodexUsageRow(
day: r3.day, model: r3.model, rawModel: r3.rawModel, turnID: r3.turnID, eventIndex: 99,
timestampUnixMs: (r3.timestampUnixMs ?? 0) + 49,
input: r3.input, cached: r3.cached, output: r3.output, reasoning: r3.reasoning))
usageFile.codexRows = rows
usageFile.codexParserRevision = 8
stored.files[file.path] = usageFile
_ = CostUsageStoreAccess.replace(cacheRoot: env.cacheRoot, cache: stored, calendar: calendar)
let seeded = CostUsageStoreAccess.read(cacheRoot: env.cacheRoot, calendar: calendar).files[file.path]
#expect(seeded?.codexRows?.count == 4)
if bounded {
options.maxCodexScanBytesPerRefresh = usageFile.size / 2
}
var migrated: CostUsageFileUsage?
for pass in 1...20 {
_ = report(end.addingTimeInterval(Double(pass)))
migrated = CostUsageStore(cacheRoot: env.cacheRoot).syncLoadCodexCache(calendar: calendar)
.files[file.path]
if migrated?.hasCurrentCodexParser == true, migrated?.codexScanComplete == true { break }
}
let migratedRows = try #require(migrated?.codexRows)
print("[compaction-repro] upgrade bounded=\(bounded) rows=\(migratedRows.count) " +
"total=\(String(describing: report(end.addingTimeInterval(30)).summary?.totalTokens))")
#expect(migrated?.hasCurrentCodexParser == true)
#expect(migratedRows.count == 3)
#expect(report(end.addingTimeInterval(30)).summary?.totalTokens == 6830)
}
}Run with |
A near or offset pair is one request only if the second observation's counter advanced by no more than its own usage since that counter's previous observation. A larger advance shows another request in between, so the two stay distinct, as on main, including through the revision 9 reparse.
Carry saved pricing from the original legacy observation through bounded request-ledger upgrades. Track pricing ownership separately from response deduplication so later same-counter replays cannot donate their prices. Keep compatible cache rows and unknown-price markers. Replace the production cache forwarding factory with direct value initialization, preserving defaults; the convenience factory now belongs to synthetic test fixtures. Validation: 251 focused tests in 26 suites passed, including bounded/unbounded same-counter replay regressions that failed before the ownership fix. Codex review found no remaining actionable findings. make check passes. Co-authored-by: Gabriel Rojas <[email protected]>
Pair adjacent same-turn observations using request usage and counter continuity, including delayed mirrors after compaction. Preserve original ledger evidence and bare-usage boundaries in replay buffers, and resolve fork mirror ownership in log order after verifying the parent baseline. Keep pending matches across identical copies and recognize owned legacy replays after counter-history eviction. Preserve independent last-only requests and explicit unknown-price evidence during cache upgrades. Consolidate regression fixtures and remove unused accounting wrappers. Incorporate steipete#4270 without rewriting contributor history. Includes @kcharlan's delayed-compaction regression. Fixes steipete#4289 Co-authored-by: Gabriel Rojas <[email protected]>
Merge train for ten Codex cost PRs that each regenerate the parser fingerprint; landed together so the generated hash is regenerated once (final fingerprint 7ff985e81e281a11, predecessor 99d920977063318a from main) and existing caches and checkpoints survive. #4276 (@luochen211) Fix Codex session tier pricing: durable thread_settings_applied Priority evidence binds to the following turns, with the Fast multipliers applied and the evidence preserved through incremental scans and SQLite reopening; the train also fixes Priority being cleared after the first turn (threadPriority is retained until replaced). #4279 (@gabrielrojasc, consolidating #4278 by @luochen211) Keep priced Codex subtotals when some requests are unpriced: one unpriced request no longer hides the whole model/day estimate, and a day with an unpriced model no longer reads as fully priced. #4295 (@Yuxin-Qiao) Keep known daily request counts as lower bounds independently of token and cost completeness. #4258 (@urda) Price Antigravity gpt-oss-120b at the Google Vertex list price through warm and cold catalog paths. #4290 (@gabrielrojasc, fixture by @kcharlan) Count drifted Codex ledger mirrors once: counter-continuity matching, retained replay evidence, deferred fork mirror ownership, bounded resumes. #4305 (@shiquda) ClinePass labeled API-key token accounts through the shared token-account adapter with selected-key isolation. #4296 (@Yuxin-Qiao) Recover empty Codex cost scans (one bounded recovery per cache and worker when a pass yielded with zero attempts) and clear completed dashboard stalls via a read-only completion check. #4312 (@steipete) Honor documented long-context pricing thresholds: the models.dev explicit context tier (272,000 for the GPT-6 family) replaces the literal 200,000 read from the legacy field. #4277 (@luochen211, includes #4286 by @Yuxin-Qiao) Reuse Codex report preparation per refresh (402 reports instead of 802 for a 400-file cached refresh) and reduce repeated component path work in storage scans. #4291 (@kristofferR) Stream Codex usage rows for reports and baselines without materializing encoded-row arrays. Fixes #4274 Fixes #4273 Fixes #4289 Fixes #4302 Fixes #4275 Thanks @luochen211, @gabrielrojasc, @kcharlan, @Yuxin-Qiao, @urda, @shiquda and @kristofferR!
|
Thanks @gabrielrojasc and @kcharlan! Landed through the merge train #4317 (d919d23) with the contributor history preserved and #4270 incorporated. Drifted and delayed mirrors retain counter continuity, ordered fork replay and explicit unknown-price evidence; the reported fixture counts one row and 87,275 input tokens in either order. Ships in the next release. |
Fixes #4289.
Summary
A response's
token_usage_recordand itstoken_countmirror are counted twice when Codex's token_count counter has drifted from the thread counter, for example after a resume. This PR pairs them by turn, identical usage, and time or counter offset, while keeping the #4195 protections.main. A cold parse pairs it.Evidence
Real history (
.github/pr-proof/codex-ledger-mirror-window-real-setup.log). The CLI cost path ran over one real Codex history from a copy of a 0.72.0 cache.mainand this branch each ran until fully scanned:main@6a26b2e9bNo file loses ledger rows or gains legacy rows. A raw-log pass finds 66,336
token_countevents beside a ledger record with identical usage, holding 8.21B tokens. The 5.46B removed fits inside that pool.Temporary harness (not committed)
Issue repro (
CostUsageCodexOffsetMirrorTestson the issue). Onmain@6a26b2e9b, both event orders giverows=2 input=174550. With this branch, the same scenario is covered byadjacent offset counters pair only inside the mirror window.New tests, in
CostUsageCodexRequestLedgerTests+MirrorWindow.swift:turn_id, and atask_startedbetween the events (stays distinct)Mutation checks. With near pairing disabled, the window, refresh, and revision 8 tests fail. With the offset rule, resume clear, and bare-usage clear disabled, the far same-offset case and all four separator cases fail. Removing either replay guard fails the replay test; never setting the bare-usage flag, always setting it, or dropping it from saved state each fails a bounded-pass or empty-fragment test.
Commands run:
codexParserRevisionMigrationPricingnow returns an empty map when saved unpriced rows remain and no saved price is reusable, so the revision 9 reparse keeps them unpriced. It also returns an empty map when an unpriced and a priced row share a key, using the same lines as #4270, so that part merges to identical code. Whichever merges second keeps both checks.This PR, #4270, and #4279 each regenerate the Codex parser hash from
ed735dc27ffa70d9and add it to the predecessor lists. Whichever merges later needs a small rebase that regenerates the hash and keeps the merged PR's hash as a predecessor.Merge Danger
Door: two-way
Reverting restores the stricter pairing. Caches reparsed under revision 9 keep their rows; a revert only stops new pairing.
Blast Radius: Codex costs
Codex token and cost totals go down wherever duplicated mirrors were counted. Every Codex cache reparses its files once, in bounded passes, after upgrading. Other providers are unchanged.