diff --git a/src/parser.ts b/src/parser.ts index 43f7c073..ee28a328 100644 --- a/src/parser.ts +++ b/src/parser.ts @@ -2951,18 +2951,14 @@ function getOrCreateProviderSection(cache: SessionCache, provider: string): Prov // union counts it twice. Changing a provider's key shape is therefore a // cache-version (CACHE_VERSION) change, not a parse-version change. // - // The price of that contract, worth knowing before writing the next bump: a - // bump no longer RE-DERIVES a durable call it carried forward. The union - // appends only unseen keys, so a call already in the cache keeps the FIELDS - // the old parser gave it. A bump that changes what a call is worth in - // dollars still lands (cost is recomputed at serve time from the cached - // usage), but a bump that changes a call's metadata or its day attribution - // — this PR's own shutdown-timestamp fallback, capture-only fields like - // nanoAiu/compactedAt — reaches only calls the bump parses for the first - // time. Fixing those for existing caches needs CACHE_VERSION, which drops - // the cache outright, and that is exactly the history loss this block - // exists to prevent: the two cannot both be had for a source that has - // pruned its rows. + // What the re-read is FOR, beyond appending new keys: the union replaces a + // cached call with the freshly-derived one wherever the key matches, so a + // bump that changes a call's metadata or day attribution (this PR's + // shutdown-timestamp fallback, capture-only fields like nanoAiu/compactedAt, + // the compaction row's output) lands on existing caches too. Only keys the + // re-read did NOT produce keep the old parser's fields, and those are + // precisely the ones the source can no longer re-derive — where stale + // accounting is the only alternative to nothing at all. if (existing && DURABLE_PROVIDER_NAMES.has(provider)) { if (existing.durable) section.durable = true for (const [path, file] of Object.entries(existing.files)) { @@ -3397,16 +3393,30 @@ async function parseProviderSources( // Store/merge parsed turns into the cache. // Durable providers use a union-by-deduplicationKey merge: existing turns - // are NEVER deleted (preserves data for spans pruned from the DB), and - // only turns whose dedup keys are not already cached are appended. A - // deliberate consequence: capture-only metadata on an already-cached key - // (copilot nanoAiu/requestMultiplier) is not backfilled by a re-parse. - // Safe because the parse version that admits store rows is the same one - // that captures the metadata, and the CLI never rewrites old rows. + // are NEVER deleted (preserves data for spans pruned from the DB). Keys + // the parse did not produce - rows the source has since pruned - are + // exactly what the cache is the last record of, so they stay untouched. + // A key the parse DID produce is re-derived from the live source in this + // very pass, so the fresh call replaces the cached one in place. + // + // That replacement is load-bearing, not tidiness. Fields a parse-version + // bump adds to a call whose key is stable (copilot `compactedAt` on the + // shutdown rollup, `initiator`/output on a store row) could otherwise + // never reach a cache written before the bump: append-only left the old + // field-set in place forever, and the reconciliation then ran on a + // migrated cache with an anchor the virgin cache had - dropping the + // post-compaction residual (#946 validation round 6, see (c6)). // Non-durable providers keep the original overwrite-or-append behaviour. if (provider.durableSources) { const existingEntry = section.files[source.path] if (existingEntry) { + const freshByKey = new Map(turns.flatMap(t => t.calls).map(c => [c.deduplicationKey, c])) + if (freshByKey.size > 0) { + existingEntry.turns = existingEntry.turns.map(t => { + const calls = t.calls.map(c => freshByKey.get(c.deduplicationKey) ?? c) + return calls.some((c, i) => c !== t.calls[i]) ? { ...t, calls } : t + }) + } const existingKeys = new Set( existingEntry.turns.flatMap(t => t.calls.map(c => c.deduplicationKey)) ) diff --git a/tests/parser.test.ts b/tests/parser.test.ts index c12dee94..abb801a4 100644 --- a/tests/parser.test.ts +++ b/tests/parser.test.ts @@ -1921,6 +1921,164 @@ describe.skipIf(!isSqliteAvailable())('(c5) compaction-initiated store rows', () }) }) +// ═══════════════════════════════════════════════════════════════════════════ +// (c6) A migrated cache must reconcile like a virgin one +// ═══════════════════════════════════════════════════════════════════════════ +// #946 validation round 6 (@vidoluco): a cache generated by 0.9.20, copied and +// then migrated by this branch, dropped exactly ONE call a virgin cache serves +// - `mai-code-1-flash-picker`, 324 input / 91,136 cache read / $0.01, sitting +// two minutes after the labelled compaction row in its session. +// +// `compactedAt` is a capture-only field this branch adds to the shutdown-ROLLUP +// call, and 0.9.20 already cached that call under the same dedup key. The +// durable union appends only unseen keys, so the bump could not reach it: the +// migrated cache ran the compaction-anchored residual math with no anchor, +// which is exactly the pre-anchor behaviour - the interval opens at -Infinity, +// the PRE-compaction rows are subtracted from a rollup that never counted +// them, and the residual clamps to zero and disappears. +describe.skipIf(!isSqliteAvailable())('(c6) a migrated cache reconciles like a virgin one', () => { + const MODEL = 'mai-code-1-flash-picker' + + const createStore = (dbPath: string): void => { + const { DatabaseSync } = requireForTest('node:sqlite') as { DatabaseSync: new (p: string) => TestDb } + const db = new DatabaseSync(dbPath) + db.exec(` + CREATE TABLE sessions (id TEXT PRIMARY KEY, cwd TEXT, repository TEXT, created_at TEXT); + CREATE TABLE assistant_usage_events ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + session_id TEXT NOT NULL, model TEXT NOT NULL, + input_tokens INTEGER, output_tokens INTEGER, + cache_read_tokens INTEGER, cache_write_tokens INTEGER, + reasoning_tokens INTEGER, created_at TEXT, + total_nano_aiu INTEGER, request_multiplier REAL, initiator TEXT); + `) + db.close() + } + const insertRow = (dbPath: string, sid: string, input: number, cacheRead: number, at: string, initiator: string | null, output = 0): void => { + const { DatabaseSync } = requireForTest('node:sqlite') as { DatabaseSync: new (p: string) => TestDb } + const db = new DatabaseSync(dbPath) + db.prepare('INSERT OR IGNORE INTO sessions (id, cwd) VALUES (?, ?)').run(sid, '/home/user/pickerproj') + db.prepare(`INSERT INTO assistant_usage_events + (session_id, model, input_tokens, output_tokens, cache_read_tokens, cache_write_tokens, + reasoning_tokens, created_at, total_nano_aiu, request_multiplier, initiator) + VALUES (?, ?, ?, ?, ?, 0, 0, ?, 1000, 1, ?)`).run(sid, MODEL, input, output, cacheRead, at, initiator) + db.close() + } + + const build = async () => { + const sessionStateDir = join(tmpHome, 'c6-state') + await mkdir(sessionStateDir, { recursive: true }) + const dbPath = join(tmpHome, 'c6-store.db') + vi.stubEnv('CODEBURN_COPILOT_SESSION_STATE_DIR', sessionStateDir) + vi.stubEnv('CODEBURN_COPILOT_SESSION_STORE_DB', dbPath) + vi.stubEnv('CODEBURN_COPILOT_DISABLE_OTEL', '1') + vi.stubEnv('CODEBURN_COPILOT_WS_STORAGE_DIR', join(tmpHome, 'no-ws')) + vi.stubEnv('CODEBURN_COPILOT_GLOBAL_STORAGE_DIR', join(tmpHome, 'no-global')) + vi.stubEnv('CODEBURN_COPILOT_JETBRAINS_DIR', join(tmpHome, 'no-jb')) + const base = Date.now() - 4 * 24 * 3600 * 1000 + const at = (sec: number): string => new Date(base + sec * 1000).toISOString() + createStore(dbPath) + + const dir = join(sessionStateDir, 'sess-8acb5587') + await mkdir(dir, { recursive: true }) + await writeFile(join(dir, 'workspace.yaml'), 'id: sess-8acb5587\ncwd: /home/user/pickerproj\n') + await writeFile(join(dir, 'events.jsonl'), [ + JSON.stringify({ type: 'session.model_change', timestamp: at(0), data: { newModel: MODEL } }), + JSON.stringify({ type: 'session.compaction_complete', timestamp: at(300), data: { success: true, kind: 'background' } }), + // The rollup RESET at the compaction, so it claims only the two + // post-compaction requests (324 + 324 uncached, 91,136 + 91,136 cached). + JSON.stringify({ type: 'session.shutdown', timestamp: at(600), data: { + shutdownType: 'routine', + modelMetrics: { [MODEL]: { requests: { count: 2, cost: 1 }, + usage: { inputTokens: 182920, outputTokens: 0, cacheReadTokens: 182272, cacheWriteTokens: 0, reasoningTokens: 0 } } }, + } }), + ].join('\n') + '\n') + + // A big PRE-compaction request the rollup never counted... + insertRow(dbPath, 'sess-8acb5587', 500000, 499000, at(100), null) + // ...and the post-compaction row, two minutes after the compaction stamp. + // Its twin never wrote a row, so the residual is exactly one request. + insertRow(dbPath, 'sess-8acb5587', 91460, 91136, at(420), null) + return { dbPath, at } + } + + /// What a 0.9.20-generated cache looks like to this build: the rollup call is + /// already cached under its (stable) dedup key with the OLD parser's fields - + /// no `compactedAt` - and the env fingerprint mismatches, which is the code + /// path a PROVIDER_PARSE_VERSIONS bump takes. + const ageCacheToPreBumpFields = async (): Promise => { + clearSessionCache() + const disk = await readCacheOnDisk() + const section = disk.providers['copilot'] + expect(section).toBeDefined() + let stripped = 0 + for (const file of Object.values(section!.files)) { + for (const turn of file.turns) { + for (const call of turn.calls) { + if (call.compactedAt !== undefined) { delete call.compactedAt; stripped++ } + } + } + } + // Self-check: if nothing was stripped this fixture proves nothing. + expect(stripped).toBeGreaterThan(0) + expect(section!.envFingerprint).not.toBe('0000000000000000') + section!.envFingerprint = '0000000000000000' + await writeCacheOnDisk(disk) + clearSessionCache() + } + + const served = async () => { + const calls = (await parseAllSessions(undefined, 'copilot')) + .flatMap(p => p.sessions).flatMap(s => s.turns).flatMap(t => t.assistantCalls) + return { + input: calls.reduce((s, c) => s + c.usage.inputTokens, 0), + cacheRead: calls.reduce((s, c) => s + c.usage.cacheReadInputTokens, 0), + output: calls.reduce((s, c) => s + c.usage.outputTokens, 0), + residuals: calls.filter(c => c.deduplicationKey.includes(':shutdown-residual:')).length, + } + } + + it('keeps the post-compaction residual after a bump onto a pre-bump cache', async () => { + await build() + const virgin = await served() + // 1,000 (pre-compaction row) + 324 (post row) + 324 (residual). + expect(virgin).toMatchObject({ input: 1648, cacheRead: 681272, residuals: 1 }) + + await ageCacheToPreBumpFields() + expect(await served()).toEqual(virgin) + // Persisted, not merely served: the loss must not come back on a cold read. + clearSessionCache() + expect(await served()).toEqual(virgin) + }) + + // Same root cause, other direction: the compaction row's output (the round-5 + // fix) has to reach a cache written before ITS bump too, which append-only + // could never do - the row's dedup key is deliberately stable. + it('backfills a store row whose fields the bump changed', async () => { + const { dbPath, at } = await build() + insertRow(dbPath, 'sess-8acb5587', 6272, 0, at(300), 'compaction', 3085) + const virgin = await served() + expect(virgin.output).toBe(3085) + + // Age the cached compaction row to its pre-fix shape (output 0), strip the + // rollup anchor, and bump - exactly a branch tester's v2 cache. + clearSessionCache() + const disk = await readCacheOnDisk() + for (const file of Object.values(disk.providers['copilot']!.files)) { + for (const turn of file.turns) { + for (const call of turn.calls) { + if (call.initiator === 'compaction') call.usage.outputTokens = 0 + delete call.compactedAt + } + } + } + disk.providers['copilot']!.envFingerprint = '0000000000000000' + await writeCacheOnDisk(disk) + clearSessionCache() + expect(await served()).toEqual(virgin) + }) +}) + // ═══════════════════════════════════════════════════════════════════════════ // (c4) Attributed cost equals cost recomputed from the served tokens // ═══════════════════════════════════════════════════════════════════════════