diff --git a/src/main/telemetry/client-deferred-start.test.ts b/src/main/telemetry/client-deferred-start.test.ts index 601b1676db5..52fe5f38743 100644 --- a/src/main/telemetry/client-deferred-start.test.ts +++ b/src/main/telemetry/client-deferred-start.test.ts @@ -1,4 +1,5 @@ import { afterAll, afterEach, beforeEach, describe, expect, it, vi } from 'vitest' +import type { GlobalSettings } from '../../shared/global-settings-types' import type { Store } from '../persistence' import type * as PostHogTransport from './posthog-transport' import { @@ -21,7 +22,15 @@ vi.mock('./posthog-transport', async (importOriginal) => ({ createPostHogClient })) +const realTransport = await vi.importActual('./posthog-transport') const { initTelemetry, setOptIn, shutdownTelemetry, track } = await import('./client') +const realSetTimeout = globalThis.setTimeout +// SDK gzip is really async, so wait in real time while the fake clock stands still. +async function settle(done: () => boolean = () => false): Promise { + for (let i = 0; i < 200 && !done(); i++) { + await new Promise((resolve) => realSetTimeout(resolve, 10)) + } +} const scheduleClientStart = vi.fn<(start: () => void) => void>() afterAll(() => { @@ -31,28 +40,29 @@ afterAll(() => { describe('deferred PostHog client start', () => { let envStash: Record + let settings: GlobalSettings let store: Store - let sdk: MockPostHog + let sdk: MockPostHog & { flush: ReturnType } beforeEach(() => { vi.useFakeTimers({ now: new Date('2026-10-29T00:00:00Z') }) envStash = stashAndClearConsentEnv() vi.spyOn(console, 'warn').mockImplementation(() => {}) - sdk = makeMockPostHog() + sdk = { ...makeMockPostHog(), flush: vi.fn(async () => {}) } createPostHogClient.mockImplementation(() => sdk) - store = makeFakeStore( - makeFakeSettings({ - optedIn: true, - installId: BASE_COMMON.install_id, - existedBeforeTelemetryRelease: false - }) - ) + settings = makeFakeSettings({ + optedIn: true, + installId: BASE_COMMON.install_id, + existedBeforeTelemetryRelease: false + }) + store = makeFakeStore(settings) initTelemetry(store, scheduleClientStart) }) afterEach(async () => { await shutdownTelemetry() vi.useRealTimers() + vi.unstubAllGlobals() vi.restoreAllMocks() createPostHogClient.mockReset() scheduleClientStart.mockReset() @@ -76,6 +86,89 @@ describe('deferred PostHog client start', () => { ]) }) + it('flushes held events 10s after the first one, as an eager client would', () => { + track('app_opened', {}) + vi.advanceTimersByTime(2_000) + scheduleClientStart.mock.calls[0][0]() + vi.advanceTimersByTime(7_999) + expect(sdk.flush).not.toHaveBeenCalled() + + vi.advanceTimersByTime(1) + + expect(sdk.flush).toHaveBeenCalledTimes(1) + }) + + it('starts and flushes on that deadline when no window ever shows', () => { + track('app_opened', {}) + + vi.advanceTimersByTime(10_000) + + expect(sdk.capture).toHaveBeenCalledWith(expect.objectContaining({ event: 'app_opened' })) + expect(sdk.flush).toHaveBeenCalledTimes(1) + }) + + it('sends a full batch of held events immediately, as the SDK flushAt threshold would', async () => { + const fetch = vi.fn(async () => new Response('{}', { status: 200 })) + vi.stubGlobal('fetch', fetch) + createPostHogClient.mockImplementation(realTransport.createPostHogClient) + for (let i = 0; i < realTransport.POSTHOG_FLUSH_AT; i++) { + vi.setSystemTime(new Date(Date.UTC(2026, 9, 29, 0, 0, 0, i))) + expect(track('telemetry_opted_in', { via: 'settings' })).toBe(true) + } + + // Gzip is really async; waitFor's fake-clock advance stays under the 10s flush deadline. + await vi.waitFor( + () => + expect(fetch).toHaveBeenCalledWith(expect.stringContaining('/batch'), expect.anything()), + { timeout: 5_000, interval: 50 } + ) + }) + + it.each([200, 400])( + 'leaves batching to the SDK after a flushAt send answered %i, matching an eager client', + async (firstStatus) => { + vi.spyOn(console, 'error').mockImplementation(() => {}) + const fetch = vi.fn(async () => new Response('{}', { status: 200 })) + fetch.mockImplementationOnce(async () => new Response('{}', { status: firstStatus })) + vi.stubGlobal('fetch', fetch) + createPostHogClient.mockImplementation(realTransport.createPostHogClient) + for (let i = 0; i < realTransport.POSTHOG_FLUSH_AT; i++) { + track('telemetry_opted_in', { via: 'settings' }) + vi.advanceTimersByTime(50) + } + await settle(() => fetch.mock.calls.length === 1) + await vi.advanceTimersByTimeAsync(1_000) + track('telemetry_opted_in', { via: 'settings' }) + await settle(() => false) + + // An eager client's interval restarted at the 2s capture; the startup deadline must not flush at 10s. + await vi.advanceTimersByTimeAsync(8_500) + await settle(() => fetch.mock.calls.length > 1) + expect(fetch).toHaveBeenCalledTimes(1) + await vi.advanceTimersByTimeAsync(1_600) + await settle(() => fetch.mock.calls.length > 1) + expect(fetch).toHaveBeenCalledTimes(2) + } + ) + + it('drops held events when consent is withdrawn before the client starts', () => { + track('app_opened', {}) + settings.telemetry!.optedIn = false + + scheduleClientStart.mock.calls[0][0]() + + expect(sdk.capture).not.toHaveBeenCalled() + }) + + it('drops held events at quit without loading the SDK when consent was withdrawn', async () => { + track('app_opened', {}) + settings.telemetry!.optedIn = false + + await shutdownTelemetry() + + expect(createPostHogClient).not.toHaveBeenCalled() + }) + it('starts the client early to flush held events and enqueue the opt-out before opting out', async () => { track('app_opened', {}) const order: string[] = [] diff --git a/src/main/telemetry/client.ts b/src/main/telemetry/client.ts index 5af7a21ee77..8e1fbadb1e2 100644 --- a/src/main/telemetry/client.ts +++ b/src/main/telemetry/client.ts @@ -83,7 +83,7 @@ export function initTelemetry(store: Store, scheduleStart: postHogStart.StartSch } posthog = null - postHogStart.deferStart(WRITE_KEY, scheduleStart, ensurePostHogClient) + postHogStart.deferStart(WRITE_KEY, store, scheduleStart, ensurePostHogClient) } function ensurePostHogClient(): PostHog | null { @@ -94,9 +94,7 @@ function ensurePostHogClient(): PostHog | null { try { // Apply consent as it stands now; the live per-event check already gated each held capture. posthog = createPostHogClient(start.writeKey, resolveConsent(storeRef.getSettings())) - for (const message of start.held) { - posthog.capture(message) - } + postHogStart.replayHeld(posthog, start.held) } catch (err) { // Callers include opt-out and quit, which must still complete without a client. console.warn('[telemetry] PostHog client failed to start or replay held events:', err) @@ -210,7 +208,7 @@ export function track(name: N, props: EventProps): boole if (posthog) { posthog.capture(message) } else { - postHogStart.holdCapture(message) + postHogStart.holdCapture(message, ensurePostHogClient) } if (dashboardActiveSurface && settings.telemetry) { trackedDashboardActiveDays.set(dashboardActiveSurface, dashboardActiveDay) @@ -325,7 +323,7 @@ export function trackAppOpenedOnce(): void { export async function shutdownTelemetry(): Promise { // Fence before flushing so late IPC cannot enqueue. shuttingDown = true - const instance = postHogStart.hasHeldCaptures() ? ensurePostHogClient() : posthog + const instance = postHogStart.hasSendableHeldCaptures() ? ensurePostHogClient() : posthog postHogStart.resetStart() if (!instance) { return diff --git a/src/main/telemetry/posthog-client-start.ts b/src/main/telemetry/posthog-client-start.ts index 5f966d23faa..1b42f8baea6 100644 --- a/src/main/telemetry/posthog-client-start.ts +++ b/src/main/telemetry/posthog-client-start.ts @@ -1,15 +1,26 @@ import type { PostHog } from 'posthog-node' +import type { Store } from '../persistence' +import { resolveConsent } from './consent' +import { POSTHOG_FLUSH_AT, POSTHOG_FLUSH_INTERVAL_MS } from './posthog-transport' type CaptureMessage = Parameters[0] /** Desktop passes a first-window scheduler; Electron stays out of this plain-Node module. */ export type StartScheduler = (start: () => void) => void let writeKey: string | null = null +let storeRef: Store | null = null +let firstFlushTimer: ReturnType | null = null const heldCaptures: CaptureMessage[] = [] /** Hold captures until the scheduled start so the SDK stays off the startup path (#35752). */ -export function deferStart(key: string, schedule: StartScheduler, start: () => void): void { +export function deferStart( + key: string, + store: Store, + schedule: StartScheduler, + start: () => void +): void { writeKey = key + storeRef = store schedule(start) } @@ -17,26 +28,74 @@ export function isStartDeferred(): boolean { return writeKey !== null } -/** Keep the capture time so replayed events land when they happened. */ -export function holdCapture(message: CaptureMessage): void { +/** Keep capture time for replay; send no later than an eager client would (flushAt or flushInterval). */ +export function holdCapture(message: CaptureMessage, start: () => PostHog | null): void { heldCaptures.push({ ...message, timestamp: new Date() }) + if (heldCaptures.length >= POSTHOG_FLUSH_AT) { + // Replaying a full batch trips the SDK's own flushAt send. + start() + return + } + if (firstFlushTimer) { + return + } + firstFlushTimer = setTimeout(() => { + firstFlushTimer = null + start() + ?.flush() + .catch((err: unknown) => console.warn('[telemetry] first flush failed:', err)) + }, POSTHOG_FLUSH_INTERVAL_MS) + firstFlushTimer.unref?.() } -export function hasHeldCaptures(): boolean { - return heldCaptures.length > 0 +function consentAllows(): boolean { + return storeRef !== null && resolveConsent(storeRef.getSettings()).effective === 'enabled' } -/** Claim the deferred start once; returns the held captures to replay in order. */ +/** Quit loads the SDK only for held events that consent still allows. */ +export function hasSendableHeldCaptures(): boolean { + return heldCaptures.length > 0 && consentAllows() +} + +function retireFirstFlushDeadline(): void { + if (firstFlushTimer) { + clearTimeout(firstFlushTimer) + firstFlushTimer = null + } +} + +/** Replay in order; the deadline stands in for the timer an eager client armed at the first held event. */ +export function replayHeld(client: PostHog, held: CaptureMessage[]): void { + // Before its first flush the SDK queue holds every enqueue, so the flushAt-th enqueue is the only SDK flush + // attempt that can precede the deadline; retire it then, whether that send succeeds or fails. + let enqueued = 0 + const stopListening = client.on('capture', (payload: unknown) => { + // Opted-out captures report a string instead of enqueuing. + if (payload !== null && typeof payload === 'object' && ++enqueued >= POSTHOG_FLUSH_AT) { + stopListening() + retireFirstFlushDeadline() + } + }) + for (const message of held) { + client.capture(message) + } +} + +/** Claim the deferred start once; held events are dropped if consent was withdrawn since capture. */ export function takeStart(): { writeKey: string; held: CaptureMessage[] } | null { if (writeKey === null) { return null } - const start = { writeKey, held: heldCaptures.splice(0) } - resetStart() + const held = heldCaptures.splice(0) + // The first-flush deadline survives so replayed events keep it. + const start = { writeKey, held: consentAllows() ? held : [] } + writeKey = null return start } export function resetStart(): void { writeKey = null + storeRef = null heldCaptures.length = 0 + retireFirstFlushDeadline() } diff --git a/src/main/telemetry/posthog-transport.ts b/src/main/telemetry/posthog-transport.ts index e28e597aa81..8367fd8e88d 100644 --- a/src/main/telemetry/posthog-transport.ts +++ b/src/main/telemetry/posthog-transport.ts @@ -5,6 +5,8 @@ import type { CommonProps, EventName } from '../../shared/telemetry-events' import type { ConsentState } from './consent' const OPT_OUT_CAPTURE_ENQUEUE_TIMEOUT_MS = 1_000 +export const POSTHOG_FLUSH_AT = 20 +export const POSTHOG_FLUSH_INTERVAL_MS = 10_000 export function buildCommonProps( installId: string, @@ -77,8 +79,8 @@ function loadPostHogSdk(): typeof PostHogSdk { export function createPostHogClient(writeKey: string, consent: ConsentState): PostHogSdk.PostHog { const client = new (loadPostHogSdk().PostHog)(writeKey, { host: 'https://us.i.posthog.com', - flushAt: 20, - flushInterval: 10_000, + flushAt: POSTHOG_FLUSH_AT, + flushInterval: POSTHOG_FLUSH_INTERVAL_MS, // Disable SDK GeoIP/IP enrichment to keep the wire inside the declared allow-list. disableGeoip: true, // Increase offline buffer from 1000 to 5000; overflow drops oldest events.