Skip to content

Commit ded1b6d

Browse files
committed
fix(telemetry): address second review pass
1 parent cdaf9ae commit ded1b6d

58 files changed

Lines changed: 826 additions & 128 deletions

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

PRIVACY.md

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,14 @@ go—and, importantly, where they don't.
4040
We retain telemetry only as long as needed for product analytics and
4141
debugging. This PostHog-based telemetry does **not** collect your code or AI
4242
prompts, and you can opt out at any time through the settings.
43+
- **Zoo Code Cloud Task Sync**: If you sign in to Zoo Code Cloud, your task
44+
history — including your prompts and the assistant's responses — is uploaded
45+
to and stored on Zoo Code's servers so you can view and resume tasks across
46+
devices. This is separate from, and more than, the PostHog usage telemetry
47+
described above. Task sync is on by default once you're signed in (or follows
48+
your organization's policy if your account belongs to one); you can turn it
49+
off in Zoo Code Cloud account settings, and signing out of Zoo Code Cloud
50+
stops it entirely.
4351
- **Marketplace Requests**: When you browse or search the Marketplace for Model
4452
Configuration Profiles (MCPs) or Custom Modes, Zoo Code makes a secure API
4553
call to Zoo Code's backend servers to retrieve listing information. These

packages/telemetry/src/TelemetryService.ts

Lines changed: 35 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,15 @@ const CIRCUIT_BREAKER_WINDOW_MS = 10 * 60 * 1000
2626
/** How long a tripped breaker stays tripped before allowing captures again. */
2727
const CIRCUIT_BREAKER_COOLDOWN_MS = 10 * 60 * 1000
2828

29+
/**
30+
* Upper bound on how long shutdown() will wait for in-flight capture calls to drain.
31+
* deactivate() awaits shutdown() before terminal cleanup, so an unbounded wait here
32+
* (e.g. a capture stuck on network I/O that never resolves/rejects) would block the
33+
* extension host from ever finishing deactivation. Losing an in-flight capture on
34+
* timeout is an acceptable tradeoff against blocking shutdown indefinitely.
35+
*/
36+
const SHUTDOWN_DRAIN_TIMEOUT_MS = 3000
37+
2938
/**
3039
* TelemetryService wrapper class that defers initialization.
3140
* This ensures that we only create the various clients after environment
@@ -43,6 +52,10 @@ export class TelemetryService {
4352
// still mid-flight when shutdown() runs could be lost entirely.
4453
private pendingClientCalls = new Set<Promise<unknown>>()
4554

55+
// Set at the start of shutdown() so new captureEvent/captureException calls stop being
56+
// tracked (and, once clients are closing, stop being sent) instead of racing the drain.
57+
private isShuttingDown = false
58+
4659
constructor(private clients: TelemetryClient[]) {}
4760

4861
private trackPendingClientCall(promise: Promise<unknown>): void {
@@ -133,7 +146,7 @@ export class TelemetryService {
133146
*/
134147
// eslint-disable-next-line @typescript-eslint/no-explicit-any
135148
public captureEvent(eventName: TelemetryEventName, properties?: Record<string, any>): void {
136-
if (!this.isReady) {
149+
if (!this.isReady || this.isShuttingDown) {
137150
return
138151
}
139152

@@ -150,7 +163,7 @@ export class TelemetryService {
150163
* @param additionalProperties Additional properties to include with the exception
151164
*/
152165
public captureException(error: Error, additionalProperties?: Record<string, unknown>): void {
153-
if (!this.isReady) {
166+
if (!this.isReady || this.isShuttingDown) {
154167
return
155168
}
156169

@@ -182,6 +195,11 @@ export class TelemetryService {
182195
* Note "attempt_completion" means the model called that tool, not that the
183196
* user accepted the result -- it fires the same way whether the user goes
184197
* on to accept, decline, or give feedback instead.
198+
*
199+
* IMPORTANT for anyone querying this event (e.g. a PostHog dashboard/funnel):
200+
* "one row" no longer means "one finished task". Group by taskId and sum
201+
* toolsUsed/messageCount across completionReason installments -- do not
202+
* treat `count()` of raw events as a count of completed tasks.
185203
*/
186204
public captureTaskCompleted(
187205
taskId: string,
@@ -370,12 +388,23 @@ export class TelemetryService {
370388
return
371389
}
372390

391+
// Stop accepting new captures immediately, before draining -- otherwise a steady trickle
392+
// of new calls (e.g. from a teardown-time error handler) could keep pendingClientCalls
393+
// non-empty indefinitely and the drain loop below would never terminate on its own.
394+
this.isShuttingDown = true
395+
373396
// Drain any in-flight capture/captureException calls first, so a client's shutdown()
374397
// (which flushes its queue) can't run ahead of a capture that hasn't been enqueued yet.
375-
// Loop rather than a single snapshot: a call queued while draining (e.g. from a
376-
// teardown-time error handler) would otherwise be missed by one Promise.all pass.
377-
while (this.pendingClientCalls.size > 0) {
378-
await Promise.all(this.pendingClientCalls)
398+
// Loop rather than a single snapshot: a call already in flight when draining started may
399+
// itself still be tracked by the time we check again. Bounded by a timeout so a capture
400+
// stuck on network I/O that never resolves/rejects can't block deactivate() forever --
401+
// losing that one capture is an acceptable tradeoff against hanging terminal cleanup.
402+
const drainStart = Date.now()
403+
while (this.pendingClientCalls.size > 0 && Date.now() - drainStart < SHUTDOWN_DRAIN_TIMEOUT_MS) {
404+
await Promise.race([
405+
Promise.all(this.pendingClientCalls),
406+
new Promise((resolve) => setTimeout(resolve, SHUTDOWN_DRAIN_TIMEOUT_MS - (Date.now() - drainStart))),
407+
])
379408
}
380409

381410
await Promise.all(this.clients.map((client) => client.shutdown()))

packages/telemetry/src/__tests__/TelemetryService.shutdown.test.ts

Lines changed: 69 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -44,14 +44,15 @@ describe("TelemetryService.shutdown draining", () => {
4444
expect(captureOrder).toEqual(["captured", "shutdown"])
4545
})
4646

47-
it("drains a second capture that gets queued after shutdown() has already started draining", async () => {
47+
it("drains a call already queued before shutdown() started, even across multiple drain passes", async () => {
4848
// Regression test: shutdown() must not take a single Promise.all snapshot of
4949
// pendingClientCalls. A promise added to pendingClientCalls *after* Promise.all(set)
5050
// has already been called is never awaited by that call, even if it never resolves
51-
// -- Promise.all takes its list of promises to await synchronously, at call time.
52-
// So a second capture queued while the first Promise.all pass is still pending (e.g.
53-
// a teardown-time error handler reacting to something unrelated) would be silently
54-
// dropped by a single-pass drain, letting client.shutdown() run without it.
51+
// -- Promise.all takes its list of promises to await synchronously, at call time. So a
52+
// capture that was already in flight (tracked in pendingClientCalls) when shutdown()
53+
// took its first Promise.all snapshot, but whose *own* async chain enqueues more work
54+
// tracked via a fresh pendingClientCalls entry, must still be drained by a later pass
55+
// of the loop rather than being silently dropped by a single-pass drain.
5556
let resolveFirstCapture!: () => void
5657
const firstCapturePromise = new Promise<void>((resolve) => {
5758
resolveFirstCapture = resolve
@@ -88,15 +89,15 @@ describe("TelemetryService.shutdown draining", () => {
8889

8990
const service = new TelemetryService([mockClient])
9091

92+
// Both captures are fired *before* shutdown() is called, so both are legitimately
93+
// in flight (tracked in pendingClientCalls) at the moment shutdown() takes its first
94+
// snapshot -- unlike a capture fired after shutdown() has started, which is expected
95+
// to be gated out instead (see the "stops accepting new captures" test below).
9196
service.captureEvent(TelemetryEventName.TASK_CREATED, { taskId: "first" })
97+
service.captureEvent(TelemetryEventName.TASK_CREATED, { taskId: "second" })
9298

9399
const shutdownPromise = service.shutdown()
94100

95-
// Queue the second capture synchronously, immediately after shutdown() has started
96-
// (and thus after its first Promise.all(pendingClientCalls) pass has already taken
97-
// its snapshot). This is the scenario the loop fix protects against.
98-
service.captureEvent(TelemetryEventName.TASK_CREATED, { taskId: "second" })
99-
100101
resolveFirstCapture()
101102
// Flush several microtask ticks so a buggy single-pass drain has every opportunity
102103
// to run client.shutdown() before we check -- a couple of ticks isn't enough since
@@ -116,6 +117,64 @@ describe("TelemetryService.shutdown draining", () => {
116117
expect(captureOrder).toEqual(["first-captured", "second-captured", "shutdown"])
117118
})
118119

120+
it("stops accepting new captures once shutdown() has started", async () => {
121+
// Finding #4: shutdown() must mark itself as shutting down before draining, so a
122+
// steady trickle of new captures firing after shutdown() has begun (e.g. from a
123+
// teardown-time error handler) can't keep pendingClientCalls non-empty forever and
124+
// prevent the drain loop from ever terminating on its own.
125+
const mockClient: TelemetryClient = {
126+
setProvider: vi.fn(),
127+
capture: vi.fn().mockResolvedValue(undefined),
128+
captureException: vi.fn(),
129+
updateTelemetryState: vi.fn(),
130+
isTelemetryEnabled: vi.fn().mockReturnValue(true),
131+
shutdown: vi.fn().mockResolvedValue(undefined),
132+
}
133+
134+
const service = new TelemetryService([mockClient])
135+
136+
const shutdownPromise = service.shutdown()
137+
138+
// Fired after shutdown() has already started -- must be dropped, not tracked/drained.
139+
service.captureEvent(TelemetryEventName.TASK_CREATED, { taskId: "late" })
140+
141+
await shutdownPromise
142+
143+
expect(mockClient.capture).not.toHaveBeenCalled()
144+
})
145+
146+
it("does not hang forever when a capture never resolves, bounded by the drain timeout", async () => {
147+
vi.useFakeTimers()
148+
try {
149+
const mockClient: TelemetryClient = {
150+
setProvider: vi.fn(),
151+
// Never resolves -- simulates a capture stuck on network I/O.
152+
capture: vi.fn().mockImplementation(() => new Promise(() => {})),
153+
captureException: vi.fn(),
154+
updateTelemetryState: vi.fn(),
155+
isTelemetryEnabled: vi.fn().mockReturnValue(true),
156+
shutdown: vi.fn().mockResolvedValue(undefined),
157+
}
158+
159+
const service = new TelemetryService([mockClient])
160+
161+
service.captureEvent(TelemetryEventName.TASK_CREATED, { taskId: "stuck" })
162+
163+
const shutdownPromise = service.shutdown()
164+
let settled = false
165+
void shutdownPromise.then(() => {
166+
settled = true
167+
})
168+
169+
await vi.advanceTimersByTimeAsync(3000)
170+
171+
expect(settled).toBe(true)
172+
expect(mockClient.shutdown).toHaveBeenCalledTimes(1)
173+
} finally {
174+
vi.useRealTimers()
175+
}
176+
})
177+
119178
it("does not let a rejected capture prevent shutdown from completing", async () => {
120179
const mockClient: TelemetryClient = {
121180
setProvider: vi.fn(),

packages/types/src/vscode-extension-host.ts

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -359,6 +359,11 @@ export type ExtensionState = Pick<
359359
telemetrySetting: TelemetrySetting
360360
telemetryKey?: string
361361
machineId?: string
362+
// Live vscode.env.isTelemetryEnabled, so the webview's own PostHog client can respect
363+
// the VS Code global telemetry toggle the same way the extension-side gate does --
364+
// without this, an explicit user Accept can still send events while VS Code's global
365+
// telemetry is disabled.
366+
vscodeTelemetryEnabled?: boolean
362367

363368
renderContext: "sidebar" | "editor"
364369
settingsImportedAt?: number

src/__tests__/extension.spec.ts

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -406,6 +406,22 @@ describe("extension.ts", () => {
406406

407407
expect(updateTelemetryStateMock).toHaveBeenCalledWith(false)
408408
})
409+
410+
test("pushes a state update to the webview so its own PostHog client picks up the new vscode.env.isTelemetryEnabled value", async () => {
411+
const vscode = await import("vscode")
412+
const { ClineProvider } = await import("../core/webview/ClineProvider")
413+
414+
const { activate } = await import("../extension")
415+
await activate(mockContext)
416+
417+
const visibleInstance = (ClineProvider as any).getVisibleInstance()
418+
vi.mocked(visibleInstance.postStateToWebviewWithoutClineMessages).mockClear()
419+
420+
const onDidChangeHandler = vi.mocked(vscode.env.onDidChangeTelemetryEnabled).mock.calls[0][0]
421+
onDidChangeHandler(undefined as any)
422+
423+
expect(visibleInstance.postStateToWebviewWithoutClineMessages).toHaveBeenCalled()
424+
})
409425
})
410426

411427
describe("deactivate", () => {

src/api/providers/fetchers/__tests__/modelCache.spec.ts

Lines changed: 101 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -300,6 +300,73 @@ describe("empty cache protection", () => {
300300
expect(mockSet).toHaveBeenCalledWith("openrouter", mockModels)
301301
})
302302

303+
it("reuses an in-flight fetch for concurrent getModels() calls to the same provider", async () => {
304+
// Finding #11: getModels() previously had no de-duplication at all -- two concurrent
305+
// cache-miss calls would each independently fire their own provider fetch. It now
306+
// shares the same inFlightRefresh single-flight coordinator refreshModels() uses.
307+
const mockModels = {
308+
"openrouter/model": {
309+
maxTokens: 8192,
310+
contextWindow: 128000,
311+
supportsPromptCache: false,
312+
description: "OpenRouter model",
313+
},
314+
}
315+
316+
let resolvePromise: (value: typeof mockModels) => void
317+
const delayedPromise = new Promise<typeof mockModels>((resolve) => {
318+
resolvePromise = resolve
319+
})
320+
mockGetOpenRouterModels.mockReturnValue(delayedPromise)
321+
mockGet.mockReturnValue(undefined)
322+
323+
const promise1 = getModels({ provider: "openrouter" })
324+
const promise2 = getModels({ provider: "openrouter" })
325+
326+
expect(mockGetOpenRouterModels).toHaveBeenCalledTimes(1)
327+
328+
resolvePromise!(mockModels)
329+
330+
const [result1, result2] = await Promise.all([promise1, promise2])
331+
expect(result1).toEqual(mockModels)
332+
expect(result2).toEqual(mockModels)
333+
})
334+
335+
it("shares a single in-flight fetch between getModels() and refreshModels() for the same key", async () => {
336+
// The two entry points must converge on the same coordinator so a getModels() cache
337+
// miss racing a concurrent refreshModels() call can't produce two unordered writes to
338+
// the same cache key -- whichever fetch happened to finish last previously won,
339+
// regardless of which one was actually more current.
340+
const mockModels = {
341+
"openrouter/model": {
342+
maxTokens: 8192,
343+
contextWindow: 128000,
344+
supportsPromptCache: false,
345+
description: "OpenRouter model",
346+
},
347+
}
348+
349+
let resolvePromise: (value: typeof mockModels) => void
350+
const delayedPromise = new Promise<typeof mockModels>((resolve) => {
351+
resolvePromise = resolve
352+
})
353+
mockGetOpenRouterModels.mockReturnValue(delayedPromise)
354+
mockGet.mockReturnValue(undefined)
355+
356+
const { refreshModels } = await import("../modelCache")
357+
358+
const getPromise = getModels({ provider: "openrouter" })
359+
const refreshPromise = refreshModels({ provider: "openrouter" })
360+
361+
expect(mockGetOpenRouterModels).toHaveBeenCalledTimes(1)
362+
363+
resolvePromise!(mockModels)
364+
365+
const [getResult, refreshResult] = await Promise.all([getPromise, refreshPromise])
366+
expect(getResult).toEqual(mockModels)
367+
expect(refreshResult).toEqual(mockModels)
368+
})
369+
303370
it("re-arms the empty-response throttle after a non-empty response from an auth-scoped provider", async () => {
304371
// zoo-gateway is auth-scoped and skips caching entirely, but a non-empty response
305372
// must still clear the empty-response throttle so a later empty response is reported again.
@@ -525,6 +592,7 @@ describe("MODEL_CACHE_EMPTY_RESPONSE throttling", () => {
525592
let freshRefreshModels: ModelCacheModule["refreshModels"]
526593
let freshMockGetOpenRouterModels: Mock<typeof getOpenRouterModels>
527594
let freshMockGetLiteLLMModels: Mock<typeof getLiteLLMModels>
595+
let freshMockGetZooGatewayModels: Mock<typeof getZooGatewayModels>
528596

529597
beforeEach(async () => {
530598
// The empty-response throttle is deliberately module-level, persistent state (once per
@@ -535,11 +603,13 @@ describe("MODEL_CACHE_EMPTY_RESPONSE throttling", () => {
535603
const modelCacheModule: ModelCacheModule = await import("../modelCache")
536604
const openRouterModule = await import("../openrouter")
537605
const liteLLMModule = await import("../litellm")
606+
const zooGatewayModule = await import("../zoo-gateway")
538607

539608
freshGetModels = modelCacheModule.getModels
540609
freshRefreshModels = modelCacheModule.refreshModels
541610
freshMockGetOpenRouterModels = openRouterModule.getOpenRouterModels as Mock<typeof getOpenRouterModels>
542611
freshMockGetLiteLLMModels = liteLLMModule.getLiteLLMModels as Mock<typeof getLiteLLMModels>
612+
freshMockGetZooGatewayModels = zooGatewayModule.getZooGatewayModels as Mock<typeof getZooGatewayModels>
543613

544614
const NodeCacheModule = await import("node-cache")
545615
const MockedNodeCache = vi.mocked(NodeCacheModule.default)
@@ -632,6 +702,37 @@ describe("MODEL_CACHE_EMPTY_RESPONSE throttling", () => {
632702

633703
expect(FreshTelemetryService.instance.captureEvent).toHaveBeenCalledTimes(2)
634704
})
705+
706+
it("throttles zoo-gateway independently per session token, even though caching itself is skipped", async () => {
707+
// zoo-gateway is auth-scoped (see AUTH_SCOPED_PROVIDERS) and never persists to the
708+
// memory/disk cache, but the empty-response throttle must still discriminate by
709+
// identity: a sign-out/sign-in cycle to a different account carries a different
710+
// session token (apiKey) on the same gateway URL, and must not have its empty-response
711+
// signal suppressed by the previous account's throttle entry.
712+
const { TelemetryService: FreshTelemetryService } = await import("@roo-code/telemetry")
713+
714+
freshMockGetZooGatewayModels.mockResolvedValue({})
715+
716+
await freshGetModels({ provider: "zoo-gateway", apiKey: "account-a-token" })
717+
await freshGetModels({ provider: "zoo-gateway", apiKey: "account-a-token" })
718+
expect(FreshTelemetryService.instance.captureEvent).toHaveBeenCalledTimes(1)
719+
720+
await freshGetModels({ provider: "zoo-gateway", apiKey: "account-b-token" })
721+
expect(FreshTelemetryService.instance.captureEvent).toHaveBeenCalledTimes(2)
722+
})
723+
724+
it("throttles zoo-gateway independently per gateway baseUrl", async () => {
725+
// Same session token, different gateway endpoint (e.g. staging vs. production) --
726+
// must also be treated as a distinct identity for throttle purposes.
727+
const { TelemetryService: FreshTelemetryService } = await import("@roo-code/telemetry")
728+
729+
freshMockGetZooGatewayModels.mockResolvedValue({})
730+
731+
await freshGetModels({ provider: "zoo-gateway", apiKey: "token", baseUrl: "https://gateway-a.example.com" })
732+
await freshGetModels({ provider: "zoo-gateway", apiKey: "token", baseUrl: "https://gateway-b.example.com" })
733+
734+
expect(FreshTelemetryService.instance.captureEvent).toHaveBeenCalledTimes(2)
735+
})
635736
})
636737

637738
describe("key-scoped cache key derivation", () => {

0 commit comments

Comments
 (0)