From db39157ea6cf51d703183e29d1a3befc4d02d5fd Mon Sep 17 00:00:00 2001 From: ozymandiashh <234437643+ozymandiashh@users.noreply.github.com> Date: Sat, 18 Jul 2026 22:09:14 +0300 Subject: [PATCH] fix(telemetry): cap cli_error per kind per day, flush app_close on quit Two robustness fixes from the #741 telemetry audit: - cli_error had no rate limit: one install emitted 804 timeout events in a single day (56% of all events ever received). track() now caps cli_error at 20 per kind per calendar day. The day and per-kind counts persist in the telemetry state file (defensively loaded), so app relaunches within the same day cannot reset the budget; other event names are unaffected. - app_close almost never fired (1 close vs 48 opens): the quit path raced the outbound POST. before-quit now defers quit once, tracks the close and flushes with a bounded wait (1500ms race), then quits. Every step of the handler is independently guarded so a synchronous failure can neither skip the flush nor wedge quitting, and a full queue evicts its oldest event rather than dropping app_close. Disabled or not-onboarded telemetry quits instantly. --- app/electron/main.test.ts | 137 ++++++++++++++++++++++++++++++++- app/electron/main.ts | 64 +++++++++++++-- app/electron/telemetry.test.ts | 74 +++++++++++++++++- app/electron/telemetry.ts | 37 ++++++++- 4 files changed, 301 insertions(+), 11 deletions(-) diff --git a/app/electron/main.test.ts b/app/electron/main.test.ts index 47883142..c05635ab 100644 --- a/app/electron/main.test.ts +++ b/app/electron/main.test.ts @@ -1,4 +1,7 @@ // @vitest-environment node +import { mkdtempSync, rmSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' import { describe, it, expect, vi } from 'vitest' // Stub electron so importing main.ts does not require an Electron runtime. @@ -11,8 +14,9 @@ vi.mock('electron', () => ({ shell: { openExternal: vi.fn() }, })) -import { createApplicationMenuTemplate, createBridgeHandlers } from './main' +import { createApplicationMenuTemplate, createBeforeQuitHandler, createBridgeHandlers } from './main' import { CliError } from './cli' +import { Telemetry } from './telemetry' function fakeSpawn(result: unknown = { current: { cost: 12.34 } }) { const calls: string[][] = [] @@ -274,6 +278,137 @@ describe('createApplicationMenuTemplate', () => { }) }) +describe('createBeforeQuitHandler', () => { + it('flushes app_close to a fast endpoint before allowing quit', async () => { + const stateDir = mkdtempSync(join(tmpdir(), 'cb-main-quit-')) + try { + const posts: Array<{ events: Array<{ name: string }> }> = [] + const fetchFn = vi.fn(async (_url: unknown, init?: { body?: unknown }) => { + posts.push(JSON.parse(String(init?.body)) as { events: Array<{ name: string }> }) + return { ok: true } as Response + }) as unknown as typeof fetch + const telemetry = new Telemetry({ stateDir, country: 'US', isPackaged: true, appVersion: '1', fetchFn }) + telemetry.completeOnboarding(true) + await telemetry.flush() // isolate the final beat from the onboarding app_open + posts.length = 0 + + const quit = vi.fn() + const killChildren = vi.fn() + const handler = createBeforeQuitHandler({ getTelemetry: () => telemetry, killAll: killChildren, quit }) + const firstEvent = { preventDefault: vi.fn() } + handler(firstEvent) + + expect(firstEvent.preventDefault).toHaveBeenCalledOnce() + await vi.waitFor(() => expect(quit).toHaveBeenCalledOnce()) + expect(killChildren).toHaveBeenCalledOnce() + expect(posts).toHaveLength(1) + expect(posts[0]!.events.map(event => event.name)).toContain('app_close') + + const finalEvent = { preventDefault: vi.fn() } + handler(finalEvent) + expect(finalEvent.preventDefault).not.toHaveBeenCalled() + expect(quit).toHaveBeenCalledOnce() + } finally { + rmSync(stateDir, { recursive: true, force: true }) + } + }) + + it('allows quit at 1500ms when the endpoint never resolves and does not re-enter', async () => { + vi.useFakeTimers() + try { + const trackClose = vi.fn() + const flush = vi.fn(() => new Promise(() => {})) + const quit = vi.fn() + const handler = createBeforeQuitHandler({ + getTelemetry: () => ({ trackClose, flush }), + killAll: vi.fn(), + quit, + }) + + const firstEvent = { preventDefault: vi.fn() } + handler(firstEvent) + const repeatedEvent = { preventDefault: vi.fn() } + handler(repeatedEvent) + + expect(firstEvent.preventDefault).toHaveBeenCalledOnce() + expect(repeatedEvent.preventDefault).toHaveBeenCalledOnce() + expect(trackClose).toHaveBeenCalledOnce() + expect(flush).toHaveBeenCalledOnce() + + await vi.advanceTimersByTimeAsync(1499) + expect(quit).not.toHaveBeenCalled() + await vi.advanceTimersByTimeAsync(1) + expect(quit).toHaveBeenCalledOnce() + + const finalEvent = { preventDefault: vi.fn() } + handler(finalEvent) + expect(finalEvent.preventDefault).not.toHaveBeenCalled() + expect(quit).toHaveBeenCalledOnce() + } finally { + vi.useRealTimers() + } + }) + + it('still flushes and quits when trackClose throws synchronously', async () => { + const trackClose = vi.fn(() => { throw new Error('track close failed') }) + const flush = vi.fn(async () => true) + const quit = vi.fn() + const handler = createBeforeQuitHandler({ + getTelemetry: () => ({ trackClose, flush }), + killAll: vi.fn(), + quit, + }) + + handler({ preventDefault: vi.fn() }) + + await vi.waitFor(() => expect(quit).toHaveBeenCalledOnce()) + expect(trackClose).toHaveBeenCalledOnce() + expect(flush).toHaveBeenCalledOnce() + }) + + it('still quits when synchronous child cleanup throws', async () => { + const quit = vi.fn() + const handler = createBeforeQuitHandler({ + getTelemetry: () => null, + killAll: () => { throw new Error('child cleanup failed') }, + quit, + }) + + handler({ preventDefault: vi.fn() }) + + await vi.waitFor(() => expect(quit).toHaveBeenCalledOnce()) + }) + + it('still quits when synchronous telemetry lookup throws', async () => { + const quit = vi.fn() + const handler = createBeforeQuitHandler({ + getTelemetry: () => { throw new Error('telemetry lookup failed') }, + killAll: vi.fn(), + quit, + }) + + handler({ preventDefault: vi.fn() }) + + await vi.waitFor(() => expect(quit).toHaveBeenCalledOnce()) + }) + + it('does not wait for the timeout when telemetry cannot send yet', async () => { + const stateDir = mkdtempSync(join(tmpdir(), 'cb-main-no-consent-')) + try { + const fetchFn = vi.fn() as unknown as typeof fetch + const telemetry = new Telemetry({ stateDir, country: 'US', isPackaged: true, appVersion: '1', fetchFn }) + const quit = vi.fn() + const handler = createBeforeQuitHandler({ getTelemetry: () => telemetry, killAll: vi.fn(), quit }) + + handler({ preventDefault: vi.fn() }) + await vi.waitFor(() => expect(quit).toHaveBeenCalledOnce()) + expect(fetchFn).not.toHaveBeenCalled() + } finally { + rmSync(stateDir, { recursive: true, force: true }) + } + }) +}) + describe('createBridgeHandlers (cold-start warmup)', () => { const base = (extra: object) => ({ spawnCli: vi.fn(), spawnCliAction: vi.fn(), resolveCodeburnPath: () => '/bin/codeburn', getQuota: vi.fn(async () => []), ...extra }) diff --git a/app/electron/main.ts b/app/electron/main.ts index 705ab5cd..ffd43f6b 100644 --- a/app/electron/main.ts +++ b/app/electron/main.ts @@ -14,6 +14,59 @@ let updateChecker: UpdateChecker | null = null /** The slice of Telemetry the bridge handlers use — injectable for tests. */ export type TelemetryBridge = Pick +type QuitTelemetry = Pick +type BeforeQuitEvent = { preventDefault: () => void } +type BeforeQuitDeps = { + getTelemetry: () => QuitTelemetry | null + killAll: () => void + quit: () => void + timeoutMs?: number +} + +const QUIT_FLUSH_TIMEOUT_MS = 1500 + +/** Intercept one quit pass, then allow the re-entrant pass after a bounded flush. */ +export function createBeforeQuitHandler(deps: BeforeQuitDeps): (event: BeforeQuitEvent) => void { + let flushStarted = false + let allowQuit = false + let closeTracked = false + + return event => { + if (allowQuit) return + try { event.preventDefault() } catch { /* keep the quit path moving */ } + if (flushStarted) return + flushStarted = true + + void (async () => { + let timer: ReturnType | undefined + try { + try { deps.killAll() } catch { /* child cleanup must not wedge quit */ } + + let telemetry: QuitTelemetry | null = null + try { telemetry = deps.getTelemetry() } catch { /* telemetry lookup is best-effort */ } + + let flush: Promise = Promise.resolve(false) + if (telemetry) { + if (!closeTracked) { + closeTracked = true + try { telemetry.trackClose() } catch { /* flush the existing queue anyway */ } + } + try { flush = Promise.resolve(telemetry.flush()) } catch { /* use the resolved fallback */ } + } + + const timeout = new Promise(resolve => { + timer = setTimeout(resolve, deps.timeoutMs ?? QUIT_FLUSH_TIMEOUT_MS) + }) + await Promise.race([flush.catch(() => false), timeout]) + } finally { + if (timer !== undefined) clearTimeout(timer) + allowQuit = true + try { deps.quit() } catch { /* a throwing quit call must not reset the guard */ } + } + })() + } +} + // Result envelope: handlers never throw across IPC so the structured error // `kind` survives contextBridge serialization. preload.ts unwraps it. export type Envelope = { ok: true; value: T } | { ok: false; error: { kind: string; message: string } } @@ -485,12 +538,11 @@ function bootstrap(): void { win.focus() }) - app.on('before-quit', () => { - killAll() - // Best-effort final beat: session duration + whatever is still queued. - telemetryInstance?.trackClose() - void telemetryInstance?.flush() - }) + app.on('before-quit', createBeforeQuitHandler({ + getTelemetry: () => telemetryInstance, + killAll, + quit: () => app.quit(), + })) void app.whenReady().then(() => { // Consent-gated anonymous telemetry (desktop only). Nothing transmits until diff --git a/app/electron/telemetry.test.ts b/app/electron/telemetry.test.ts index 394a8d74..4adbb701 100644 --- a/app/electron/telemetry.test.ts +++ b/app/electron/telemetry.test.ts @@ -1,5 +1,5 @@ // @vitest-environment node -import { mkdtempSync, readFileSync, rmSync } from 'node:fs' +import { mkdtempSync, readFileSync, rmSync, writeFileSync } from 'node:fs' import { tmpdir } from 'node:os' import { join } from 'node:path' import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' @@ -155,6 +155,78 @@ describe('events', () => { expect(telemetry.queueLength).toBe(before + 1) }) + it('caps cli_error per kind per local day while leaving other events unaffected', async () => { + let instant = new Date('2026-07-17T12:00:00') + const { telemetry, posts } = make({ now: () => instant }) + telemetry.completeOnboarding(true) + + for (let i = 0; i < 25; i++) telemetry.track('cli_error', { kind: 'timeout', cmd: 'status' }) + telemetry.track('cli_error', { kind: 'not-found', cmd: 'status' }) + telemetry.track('section_view', { section: 'spend' }) + + expect(telemetry.queueLength).toBe(23) // app_open + 20 timeout + one other kind + one other event + + instant = new Date('2026-07-18T12:00:00') + telemetry.track('cli_error', { kind: 'timeout', cmd: 'status' }) + expect(telemetry.queueLength).toBe(24) + + await telemetry.flush() + const body = posts[0]!.body as { events: Array<{ name: string; day: string; props: Record }> } + const timeoutEvents = body.events.filter(event => event.name === 'cli_error' && event.props.kind === 'timeout') + expect(timeoutEvents.filter(event => event.day === '2026-07-17')).toHaveLength(20) + expect(timeoutEvents.filter(event => event.day === '2026-07-18')).toHaveLength(1) + expect(body.events.filter(event => event.name === 'cli_error' && event.props.kind === 'not-found')).toHaveLength(1) + expect(body.events.filter(event => event.name === 'section_view')).toHaveLength(1) + }) + + it('persists the cli_error cap across restarts on the same local day', () => { + const instant = new Date('2026-07-17T12:00:00') + const { telemetry } = make({ now: () => instant }) + telemetry.completeOnboarding(true) + for (let i = 0; i < 20; i++) telemetry.track('cli_error', { kind: 'timeout', cmd: 'status' }) + + const reloaded = new Telemetry({ stateDir: dir, country: 'US', isPackaged: true, appVersion: '1', now: () => instant }) + reloaded.track('cli_error', { kind: 'timeout', cmd: 'status' }) + expect(reloaded.queueLength).toBe(0) + reloaded.track('cli_error', { kind: 'not-found', cmd: 'status' }) + expect(reloaded.queueLength).toBe(1) + + const raw = JSON.parse(readFileSync(join(dir, 'telemetry.v1.json'), 'utf-8')) + expect(raw).toMatchObject({ cliErrorDay: '2026-07-17', cliErrorCounts: { timeout: 20, 'not-found': 1 } }) + }) + + it('falls back to fresh cli_error counters when the persisted budget is malformed', () => { + const instant = new Date('2026-07-17T12:00:00') + const { telemetry } = make({ now: () => instant }) + telemetry.completeOnboarding(true) + const stateFile = join(dir, 'telemetry.v1.json') + const raw = JSON.parse(readFileSync(stateFile, 'utf-8')) + writeFileSync(stateFile, JSON.stringify({ ...raw, cliErrorDay: '2026-07-17', cliErrorCounts: { timeout: 'many' } })) + + const reloaded = new Telemetry({ stateDir: dir, country: 'US', isPackaged: true, appVersion: '1', now: () => instant }) + for (let i = 0; i < 25; i++) reloaded.track('cli_error', { kind: 'timeout', cmd: 'status' }) + expect(reloaded.queueLength).toBe(20) + expect(reloaded.status()).toMatchObject({ enabled: true, onboarded: true }) + }) + + it('evicts the oldest event so app_close survives a full queue', async () => { + const { telemetry, posts } = make() + telemetry.completeOnboarding(true) + for (let i = 0; i < 199; i++) telemetry.track('section_view', { section: `section-${i}` }) + telemetry.track('section_view', { section: 'dropped-at-capacity' }) + expect(telemetry.queueLength).toBe(200) + + telemetry.trackClose() + expect(telemetry.queueLength).toBe(200) + await telemetry.flush() + + const body = posts[0]!.body as { events: Array<{ name: string; props: Record }> } + expect(body.events).toHaveLength(200) + expect(body.events[0]).toMatchObject({ name: 'section_view', props: { section: 'section-0' } }) + expect(body.events.at(-1)?.name).toBe('app_close') + expect(body.events.some(event => event.props.section === 'dropped-at-capacity')).toBe(false) + }) + it('keeps the queue on a transient failure (5xx) and clears it on success', async () => { let ok = false const fetchFn = vi.fn(async () => ({ ok, status: 503 })) as unknown as typeof fetch diff --git a/app/electron/telemetry.ts b/app/electron/telemetry.ts index a20d9598..a61592e2 100644 --- a/app/electron/telemetry.ts +++ b/app/electron/telemetry.ts @@ -43,6 +43,7 @@ export const EVENT_NAMES = new Set([ ]) const MAX_QUEUE = 200 +const MAX_CLI_ERRORS_PER_KIND_PER_DAY = 20 const MAX_STRING = 64 const MAX_ARRAY = 12 const MAX_KEYS = 16 @@ -62,6 +63,8 @@ type PersistedState = { enabled: boolean onboardedAt?: string lastSnapshotDay?: string + cliErrorDay?: string + cliErrorCounts?: Record } type Deps = { @@ -85,6 +88,17 @@ function dayKey(date: Date): string { return `${date.getFullYear()}-${String(date.getMonth() + 1).padStart(2, '0')}-${String(date.getDate()).padStart(2, '0')}` } +function loadCliErrorBudget(day: unknown, counts: unknown): Pick { + if (typeof day !== 'string' || !/^\d{4}-\d{2}-\d{2}$/.test(day)) return {} + if (!counts || typeof counts !== 'object' || Array.isArray(counts)) return {} + const cleanCounts = Object.create(null) as Record + for (const [kind, count] of Object.entries(counts)) { + if (!Number.isInteger(count) || (count as number) < 0 || (count as number) > MAX_CLI_ERRORS_PER_KIND_PER_DAY) return {} + cleanCounts[kind] = count as number + } + return { cliErrorDay: day, cliErrorCounts: cleanCounts } +} + function sanitizeValue(value: unknown): unknown | undefined { if (typeof value === 'string') return value.slice(0, MAX_STRING) if (typeof value === 'number') return Number.isFinite(value) ? value : undefined @@ -152,6 +166,7 @@ export class Telemetry { enabled: raw.enabled, onboardedAt: typeof raw.onboardedAt === 'string' ? raw.onboardedAt : undefined, lastSnapshotDay: typeof raw.lastSnapshotDay === 'string' ? raw.lastSnapshotDay : undefined, + ...loadCliErrorBudget(raw.cliErrorDay, raw.cliErrorCounts), } } } catch { /* first run or unreadable — start fresh */ } @@ -206,14 +221,30 @@ export class Telemetry { if (!this.state.enabled) return // usage_snapshot is an aggregate: at most one per calendar day. const now = (this.deps.now ?? (() => new Date()))() + const day = dayKey(now) if (name === 'usage_snapshot') { - const day = dayKey(now) if (this.state.lastSnapshotDay === day) return this.state.lastSnapshotDay = day this.save() } - if (this.queue.length >= MAX_QUEUE) return - this.queue.push({ name, day: dayKey(now), props: sanitizeProps(props) }) + if (this.queue.length >= MAX_QUEUE) { + if (name !== 'app_close') return + this.queue.shift() + } + const sanitizedProps = sanitizeProps(props) + if (name === 'cli_error') { + if (this.state.cliErrorDay !== day) { + this.state.cliErrorDay = day + this.state.cliErrorCounts = Object.create(null) as Record + } + const counts = this.state.cliErrorCounts ?? (this.state.cliErrorCounts = Object.create(null) as Record) + const kind = typeof sanitizedProps.kind === 'string' ? sanitizedProps.kind : '' + const count = Object.prototype.hasOwnProperty.call(counts, kind) ? counts[kind]! : 0 + if (count >= MAX_CLI_ERRORS_PER_KIND_PER_DAY) return + counts[kind] = count + 1 + this.save() + } + this.queue.push({ name, day, props: sanitizedProps }) } /** Record session duration; queued for the next (final) flush. */