Skip to content

Commit d430a18

Browse files
committed
feat(telemetry): report task completion telemetry on every attempt_completion call
1 parent 413021a commit d430a18

9 files changed

Lines changed: 508 additions & 17 deletions

File tree

packages/telemetry/src/TelemetryService.ts

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -171,14 +171,27 @@ export class TelemetryService {
171171
* Captures task completion, optionally summarizing the per-task tool and
172172
* message counts that were previously reported as separate per-turn events
173173
* (`Tool Used`, `Conversation Message`) to reduce Product Analytics volume.
174+
*
175+
* A single task may emit this more than once over its lifetime (e.g. an
176+
* "idle" or "shutdown" installment followed later by a final
177+
* "attempt_completion" one) -- toolsUsed/messageCount are always the delta
178+
* since the previous emission for that task, not a running total, so
179+
* summing installments for a taskId reconstructs the full-task counts
180+
* without double-counting.
181+
*
182+
* Note "attempt_completion" means the model called that tool, not that the
183+
* user accepted the result -- it fires the same way whether the user goes
184+
* on to accept, decline, or give feedback instead.
174185
*/
175186
public captureTaskCompleted(
176187
taskId: string,
177188
toolsUsed?: ToolUsage,
178189
messageCount?: { user: number; assistant: number },
190+
completionReason: "attempt_completion" | "idle" | "shutdown" = "attempt_completion",
179191
): void {
180192
this.captureEvent(TelemetryEventName.TASK_COMPLETED, {
181193
taskId,
194+
completionReason,
182195
...(toolsUsed !== undefined && { toolsUsed }),
183196
...(messageCount !== undefined && { messageCount }),
184197
})

packages/telemetry/src/__tests__/TelemetryService.task-completed.test.ts

Lines changed: 18 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -18,14 +18,14 @@ describe("TelemetryService.captureTaskCompleted", () => {
1818
}
1919
})
2020

21-
it("captures Task Completed with the taskId when no summary is provided", () => {
21+
it("captures Task Completed with the taskId and a default 'attempt_completion' completionReason when no summary is provided", () => {
2222
const service = new TelemetryService([mockClient])
2323

2424
service.captureTaskCompleted("task_1")
2525

2626
expect(mockClient.capture).toHaveBeenCalledWith({
2727
event: TelemetryEventName.TASK_COMPLETED,
28-
properties: { taskId: "task_1" },
28+
properties: { taskId: "task_1", completionReason: "attempt_completion" },
2929
})
3030
})
3131

@@ -42,9 +42,25 @@ describe("TelemetryService.captureTaskCompleted", () => {
4242
event: TelemetryEventName.TASK_COMPLETED,
4343
properties: {
4444
taskId: "task_1",
45+
completionReason: "attempt_completion",
4546
toolsUsed: { read_file: { attempts: 3, failures: 0 }, apply_diff: { attempts: 1, failures: 1 } },
4647
messageCount: { user: 4, assistant: 5 },
4748
},
4849
})
4950
})
51+
52+
it("includes the given completionReason for idle/shutdown installments", () => {
53+
const service = new TelemetryService([mockClient])
54+
55+
service.captureTaskCompleted("task_1", { read_file: { attempts: 1, failures: 0 } }, undefined, "idle")
56+
57+
expect(mockClient.capture).toHaveBeenCalledWith({
58+
event: TelemetryEventName.TASK_COMPLETED,
59+
properties: {
60+
taskId: "task_1",
61+
completionReason: "idle",
62+
toolsUsed: { read_file: { attempts: 1, failures: 0 } },
63+
},
64+
})
65+
})
5066
})

packages/types/src/telemetry.ts

Lines changed: 12 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -140,15 +140,25 @@ export const taskPropertiesSchema = z.object({
140140
pending: z.number(),
141141
})
142142
.optional(),
143-
// Per-task tool/message summaries, captured once on Task Completed instead
144-
// of as separate per-turn events (reduces Product Analytics volume).
143+
// Per-task tool/message summaries, captured once per Task Completed
144+
// installment instead of as separate per-turn events (reduces Product
145+
// Analytics volume). A single task may emit more than one installment
146+
// (see completionReason); each installment's counts are the delta since
147+
// the previous installment for that taskId, not a running total.
145148
toolsUsed: z.record(z.string(), z.object({ attempts: z.number(), failures: z.number() })).optional(),
146149
messageCount: z
147150
.object({
148151
user: z.number(),
149152
assistant: z.number(),
150153
})
151154
.optional(),
155+
// Why this Task Completed installment was emitted: the model called
156+
// attempt_completion ("attempt_completion" -- regardless of whether the
157+
// user went on to accept, decline, or give feedback; this is NOT a signal
158+
// that the user accepted the result), the task went idle with unreported
159+
// activity ("idle"), or the extension/task was shut down with unreported
160+
// activity still pending ("shutdown").
161+
completionReason: z.enum(["attempt_completion", "idle", "shutdown"]).optional(),
152162
})
153163

154164
export type TaskProperties = z.infer<typeof taskPropertiesSchema>

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

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -199,10 +199,12 @@ describe("Nested delegation resume (A → B → C)", () => {
199199
emit: vi.fn(),
200200
getTokenUsage: vi.fn(() => ({})),
201201
toolUsage: {},
202+
messageCounts: { user: 0, assistant: 0 },
202203
clineMessages: [],
203204
userMessageContent: [],
204205
consecutiveMistakeCount: 0,
205206
emitFinalTokenUsageUpdate: vi.fn(),
207+
flushTelemetryInstallment: vi.fn(),
206208
} as unknown as Task
207209

208210
const blockC = {
@@ -246,10 +248,12 @@ describe("Nested delegation resume (A → B → C)", () => {
246248
emit: vi.fn(),
247249
getTokenUsage: vi.fn(() => ({})),
248250
toolUsage: {},
251+
messageCounts: { user: 0, assistant: 0 },
249252
clineMessages: [],
250253
userMessageContent: [],
251254
consecutiveMistakeCount: 0,
252255
emitFinalTokenUsageUpdate: vi.fn(),
256+
flushTelemetryInstallment: vi.fn(),
253257
} as unknown as Task
254258

255259
const blockB = {

src/core/task/Task.ts

Lines changed: 94 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -322,10 +322,25 @@ export class Task extends EventEmitter<TaskEvents> implements TaskLike {
322322
consecutiveNoAssistantMessagesCount: number = 0
323323
toolUsage: ToolUsage = {}
324324

325-
// Conversation message counts, summarized once on Task Completed instead
326-
// of emitting a separate telemetry event per turn.
325+
// Conversation message counts, summarized once per Task Completed
326+
// installment instead of emitting a separate telemetry event per turn.
327327
messageCounts: { user: number; assistant: number } = { user: 0, assistant: 0 }
328328

329+
// Idle/shutdown telemetry flush: reports toolUsage/messageCounts for tasks that
330+
// go quiet or get torn down without the model ever calling attempt_completion
331+
// (or without the user accepting it), so long-running/abandoned tasks aren't
332+
// invisible to telemetry. Each flush reports only what changed since the previous
333+
// one, tracked via telemetryToolUsageBaseline/telemetryMessageCountsBaseline --
334+
// task.toolUsage/messageCounts themselves are never mutated by this, since they're
335+
// also read as running totals by the public TaskCompleted API event and the UI.
336+
// Checked on an interval rather than hooked into every say()/ask() call site.
337+
private static readonly IDLE_TELEMETRY_CHECK_INTERVAL_MS = 5 * 60 * 1000
338+
private static readonly IDLE_TELEMETRY_THRESHOLD_MS = 30 * 60 * 1000
339+
private idleTelemetryCheckInterval?: NodeJS.Timeout
340+
private lastTelemetryFlushAt: number = Date.now()
341+
private telemetryToolUsageBaseline: ToolUsage = {}
342+
private telemetryMessageCountsBaseline: { user: number; assistant: number } = { user: 0, assistant: 0 }
343+
329344
// Checkpoints
330345
enableCheckpoints: boolean
331346
checkpointTimeout: number
@@ -598,6 +613,8 @@ export class Task extends EventEmitter<TaskEvents> implements TaskLike {
598613
{ leading: true, trailing: true, maxWait: this.TOKEN_USAGE_EMIT_INTERVAL_MS },
599614
)
600615

616+
this.startIdleTelemetryCheck()
617+
601618
onCreated?.(this)
602619

603620
if (startTask) {
@@ -2237,6 +2254,17 @@ export class Task extends EventEmitter<TaskEvents> implements TaskLike {
22372254
public dispose(): void {
22382255
console.log(`[Task#dispose] disposing task ${this.taskId}.${this.instanceId}`)
22392256

2257+
// Stop the idle telemetry check and report any unflushed activity as a
2258+
// shutdown installment, so a task torn down mid-work (panel closed, task
2259+
// switched, extension deactivated) isn't invisible to telemetry.
2260+
try {
2261+
clearInterval(this.idleTelemetryCheckInterval)
2262+
this.idleTelemetryCheckInterval = undefined
2263+
this.flushTelemetryInstallment("shutdown")
2264+
} catch (error) {
2265+
console.error("Error flushing shutdown telemetry:", error)
2266+
}
2267+
22402268
// Cancel any in-progress HTTP request
22412269
try {
22422270
this.cancelCurrentRequest()
@@ -4644,6 +4672,70 @@ export class Task extends EventEmitter<TaskEvents> implements TaskLike {
46444672
}
46454673
}
46464674

4675+
/**
4676+
* Emits a Task Completed installment for whatever toolUsage/messageCounts have
4677+
* changed since the previous installment (from any reason), then advances the
4678+
* telemetry baseline so a later installment reports only its own delta. Does
4679+
* NOT touch task.toolUsage/messageCounts themselves -- those stay running totals
4680+
* for the public TaskCompleted API event and the UI. No-ops if nothing changed
4681+
* since the last installment, so idle/shutdown checks don't emit empty events
4682+
* for tasks that were already fully reported (e.g. right after attempt_completion).
4683+
*/
4684+
public flushTelemetryInstallment(reason: "attempt_completion" | "idle" | "shutdown"): void {
4685+
const toolUsageDelta: ToolUsage = {}
4686+
4687+
for (const [toolName, usage] of Object.entries(this.toolUsage) as [ToolName, ToolUsage[ToolName]][]) {
4688+
if (!usage) {
4689+
continue
4690+
}
4691+
4692+
const baseline = this.telemetryToolUsageBaseline[toolName]
4693+
const attempts = usage.attempts - (baseline?.attempts ?? 0)
4694+
const failures = usage.failures - (baseline?.failures ?? 0)
4695+
4696+
if (attempts > 0 || failures > 0) {
4697+
toolUsageDelta[toolName] = { attempts, failures }
4698+
}
4699+
}
4700+
4701+
const messageCountDelta = {
4702+
user: this.messageCounts.user - this.telemetryMessageCountsBaseline.user,
4703+
assistant: this.messageCounts.assistant - this.telemetryMessageCountsBaseline.assistant,
4704+
}
4705+
4706+
const hasToolUsageDelta = Object.keys(toolUsageDelta).length > 0
4707+
const hasMessageDelta = messageCountDelta.user > 0 || messageCountDelta.assistant > 0
4708+
4709+
if (!hasToolUsageDelta && !hasMessageDelta) {
4710+
return
4711+
}
4712+
4713+
this.emitFinalTokenUsageUpdate()
4714+
TelemetryService.instance.captureTaskCompleted(this.taskId, toolUsageDelta, messageCountDelta, reason)
4715+
4716+
this.telemetryToolUsageBaseline = JSON.parse(JSON.stringify(this.toolUsage))
4717+
this.telemetryMessageCountsBaseline = { ...this.messageCounts }
4718+
this.lastTelemetryFlushAt = Date.now()
4719+
}
4720+
4721+
private startIdleTelemetryCheck(): void {
4722+
this.idleTelemetryCheckInterval = setInterval(() => {
4723+
// lastMessageTs only moves forward on activity, so comparing it against the
4724+
// last flush tells us whether anything happened since that flush -- if the
4725+
// task has been quiet since well before the last flush, there's nothing new
4726+
// to report and flushTelemetryInstallment's own empty-check would no-op anyway,
4727+
// but skipping here avoids waking up to do that check needlessly.
4728+
const idleForMs = Date.now() - (this.lastMessageTs ?? this.lastTelemetryFlushAt)
4729+
4730+
if (idleForMs >= Task.IDLE_TELEMETRY_THRESHOLD_MS) {
4731+
this.flushTelemetryInstallment("idle")
4732+
}
4733+
}, Task.IDLE_TELEMETRY_CHECK_INTERVAL_MS)
4734+
4735+
// Don't hold the process open just for this timer.
4736+
this.idleTelemetryCheckInterval?.unref?.()
4737+
}
4738+
46474739
// Getters
46484740

46494741
public get taskStatus(): TaskStatus {

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

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -304,6 +304,10 @@ describe("Task persistence", () => {
304304
task: "test task",
305305
startTask: false,
306306
})
307+
// Dispose the idle-telemetry-check interval before running all timers, so
308+
// runAllTimersAsync doesn't treat it as an infinite loop (it's unrelated
309+
// to what this test exercises).
310+
task.dispose()
307311

308312
const promise = task.retrySaveApiConversationHistory()
309313
await vi.runAllTimersAsync()
@@ -326,6 +330,10 @@ describe("Task persistence", () => {
326330
task: "test task",
327331
startTask: false,
328332
})
333+
// Dispose the idle-telemetry-check interval before running all timers, so
334+
// runAllTimersAsync doesn't treat it as an infinite loop (it's unrelated
335+
// to what this test exercises).
336+
task.dispose()
329337

330338
const promise = task.retrySaveApiConversationHistory()
331339
await vi.runAllTimersAsync()

0 commit comments

Comments
 (0)