Skip to content

Commit d65a372

Browse files
committed
fix(telemetry): advance baseline before emit to prevent double-reporting on throw
1 parent 2165cdf commit d65a372

4 files changed

Lines changed: 48 additions & 5 deletions

File tree

src/__tests__/history-resume-delegation.spec.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -26,7 +26,7 @@ vi.mock("vscode", () => {
2626
return { window, workspace, env, Uri, commands, ExtensionMode, version }
2727
})
2828

29-
// Mock TelemetryService (needed by attemptCompletionTool's emitTaskCompleted)
29+
// Mock TelemetryService (needed by attemptCompletionTool's emitPublicTaskCompleted)
3030
vi.mock("@roo-code/telemetry", () => ({
3131
TelemetryService: {
3232
instance: {

src/core/task/Task.ts

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -4767,12 +4767,16 @@ export class Task extends EventEmitter<TaskEvents> implements TaskLike {
47674767
return
47684768
}
47694769

4770-
this.emitFinalTokenUsageUpdate()
4771-
TelemetryService.instance.captureTaskCompleted(this.taskId, toolUsageDelta, messageCountDelta, reason)
4772-
4770+
// Advance the baseline before emitting so a synchronous throw from an
4771+
// EventEmitter listener or TelemetryService client cannot leave the baseline
4772+
// behind the running totals, which would cause the same delta to re-appear
4773+
// on the next flush. The delta values are already captured in locals above.
47734774
this.telemetryToolUsageBaseline = JSON.parse(JSON.stringify(this.toolUsage))
47744775
this.telemetryMessageCountsBaseline = { ...this.messageCounts }
47754776
this.lastTelemetryFlushAt = Date.now()
4777+
4778+
this.emitFinalTokenUsageUpdate()
4779+
TelemetryService.instance.captureTaskCompleted(this.taskId, toolUsageDelta, messageCountDelta, reason)
47764780
}
47774781

47784782
startIdleTelemetryCheck(): void {

src/core/task/__tests__/Task.spec.ts

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3252,6 +3252,40 @@ describe("Telemetry installments (idle/shutdown flush)", () => {
32523252

32533253
expect(captureTaskCompletedSpy).not.toHaveBeenCalled()
32543254
})
3255+
3256+
it("does not re-flush when lastMessageTs is recent even after a prior flush", () => {
3257+
// Regression guard for the Math.max(lastMessageTs, lastTelemetryFlushAt) fix.
3258+
// Without it, once lastMessageTs is set it never advances after a flush, so
3259+
// the idle check would fire on every 5-minute tick for the rest of the task's
3260+
// life even with no new activity.
3261+
vi.useFakeTimers()
3262+
const task = createTask()
3263+
task.recordToolUsage("read_file")
3264+
3265+
// First idle flush fires after 31 min.
3266+
vi.advanceTimersByTime(31 * 60 * 1000)
3267+
expect(captureTaskCompletedSpy).toHaveBeenCalledTimes(1)
3268+
captureTaskCompletedSpy.mockClear()
3269+
3270+
// New activity arrives 1 min after the flush.
3271+
vi.advanceTimersByTime(1 * 60 * 1000)
3272+
task.lastMessageTs = Date.now()
3273+
task.recordToolUsage("write_to_file")
3274+
3275+
// Only 10 min since the new activity — should not flush again yet.
3276+
vi.advanceTimersByTime(10 * 60 * 1000)
3277+
expect(captureTaskCompletedSpy).not.toHaveBeenCalled()
3278+
3279+
// 35 min since the new activity (past the 30-min threshold and the next
3280+
// 5-min interval tick) — should flush the new delta now.
3281+
vi.advanceTimersByTime(25 * 60 * 1000)
3282+
expect(captureTaskCompletedSpy).toHaveBeenCalledWith(
3283+
task.taskId,
3284+
{ write_to_file: { attempts: 1, failures: 0 } },
3285+
{ user: 0, assistant: 0 },
3286+
"idle",
3287+
)
3288+
})
32553289
})
32563290

32573291
describe("dispose", () => {

src/core/tools/__tests__/attemptCompletionTool.spec.ts

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -591,7 +591,12 @@ describe("attemptCompletionTool", () => {
591591
expect(mockPushToolResult).not.toHaveBeenCalledWith("")
592592
// Emission now happens once per validated attempt_completion call, before
593593
// delegation is attempted -- independent of whether delegation succeeds.
594-
expect(mockCaptureTaskCompleted).toHaveBeenCalledTimes(1)
594+
expect(mockCaptureTaskCompleted).toHaveBeenCalledWith(
595+
mockTask.taskId,
596+
mockTask.toolUsage,
597+
mockTask.messageCounts,
598+
"attempt_completion",
599+
)
595600
})
596601

597602
it("does not resume the parent when the parent is no longer awaiting this child", async () => {

0 commit comments

Comments
 (0)