add migration telemetry

This commit is contained in:
Max Paulus 🥪
2026-06-24 14:11:26 +09:00
committed by Dominic Cooney
parent 61ea8688c6
commit f5d0b4fd49
5 changed files with 378 additions and 23 deletions
+1
View File
@@ -309,6 +309,7 @@ export class Controller {
this.taskHistory = new SdkTaskHistory({
mcpHub: this.mcpHub,
sessions: this.sessions,
telemetry: telemetryService,
// History rendering mints ids from the shared authority so regenerated history ids
// never overlap live-session ids.
getMinter: () => this.messageTranslatorState.getMinter(),
+102 -2
View File
@@ -2,6 +2,7 @@ import type { SessionHistoryRecord } from "@cline/core"
import type { HistoryItem } from "@shared/HistoryItem"
import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"
import type { McpHub } from "@/services/mcp/McpHub"
import type { TelemetryService } from "@/services/telemetry/TelemetryService"
import { sdkMessagesToClineMessages } from "./message-translator"
import type { SdkSessionLifecycle } from "./sdk-session-lifecycle"
import { SdkTaskHistory, sessionHistoryRecordToHistoryItem } from "./sdk-task-history"
@@ -26,6 +27,11 @@ vi.mock("@/utils/fs", () => ({
fileExistsAtPath: vi.fn(() => Promise.resolve(false)),
}))
const legacyStateReaderMock = vi.hoisted(() => ({
taskHistory: [] as HistoryItem[],
apiConversationHistory: [] as unknown[],
}))
vi.mock("@/shared/services/Logger", () => ({
Logger: {
error: vi.fn(),
@@ -34,8 +40,20 @@ vi.mock("@/shared/services/Logger", () => ({
},
}))
vi.mock("./legacy-state-reader", () => ({
readTaskHistory: vi.fn(() => legacyStateReaderMock.taskHistory),
readApiConversationHistory: vi.fn(() => legacyStateReaderMock.apiConversationHistory),
}))
vi.mock("./cline-session-factory", async (importOriginal) => ({
...(await importOriginal<typeof import("./cline-session-factory")>()),
buildSessionConfig: vi.fn(async ({ cwd, workspaceRoot, mode }) => ({ cwd, workspaceRoot, mode })),
}))
describe("SdkTaskHistory", () => {
beforeEach(() => {
legacyStateReaderMock.taskHistory = []
legacyStateReaderMock.apiConversationHistory = []
vi.clearAllMocks()
})
@@ -213,6 +231,74 @@ describe("SdkTaskHistory", () => {
expect(deleteSession).toHaveBeenCalledWith("task-1")
})
it("emits telemetry when migrating a legacy task to an SDK session", async () => {
vi.spyOn(Date, "now").mockReturnValue(123_456)
legacyStateReaderMock.taskHistory = [
makeHistoryItem("legacy-task", {
task: "legacy prompt",
isFavorited: true,
tokensIn: 10,
tokensOut: 20,
totalCost: 0.03,
cwdOnTaskInitialization: "/legacy/repo",
}),
]
legacyStateReaderMock.apiConversationHistory = [
{ role: "user", content: "legacy prompt" },
{ role: "assistant", content: "legacy answer" },
]
const telemetry = makeTelemetry()
const { history, startSession } = makeHistory([], telemetry)
await history.getClineMessages("legacy-task")
expect(startSession).toHaveBeenCalledWith(
expect.objectContaining({
config: expect.objectContaining({ sessionId: "legacy-task", cwd: "/legacy/repo" }),
initialMessages: expect.arrayContaining([
expect.objectContaining({ role: "user" }),
expect.objectContaining({ role: "assistant" }),
]),
sessionMetadata: expect.objectContaining({
migratedFromLegacyTask: true,
title: "legacy prompt",
isFavorited: true,
}),
}),
)
expect(telemetry.captureLegacyTaskMigration).toHaveBeenCalledWith(
expect.objectContaining({
taskId: "legacy-task",
outcome: "success",
reason: "migrated",
legacyApiHistoryLength: 2,
convertedMessageCount: 2,
hasFavorite: true,
hasCost: true,
hasTokenUsage: true,
hasCwd: true,
}),
)
})
it("emits backlog telemetry when legacy tasks are still pending migration", async () => {
legacyStateReaderMock.taskHistory = [makeHistoryItem("legacy-task", { task: "legacy prompt" })]
const telemetry = makeTelemetry()
const { history } = makeHistory(
[makeSessionRecord("sdk-task"), makeSessionRecord("migrated", { metadata: { migratedFromLegacyTask: true } })],
telemetry,
)
await history.listHistory({ hydrate: false })
expect(telemetry.captureLegacyTaskMigrationBacklog).toHaveBeenCalledWith({
pendingLegacyTaskCount: 1,
migratedSdkTaskCount: 1,
visibleSdkTaskCount: 2,
visibleTaskCount: 3,
})
})
it("updates usage for an existing SDK task", async () => {
vi.spyOn(Date, "now").mockReturnValue(123_456)
const { history, updateSession } = makeHistory([
@@ -277,7 +363,15 @@ function makeSessionRecord(id: string, overrides: Partial<SessionHistoryRecord>
}
}
function makeHistory(records: SessionHistoryRecord[]) {
function makeTelemetry(): TelemetryService {
return {
safeCapture: vi.fn((fn: () => void) => fn()),
captureLegacyTaskMigration: vi.fn(),
captureLegacyTaskMigrationBacklog: vi.fn(),
} as unknown as TelemetryService
}
function makeHistory(records: SessionHistoryRecord[], telemetry?: TelemetryService) {
let currentRecords = records
const updateSession = vi.fn(
async (
@@ -299,10 +393,15 @@ function makeHistory(records: SessionHistoryRecord[]) {
const getSession = vi.fn(async (sessionId: string) => currentRecords.find((record) => record.sessionId === sessionId))
const listHistory = vi.fn(async () => currentRecords)
const readMessages = vi.fn(async () => [])
const startSession = vi.fn(async (input: { config: { sessionId?: string } }) => {
currentRecords = [makeSessionRecord(input.config.sessionId ?? "started"), ...currentRecords]
return { sessionId: input.config.sessionId }
})
const host = {
get: getSession,
listHistory,
readMessages,
start: startSession,
update: updateSession,
delete: deleteSession,
} as unknown as VscodeSessionHost
@@ -312,7 +411,8 @@ function makeHistory(records: SessionHistoryRecord[]) {
const history = new SdkTaskHistory({
mcpHub: {} as McpHub,
sessions,
telemetry,
})
return { history, getSession, listHistory, updateSession, deleteSession }
return { history, getSession, listHistory, updateSession, deleteSession, startSession }
}
+87 -21
View File
@@ -4,6 +4,7 @@ import { type ContentBlock, formatDisplayUserInput, type MessageWithMetadata } f
import type { ClineMessage } from "@shared/ExtensionMessage"
import type { HistoryItem } from "@shared/HistoryItem"
import type { McpHub } from "@/services/mcp/McpHub"
import type { TelemetryService } from "@/services/telemetry/TelemetryService"
import { Logger } from "@/shared/services/Logger"
import { buildSessionConfig } from "./cline-session-factory"
import { sanitizeInitialMessagesForSessionStart } from "./initial-message-sanitizer"
@@ -39,6 +40,7 @@ export interface SdkTaskHistoryOptions {
* it so regenerated history ids never overlap live-session ids. Optional for tests.
*/
getMinter?: () => MessageIdMinter
telemetry?: TelemetryService
}
type SdkTaskHistoryListOptions = ClineCoreListHistoryOptions & {
@@ -68,6 +70,10 @@ function dateStringToTimestamp(value: string | null | undefined): number {
return Number.isFinite(timestamp) ? timestamp : 0
}
function historyItemHasTokenUsage(item: HistoryItem): boolean {
return (item.tokensIn ?? 0) > 0 || (item.tokensOut ?? 0) > 0 || (item.cacheReads ?? 0) > 0 || (item.cacheWrites ?? 0) > 0
}
function historyItemToSessionHistoryRecord(item: HistoryItem): SessionHistoryRecord {
const startedAt = new Date(item.ts || Date.now()).toISOString()
const displayTask = formatDisplayUserInput(item.task)
@@ -369,6 +375,9 @@ export class SdkTaskHistory {
const legacyHistory = readTaskHistory()
.filter((item) => item.id && item.task && !sdkIds.has(item.id))
.map(historyItemToSessionHistoryRecord)
const migratedSdkTaskCount = visibleSdkHistory.filter(
(item) => metadataBoolean(item.metadata, "migratedFromLegacyTask") === true,
).length
const mergedHistory = [...visibleSdkHistory, ...legacyHistory].sort(
(a, b) =>
@@ -379,6 +388,17 @@ export class SdkTaskHistory {
this.metadataHistoryCache = { records: mergedHistory, hostLimit, createdAt: Date.now() }
}
this.options.telemetry?.safeCapture(
() =>
this.options.telemetry?.captureLegacyTaskMigrationBacklog({
pendingLegacyTaskCount: legacyHistory.length,
migratedSdkTaskCount,
visibleSdkTaskCount: visibleSdkHistory.length,
visibleTaskCount: mergedHistory.length,
}),
"SdkTaskHistory.listHistory.legacyMigrationBacklog",
)
const result = mergedHistory.slice(offset, offset + limit)
return result
}
@@ -394,56 +414,102 @@ export class SdkTaskHistory {
}
private async migrateLegacyTaskIfNeeded(taskId: string): Promise<boolean> {
const startedAt = Date.now()
let sdkLookupFailed = false
let historyItem: HistoryItem | undefined
let legacyApiHistoryLength: number | undefined
let convertedMessageCount: number | undefined
const emitMigrationTelemetry = (args: { outcome: "success" | "skipped" | "error"; reason: string }) => {
const payload = {
taskId,
outcome: args.outcome,
reason: args.reason,
durationMs: Date.now() - startedAt,
legacyApiHistoryLength,
convertedMessageCount,
sdkLookupFailed,
hasFavorite: historyItem?.isFavorited === true,
hasCost: (historyItem?.totalCost ?? 0) > 0,
hasTokenUsage: historyItem ? historyItemHasTokenUsage(historyItem) : undefined,
hasCwd: !!historyItem?.cwdOnTaskInitialization,
}
Logger.log("[SdkTaskHistory] Legacy task migration", payload)
this.options.telemetry?.safeCapture(
() => this.options.telemetry?.captureLegacyTaskMigration(payload),
"SdkTaskHistory.migrateLegacyTaskIfNeeded",
)
}
return this.withHistoryHost(async (host) => {
try {
const existing = await host.get(taskId)
if (existing) {
emitMigrationTelemetry({ outcome: "skipped", reason: "sdk_exists" })
return false
}
} catch (error) {
sdkLookupFailed = true
Logger.warn(`[SdkTaskHistory] Failed to check SDK session before legacy migration: ${taskId}`, error)
}
const historyItem = readTaskHistory().find((item) => item.id === taskId)
historyItem = readTaskHistory().find((item) => item.id === taskId)
if (!historyItem) {
emitMigrationTelemetry({ outcome: "skipped", reason: "legacy_history_missing" })
return false
}
const legacyApiHistory = readApiConversationHistory(taskId)
legacyApiHistoryLength = legacyApiHistory.length
if (legacyApiHistory.length === 0) {
emitMigrationTelemetry({ outcome: "skipped", reason: "legacy_api_history_empty" })
return false
}
const initialMessages = legacyApiHistoryToSdkMessages(legacyApiHistory, historyItem)
convertedMessageCount = initialMessages.length
if (initialMessages.length === 0) {
emitMigrationTelemetry({ outcome: "skipped", reason: "converted_messages_empty" })
return false
}
const cwd = historyItem.cwdOnTaskInitialization || process.cwd()
const config = await buildSessionConfig({ cwd, workspaceRoot: cwd, mode: "act" })
config.sessionId = taskId
let config: Awaited<ReturnType<typeof buildSessionConfig>>
try {
config = await buildSessionConfig({ cwd, workspaceRoot: cwd, mode: "act" })
config.sessionId = taskId
} catch (error) {
emitMigrationTelemetry({ outcome: "error", reason: "config_failed" })
throw error
}
await host.start({
config,
prompt: undefined,
interactive: true,
initialMessages,
sessionMetadata: {
title: historyItem.task,
isFavorited: historyItem.isFavorited ?? false,
size: historyItem.size ?? 0,
totalCost: historyItem.totalCost ?? 0,
tokensIn: historyItem.tokensIn ?? 0,
tokensOut: historyItem.tokensOut ?? 0,
cacheWrites: historyItem.cacheWrites ?? 0,
cacheReads: historyItem.cacheReads ?? 0,
modelId: historyItem.modelId ?? "",
migratedFromLegacyTask: true,
},
})
try {
await host.start({
config,
prompt: undefined,
interactive: true,
initialMessages,
sessionMetadata: {
title: historyItem.task,
isFavorited: historyItem.isFavorited ?? false,
size: historyItem.size ?? 0,
totalCost: historyItem.totalCost ?? 0,
tokensIn: historyItem.tokensIn ?? 0,
tokensOut: historyItem.tokensOut ?? 0,
cacheWrites: historyItem.cacheWrites ?? 0,
cacheReads: historyItem.cacheReads ?? 0,
modelId: historyItem.modelId ?? "",
migratedFromLegacyTask: true,
},
})
} catch (error) {
emitMigrationTelemetry({ outcome: "error", reason: "write_failed" })
throw error
}
this.invalidateMetadataHistoryCache()
Logger.log(`[SdkTaskHistory] Migrated legacy task to SDK session: ${taskId}`)
emitMigrationTelemetry({ outcome: "success", reason: "migrated" })
return true
})
}
@@ -193,6 +193,26 @@ export class TelemetryService {
GRPC: {
RESPONSE_SIZE_BYTES: "cline.grpc.response.size_bytes",
},
MIGRATION: {
// Fires whenever Cline checks an old pre-SDK task and decides whether/how to migrate it.
LEGACY_TASK_ATTEMPTS_TOTAL: "cline.migration.legacy_task.attempts.total",
// Fires when the user opens an old task and Cline successfully copies it into SDK session storage.
LEGACY_TASK_SUCCESS_TOTAL: "cline.migration.legacy_task.success.total",
// Fires when Cline tried to migrate an old task but failed while building or writing the SDK session.
LEGACY_TASK_FAILURES_TOTAL: "cline.migration.legacy_task.failures.total",
// Fires when no migration happens because it is unnecessary or impossible, e.g. already migrated or missing old messages.
LEGACY_TASK_SKIPPED_TOTAL: "cline.migration.legacy_task.skipped.total",
// Fires for every migration decision; measures how long the check/migration took.
LEGACY_TASK_DURATION_SECONDS: "cline.migration.legacy_task.duration.seconds",
// Fires when Cline finds old conversation messages; records how many old messages were found.
LEGACY_TASK_LEGACY_MESSAGES_COUNT: "cline.migration.legacy_task.legacy_messages.count",
// Fires after conversion; records how many messages made it into SDK-compatible form.
LEGACY_TASK_CONVERTED_MESSAGES_COUNT: "cline.migration.legacy_task.converted_messages.count",
// Fires when history is listed; counts old pre-SDK tasks still waiting to be migrated.
LEGACY_TASK_PENDING_COUNT: "cline.migration.legacy_task.pending.count",
// Fires when history is listed; counts old tasks that already made it safely into SDK session storage.
LEGACY_TASK_MIGRATED_COUNT: "cline.migration.legacy_task.migrated.count",
},
}
// Event constants for tracking user interactions and system events
private static readonly EVENTS = {
@@ -250,6 +270,8 @@ export class TelemetryService {
MCP_TOOL_CALLED: "task.mcp_tool_called",
// Tracks when a historical task is loaded from storage
HISTORICAL_LOADED: "task.historical_loaded",
// Tracks legacy VS Code task history migration into SDK sessions
LEGACY_TASK_MIGRATION: "task.legacy_task_migration",
// Tracks when the retry button is clicked for failed operations
RETRY_CLICKED: "task.retry_clicked",
// Tracks when a diff edit (replace_in_file) operation fails
@@ -2376,6 +2398,129 @@ export class TelemetryService {
* @param method The gRPC method name
* @param requestId Optional request ID for correlation
*/
public captureLegacyTaskMigration(args: {
taskId: string
outcome: "success" | "skipped" | "error"
reason: string
durationMs: number
legacyApiHistoryLength?: number
convertedMessageCount?: number
sdkLookupFailed?: boolean
hasFavorite?: boolean
hasCost?: boolean
hasTokenUsage?: boolean
hasCwd?: boolean
}): void {
const migrationType = "legacy_task_to_sdk_session"
const metricAttributes = {
migration_type: migrationType,
outcome: args.outcome,
reason: args.reason,
}
this.capture({
event: TelemetryService.EVENTS.TASK.LEGACY_TASK_MIGRATION,
properties: {
ulid: args.taskId,
migration_type: migrationType,
outcome: args.outcome,
reason: args.reason,
durationMs: args.durationMs,
legacyApiHistoryLength: args.legacyApiHistoryLength,
convertedMessageCount: args.convertedMessageCount,
sdkLookupFailed: args.sdkLookupFailed,
hasFavorite: args.hasFavorite,
hasCost: args.hasCost,
hasTokenUsage: args.hasTokenUsage,
hasCwd: args.hasCwd,
},
})
this.recordCounter(
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_ATTEMPTS_TOTAL,
1,
metricAttributes,
"Legacy VS Code task migration decisions",
)
if (args.outcome === "success") {
this.recordCounter(
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_SUCCESS_TOTAL,
1,
metricAttributes,
"Legacy VS Code tasks successfully copied into SDK session storage",
)
} else if (args.outcome === "error") {
this.recordCounter(
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_FAILURES_TOTAL,
1,
metricAttributes,
"Legacy VS Code task migrations that failed while building or writing the SDK session",
)
} else {
this.recordCounter(
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_SKIPPED_TOTAL,
1,
metricAttributes,
"Legacy VS Code task migration checks that did not need or could not perform a migration",
)
}
this.recordHistogram(
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_DURATION_SECONDS,
args.durationMs / 1000,
metricAttributes,
"Time spent checking or migrating a legacy VS Code task into SDK session storage",
)
if (args.legacyApiHistoryLength !== undefined) {
this.recordHistogram(
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_LEGACY_MESSAGES_COUNT,
args.legacyApiHistoryLength,
metricAttributes,
"Number of raw legacy API history messages found while migrating a legacy VS Code task",
)
}
if (args.convertedMessageCount !== undefined) {
this.recordHistogram(
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_CONVERTED_MESSAGES_COUNT,
args.convertedMessageCount,
metricAttributes,
"Number of SDK-compatible messages produced from a legacy VS Code task migration",
)
}
}
public captureLegacyTaskMigrationBacklog(args: {
pendingLegacyTaskCount: number
migratedSdkTaskCount: number
visibleSdkTaskCount: number
visibleTaskCount: number
}): void {
const attributes = { migration_type: "legacy_task_to_sdk_session" }
this.recordGauge(
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_PENDING_COUNT,
args.pendingLegacyTaskCount,
attributes,
"Legacy VS Code tasks visible in history but not yet migrated to SDK sessions",
)
this.recordGauge(
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_MIGRATED_COUNT,
args.migratedSdkTaskCount,
attributes,
"SDK sessions marked as migrated from legacy VS Code task history",
)
this.capture({
event: TelemetryService.EVENTS.TASK.LEGACY_TASK_MIGRATION,
properties: {
migration_type: "legacy_task_to_sdk_session",
outcome: "backlog",
pendingLegacyTaskCount: args.pendingLegacyTaskCount,
migratedSdkTaskCount: args.migratedSdkTaskCount,
visibleSdkTaskCount: args.visibleSdkTaskCount,
visibleTaskCount: args.visibleTaskCount,
},
})
}
public captureGrpcResponseSize(sizeUtf8Bytes: number, service: string, method: string, requestId?: string): void {
this.recordHistogram(
TelemetryService.METRICS.GRPC.RESPONSE_SIZE_BYTES,
@@ -383,4 +383,47 @@ describe("TelemetryService metrics", () => {
assert.strictEqual(entry.attributes.extension_version, "test")
assert.strictEqual(entry.attributes.platform, "test-platform")
})
it("captureLegacyTaskMigration emits event and migration metrics", () => {
const provider = new FakeProvider()
const service = createTelemetryService(provider)
service.captureLegacyTaskMigration({
taskId: "legacy-task",
outcome: "success",
reason: "migrated",
durationMs: 250,
legacyApiHistoryLength: 3,
convertedMessageCount: 2,
hasFavorite: true,
hasCost: true,
hasTokenUsage: true,
hasCwd: true,
})
const event = provider.logs.find((entry) => entry.event === "task.legacy_task_migration")
assert.ok(event)
assert.strictEqual(event?.properties?.ulid, "legacy-task")
assert.strictEqual(event?.properties?.outcome, "success")
assert.strictEqual(event?.properties?.legacyApiHistoryLength, 3)
assert.deepStrictEqual(
provider.counters.map((entry) => entry.name),
[
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_ATTEMPTS_TOTAL,
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_SUCCESS_TOTAL,
],
)
assert.deepStrictEqual(
provider.histograms.map((entry) => entry.name),
[
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_DURATION_SECONDS,
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_LEGACY_MESSAGES_COUNT,
TelemetryService.METRICS.MIGRATION.LEGACY_TASK_CONVERTED_MESSAGES_COUNT,
],
)
assert.strictEqual(provider.histograms[0].value, 0.25)
assert.strictEqual(provider.histograms[0].attributes.migration_type, "legacy_task_to_sdk_session")
assert.strictEqual(provider.histograms[0].attributes.reason, "migrated")
})
})