Skip to content

Commit 8f8cf07

Browse files
BenGuanRandoudouOUC
authored andcommitted
fix(stats): dedup usage records by sessionId and skip in-progress writes (#4995)
* fix(stats): dedup usage records by sessionId and skip in-progress writes (#4994) Opening /stats during the first-ever turn followed by /clear (or exit) used to write the same sessionId twice into ~/.qwen/usage_record.jsonl, permanently inflating every aggregate (sessions / tokens / durations / tools / heatmap / projects) 2x for that session. Closes #4994. Defense in depth: - Read side: loadUsageHistory dedups records by sessionId (last-wins), so any duplicates already on disk from this bug stop inflating future aggregates. - Write side: rebuildFromSessionJsonl skips the in-progress session when its sessionId is passed in; statsDataService threads currentSession.sessionId through. New duplicates are no longer created at the source. Regression coverage in usageHistoryService.test.ts mirrors the exact bug sequence (open /stats during first turn -> /clear -> re-open /stats) and asserts sessionCount=1, totalTokens=1600 for a single ~1.6k-token session. * fix(stats): address PR review — log dedup count and rename rebuild-skip param Why: - dedupBySessionId silently dropped duplicate records, making it impossible to observe how many users were affected by the #4994 bug. Now logs the removed count at debug level. - The new loadUsageHistory parameter was named currentSessionId but only controls the write-side skip during rebuildFromSessionJsonl — the read path ignores it. Renaming to skipSessionInRebuild makes the limited scope explicit; statsDataService still strips/re-pushes the live current session for defense-in-depth. PR review feedback on #4995.
1 parent 12c98a8 commit 8f8cf07

3 files changed

Lines changed: 257 additions & 7 deletions

File tree

packages/cli/src/ui/utils/statsDataService.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -248,7 +248,7 @@ export async function loadStatsData(
248248
range: TimeRange,
249249
currentSession?: UsageSummaryRecord,
250250
): Promise<StatsData> {
251-
const persisted = await loadUsageHistory();
251+
const persisted = await loadUsageHistory(currentSession?.sessionId);
252252
let records = persisted;
253253
if (currentSession) {
254254
records = persisted.filter((r) => r.sessionId !== currentSession.sessionId);

packages/core/src/services/usageHistoryService.test.ts

Lines changed: 229 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -4,8 +4,16 @@
44
* SPDX-License-Identifier: Apache-2.0
55
*/
66

7-
import { describe, it, expect } from 'vitest';
8-
import { metricsToUsageRecord, aggregateUsage } from './usageHistoryService.js';
7+
import { afterEach, beforeEach, describe, it, expect } from 'vitest';
8+
import fs from 'node:fs';
9+
import os from 'node:os';
10+
import path from 'node:path';
11+
import {
12+
metricsToUsageRecord,
13+
aggregateUsage,
14+
loadUsageHistory,
15+
persistSessionUsage,
16+
} from './usageHistoryService.js';
917
import { ToolCallDecision } from '../telemetry/tool-call-decision.js';
1018
import type { SessionMetrics } from '../telemetry/uiTelemetry.js';
1119
import type { UsageSummaryRecord } from './usageHistoryService.js';
@@ -349,3 +357,222 @@ describe('aggregateUsage', () => {
349357
expect(report.tools.topTools).toEqual([]);
350358
});
351359
});
360+
361+
// Regression coverage for issue #4994: opening /stats during the first-ever
362+
// turn followed by /clear or process exit used to write the same sessionId
363+
// twice into usage_record.jsonl, permanently inflating every aggregate 2x.
364+
describe('loadUsageHistory + persistSessionUsage (issue #4994 regression)', () => {
365+
let tmpHome: string;
366+
let originalQwenHome: string | undefined;
367+
368+
beforeEach(() => {
369+
tmpHome = fs.mkdtempSync(path.join(os.tmpdir(), 'qwen-usage-history-'));
370+
originalQwenHome = process.env['QWEN_HOME'];
371+
process.env['QWEN_HOME'] = path.join(tmpHome, '.qwen');
372+
fs.mkdirSync(process.env['QWEN_HOME'], { recursive: true });
373+
});
374+
375+
afterEach(() => {
376+
if (originalQwenHome === undefined) delete process.env['QWEN_HOME'];
377+
else process.env['QWEN_HOME'] = originalQwenHome;
378+
fs.rmSync(tmpHome, { recursive: true, force: true });
379+
});
380+
381+
function plantChatJsonl(sessionId: string, tokens: number) {
382+
const cwd = '/repro/project';
383+
const start = new Date('2026-06-11T00:00:00Z').toISOString();
384+
const mid = new Date('2026-06-11T00:01:00Z').toISOString();
385+
const end = new Date('2026-06-11T00:02:00Z').toISOString();
386+
const projDir = path.join(
387+
process.env['QWEN_HOME']!,
388+
'projects',
389+
'repro-project',
390+
);
391+
fs.mkdirSync(path.join(projDir, 'chats'), { recursive: true });
392+
const records = [
393+
{
394+
sessionId,
395+
cwd,
396+
uuid: 'u1',
397+
parentUuid: null,
398+
timestamp: start,
399+
type: 'user',
400+
message: { role: 'user', content: 'hi' },
401+
},
402+
{
403+
sessionId,
404+
cwd,
405+
uuid: 'u2',
406+
parentUuid: 'u1',
407+
timestamp: mid,
408+
type: 'system',
409+
subtype: 'ui_telemetry',
410+
systemPayload: {
411+
uiEvent: {
412+
'event.name': 'qwen-code.api_response',
413+
'event.timestamp': mid,
414+
response_id: 'r1',
415+
model: 'qwen-max',
416+
duration_ms: 1200,
417+
input_token_count: tokens * 0.6,
418+
output_token_count: tokens * 0.3,
419+
cached_content_token_count: 0,
420+
thoughts_token_count: tokens * 0.1,
421+
total_token_count: tokens,
422+
prompt_id: 'p1',
423+
},
424+
},
425+
},
426+
{
427+
sessionId,
428+
cwd,
429+
uuid: 'u3',
430+
parentUuid: 'u2',
431+
timestamp: end,
432+
type: 'assistant',
433+
message: { role: 'assistant', content: 'ok' },
434+
},
435+
];
436+
fs.writeFileSync(
437+
path.join(projDir, 'chats', `${sessionId}.jsonl`),
438+
records.map((r) => JSON.stringify(r)).join('\n') + '\n',
439+
);
440+
}
441+
442+
function makeLiveMetrics(tokens: number): SessionMetrics {
443+
return {
444+
models: {
445+
'qwen-max': {
446+
api: { totalRequests: 1, totalErrors: 0, totalLatencyMs: 1200 },
447+
tokens: {
448+
prompt: tokens * 0.6,
449+
candidates: tokens * 0.3,
450+
total: tokens,
451+
cached: 0,
452+
thoughts: tokens * 0.1,
453+
},
454+
bySource: {},
455+
},
456+
},
457+
tools: {
458+
totalCalls: 0,
459+
totalSuccess: 0,
460+
totalFail: 0,
461+
totalDurationMs: 0,
462+
totalDecisions: {
463+
[ToolCallDecision.ACCEPT]: 0,
464+
[ToolCallDecision.REJECT]: 0,
465+
[ToolCallDecision.MODIFY]: 0,
466+
[ToolCallDecision.AUTO_ACCEPT]: 0,
467+
},
468+
byName: {},
469+
},
470+
files: { totalLinesAdded: 0, totalLinesRemoved: 0 },
471+
};
472+
}
473+
474+
it('read-side: dedups duplicate sessionId records already on disk (last-wins)', async () => {
475+
// Simulate a usage_record.jsonl already corrupted by the pre-fix bug:
476+
// two records with the same sessionId.
477+
const sessionId = 'sess-dup-1';
478+
const usagePath = path.join(
479+
process.env['QWEN_HOME']!,
480+
'usage_record.jsonl',
481+
);
482+
const rec = (totalTokens: number) => ({
483+
version: 1 as const,
484+
sessionId,
485+
timestamp: Date.now(),
486+
startTime: Date.now() - 60000,
487+
project: '/p',
488+
durationMs: 60000,
489+
totalLatencyMs: 1200,
490+
models: {
491+
'qwen-max': {
492+
requests: 1,
493+
inputTokens: totalTokens * 0.6,
494+
outputTokens: totalTokens * 0.3,
495+
cachedTokens: 0,
496+
thoughtsTokens: totalTokens * 0.1,
497+
totalTokens,
498+
},
499+
},
500+
tools: { totalCalls: 0, totalSuccess: 0, totalFail: 0, byName: {} },
501+
files: { linesAdded: 0, linesRemoved: 0 },
502+
});
503+
fs.writeFileSync(
504+
usagePath,
505+
JSON.stringify(rec(1000)) + '\n' + JSON.stringify(rec(1600)) + '\n',
506+
);
507+
508+
const records = await loadUsageHistory();
509+
510+
expect(records).toHaveLength(1);
511+
// Last-wins: the second record (1600 tokens) survives.
512+
expect(records[0]!.models['qwen-max']!.totalTokens).toBe(1600);
513+
514+
const report = aggregateUsage(records, 'all');
515+
expect(report.sessionCount).toBe(1);
516+
});
517+
518+
it('write-side: rebuildFromSessionJsonl skips the in-progress session when skipSessionInRebuild is passed', async () => {
519+
const sessionId = 'sess-in-progress';
520+
plantChatJsonl(sessionId, 1600);
521+
const usagePath = path.join(
522+
process.env['QWEN_HOME']!,
523+
'usage_record.jsonl',
524+
);
525+
526+
// First /stats open during the live session.
527+
const first = await loadUsageHistory(sessionId);
528+
expect(first).toHaveLength(1);
529+
// Critically: the file must NOT contain the in-progress session.
530+
expect(fs.existsSync(usagePath)).toBe(false);
531+
532+
// /clear or process exit writes the authoritative record exactly once.
533+
persistSessionUsage({
534+
sessionId,
535+
startTime: new Date('2026-06-11T00:00:00Z'),
536+
endTime: new Date('2026-06-11T00:02:00Z'),
537+
project: '/repro/project',
538+
metrics: makeLiveMetrics(1600),
539+
});
540+
const lines = fs.readFileSync(usagePath, 'utf8').trim().split('\n');
541+
expect(lines).toHaveLength(1);
542+
543+
// Subsequent /stats open after session end aggregates exactly one record.
544+
const second = await loadUsageHistory();
545+
expect(second).toHaveLength(1);
546+
const report = aggregateUsage(second, 'all');
547+
expect(report.sessionCount).toBe(1);
548+
let totalTokens = 0;
549+
for (const m of Object.values(report.models)) totalTokens += m.totalTokens;
550+
expect(totalTokens).toBe(1600);
551+
});
552+
553+
it('end-to-end: /stats during first turn + /clear must not 2x the session', async () => {
554+
const sessionId = 'sess-e2e';
555+
plantChatJsonl(sessionId, 1600);
556+
557+
// Step 1: open /stats (first time) during the live session.
558+
await loadUsageHistory(sessionId);
559+
560+
// Step 2: /clear or exit.
561+
persistSessionUsage({
562+
sessionId,
563+
startTime: new Date('2026-06-11T00:00:00Z'),
564+
endTime: new Date('2026-06-11T00:02:00Z'),
565+
project: '/repro/project',
566+
metrics: makeLiveMetrics(1600),
567+
});
568+
569+
// Step 3: re-open /stats.
570+
const records = await loadUsageHistory();
571+
const report = aggregateUsage(records, 'all');
572+
573+
expect(report.sessionCount).toBe(1);
574+
let totalTokens = 0;
575+
for (const m of Object.values(report.models)) totalTokens += m.totalTokens;
576+
expect(totalTokens).toBe(1600);
577+
});
578+
});

packages/core/src/services/usageHistoryService.ts

Lines changed: 27 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -173,7 +173,9 @@ export function metricsToUsageRecord(
173173
};
174174
}
175175

176-
async function rebuildFromSessionJsonl(): Promise<UsageSummaryRecord[]> {
176+
async function rebuildFromSessionJsonl(
177+
skipSessionInRebuild?: string,
178+
): Promise<UsageSummaryRecord[]> {
177179
const projectsDir = path.join(Storage.getGlobalQwenDir(), 'projects');
178180
try {
179181
if (!fs.existsSync(projectsDir)) return [];
@@ -261,23 +263,44 @@ async function rebuildFromSessionJsonl(): Promise<UsageSummaryRecord[]> {
261263
if (results.length > 0) {
262264
const usagePath = getUsageHistoryPath();
263265
for (const record of results) {
266+
// Skip the in-progress current session: persistSessionUsage() will write
267+
// its authoritative record on /clear or exit. Writing here would create
268+
// a permanent duplicate in usage_record.jsonl (issue #4994).
269+
if (skipSessionInRebuild && record.sessionId === skipSessionInRebuild)
270+
continue;
264271
jsonl.writeLineSync(usagePath, record);
265272
}
266273
}
267274

268275
return results;
269276
}
270277

271-
export async function loadUsageHistory(): Promise<UsageSummaryRecord[]> {
278+
function dedupBySessionId(records: UsageSummaryRecord[]): UsageSummaryRecord[] {
279+
// Last-wins by sessionId. Protects existing users whose usage_record.jsonl
280+
// already contains duplicates produced by the bug fixed in this change
281+
// (issue #4994) — without this, every aggregate stays inflated forever.
282+
const map = new Map<string, UsageSummaryRecord>();
283+
for (const r of records) map.set(r.sessionId, r);
284+
if (map.size < records.length) {
285+
debugLogger.debug(
286+
`dedupBySessionId: removed ${records.length - map.size} duplicate record(s)`,
287+
);
288+
}
289+
return [...map.values()];
290+
}
291+
292+
export async function loadUsageHistory(
293+
skipSessionInRebuild?: string,
294+
): Promise<UsageSummaryRecord[]> {
272295
try {
273296
const records = await jsonl.read<UsageSummaryRecord>(getUsageHistoryPath());
274297
const filtered = records.filter((r) => r.version === 1);
275-
if (filtered.length > 0) return filtered;
298+
if (filtered.length > 0) return dedupBySessionId(filtered);
276299
} catch (e) {
277300
debugLogger.debug(`loadUsageHistory: failed to read usage file: ${e}`);
278301
}
279302

280-
return rebuildFromSessionJsonl();
303+
return dedupBySessionId(await rebuildFromSessionJsonl(skipSessionInRebuild));
281304
}
282305

283306
export function getTimeRangeBounds(range: TimeRange): {

0 commit comments

Comments
 (0)