diff --git a/src/main/crash-reporting/crash-breadcrumb-store-orphan-cleanup.test.ts b/src/main/crash-reporting/crash-breadcrumb-store-orphan-cleanup.test.ts new file mode 100644 index 00000000000..92ff659c556 --- /dev/null +++ b/src/main/crash-reporting/crash-breadcrumb-store-orphan-cleanup.test.ts @@ -0,0 +1,167 @@ +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' +import { + clearCrashBreadcrumbsForTest, + getCrashBreadcrumbSnapshot, + recordCoalescedCrashBreadcrumb, + recordCrashBreadcrumb +} from './crash-breadcrumb-store' + +const COALESCE_WINDOW_MS = 30_000 +const MAX_COALESCE_KEYS = 128 +const ORPHAN_KEY = 'terminal_safe_fit_retry_exhausted' + +function recordOrphanCandidate(livePanes: number): void { + recordCoalescedCrashBreadcrumb({ + name: ORPHAN_KEY, + data: { livePanes }, + coalesceKey: ORPHAN_KEY, + minIntervalMs: COALESCE_WINDOW_MS + }) +} + +function resumeOrphanCandidate(livePanes: number): { suppressedSinceLast: number } | undefined { + return recordCoalescedCrashBreadcrumb({ + name: ORPHAN_KEY, + data: { livePanes }, + coalesceKey: ORPHAN_KEY, + minIntervalMs: COALESCE_WINDOW_MS + }) +} + +function recordSuppressedBurst(): void { + recordOrphanCandidate(1) + recordOrphanCandidate(2) + recordOrphanCandidate(3) +} + +function orphanFromRing(): void { + for (let index = 0; index < 30; index += 1) { + recordCrashBreadcrumb(`renderer_error_${index}`, { index }) + } + getCrashBreadcrumbSnapshot() +} + +function orphanFromSnapshotBudget(): void { + for (let index = 0; index < 4; index += 1) { + recordCrashBreadcrumb('renderer_memory_highwater', { + rendererSurface: `surface-${index}`, + thresholdPct: 80 + }) + } + for (let index = 0; index < 29; index += 1) { + recordCrashBreadcrumb(`renderer_error_${index}`, { index }) + } + getCrashBreadcrumbSnapshot() +} + +function expireWithUnrelatedKey(): void { + vi.advanceTimersByTime(COALESCE_WINDOW_MS + 1) + recordCoalescedCrashBreadcrumb({ + name: 'agent_state_changed', + data: { agentType: 'claude', state: 'working' }, + coalesceKey: 'agent:claude:working', + minIntervalMs: COALESCE_WINDOW_MS + }) +} + +function evictWithUnrelatedKeys(): void { + for (let index = 0; index < MAX_COALESCE_KEYS; index += 1) { + recordCoalescedCrashBreadcrumb({ + name: 'renderer_error', + data: { message: `error-${index}` }, + coalesceKey: `renderer_error:error-${index}`, + minIntervalMs: COALESCE_WINDOW_MS + }) + } +} + +function expectSuppressedBurstPreserved(): void { + const recovered = getCrashBreadcrumbSnapshot().find( + (breadcrumb) => breadcrumb.name === ORPHAN_KEY && breadcrumb.data?.suppressedSinceLast === 2 + ) + expect(recovered?.data).toEqual({ livePanes: 3, suppressedSinceLast: 2 }) +} + +describe('orphaned coalesced breadcrumb cleanup', () => { + beforeEach(() => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-07-22T12:00:00.000Z')) + }) + + afterEach(() => { + clearCrashBreadcrumbsForTest() + vi.useRealTimers() + }) + + it('preserves ring-orphaned repeats through unrelated expiry cleanup', () => { + recordSuppressedBurst() + orphanFromRing() + + expireWithUnrelatedKey() + + expectSuppressedBurstPreserved() + }) + + it('preserves data-less repeats through orphan cleanup', () => { + for (let index = 0; index < 3; index += 1) { + recordCoalescedCrashBreadcrumb({ + name: ORPHAN_KEY, + coalesceKey: ORPHAN_KEY, + minIntervalMs: COALESCE_WINDOW_MS + }) + } + orphanFromRing() + + expireWithUnrelatedKey() + + const recovered = getCrashBreadcrumbSnapshot().find( + (breadcrumb) => breadcrumb.name === ORPHAN_KEY + ) + expect(recovered?.data).toEqual({ suppressedSinceLast: 2 }) + }) + + it('preserves snapshot-budget-orphaned repeats through unrelated expiry cleanup', () => { + recordSuppressedBurst() + orphanFromSnapshotBudget() + + expireWithUnrelatedKey() + + expectSuppressedBurstPreserved() + }) + + it('preserves ring-orphaned repeats through LRU cleanup', () => { + recordSuppressedBurst() + orphanFromRing() + + evictWithUnrelatedKeys() + + expectSuppressedBurstPreserved() + }) + + it('preserves snapshot-budget-orphaned repeats through LRU cleanup', () => { + recordSuppressedBurst() + orphanFromSnapshotBudget() + + evictWithUnrelatedKeys() + + expectSuppressedBurstPreserved() + }) + + it('materializes only repeats not already claimed by an earlier snapshot', () => { + recordOrphanCandidate(1) + recordOrphanCandidate(2) + const firstSnapshot = getCrashBreadcrumbSnapshot() + recordOrphanCandidate(3) + recordOrphanCandidate(4) + orphanFromRing() + + expireWithUnrelatedKey() + + expect(firstSnapshot[0]?.data).toEqual({ livePanes: 2, suppressedSinceLast: 1 }) + const recovered = getCrashBreadcrumbSnapshot().find( + (breadcrumb) => breadcrumb.name === ORPHAN_KEY + ) + expect(recovered?.data).toEqual({ livePanes: 4, suppressedSinceLast: 2 }) + expect(resumeOrphanCandidate(5)).toEqual({ suppressedSinceLast: 0 }) + }) +}) diff --git a/src/main/crash-reporting/crash-breadcrumb-store.test.ts b/src/main/crash-reporting/crash-breadcrumb-store.test.ts index 5a456e8dd32..7690a01ff27 100644 --- a/src/main/crash-reporting/crash-breadcrumb-store.test.ts +++ b/src/main/crash-reporting/crash-breadcrumb-store.test.ts @@ -125,6 +125,63 @@ describe('crash breadcrumb store', () => { vi.useRealTimers() }) + it('expires the coalescing window after a backward wall-clock step', () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-05-20T12:00:00.000Z')) + const hit = (): { suppressedSinceLast: number } | undefined => + recordCoalescedCrashBreadcrumb({ + name: 'agent_state_changed', + coalesceKey: 'agent:claude:working', + minIntervalMs: 30_000 + }) + + hit() + vi.advanceTimersByTime(10_000) + expect(hit()).toBeUndefined() + vi.setSystemTime(new Date('2025-05-20T12:00:00.000Z')) + vi.advanceTimersByTime(20_000) + + expect(hit()).toEqual({ suppressedSinceLast: 1 }) + expect(getCrashBreadcrumbSnapshot()).toHaveLength(2) + }) + + it('does not collapse the coalescing window after a forward wall-clock step', () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-05-20T12:00:00.000Z')) + const hit = (): { suppressedSinceLast: number } | undefined => + recordCoalescedCrashBreadcrumb({ + name: 'agent_state_changed', + coalesceKey: 'agent:claude:working', + minIntervalMs: 30_000 + }) + + hit() + vi.advanceTimersByTime(10_000) + vi.setSystemTime(new Date('2027-05-20T12:00:00.000Z')) + + expect(hit()).toBeUndefined() + vi.advanceTimersByTime(20_000) + expect(hit()).toEqual({ suppressedSinceLast: 1 }) + }) + + it('folds data-less repeats into the emitted breadcrumb', () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-05-20T12:00:00.000Z')) + + recordCoalescedCrashBreadcrumb({ + name: 'terminal_safe_fit_retry_exhausted', + coalesceKey: 'terminal_safe_fit_retry_exhausted', + minIntervalMs: 30_000 + }) + recordCoalescedCrashBreadcrumb({ + name: 'terminal_safe_fit_retry_exhausted', + coalesceKey: 'terminal_safe_fit_retry_exhausted', + minIntervalMs: 30_000 + }) + + expect(getCrashBreadcrumbSnapshot()[0]?.data).toEqual({ suppressedSinceLast: 1 }) + }) + // Windows crash F0BKR84AHEH: two `terminal_safe_fit_retry_exhausted` bursts // (34 crumbs in 76ms, 34 in 56ms) flushed the pre-crash trail out of a // 30-entry ring. Every hidden pane is display:none, so it measures 0x0, fails @@ -315,6 +372,181 @@ describe('crash breadcrumb store', () => { expect(bursts[1].data).toEqual({ livePanes: 3, suppressedSinceLast: 1 }) }) + // A crash report filed mid-window snapshots the ring, which folds the + // suppressed repeats into the emitted crumb. Re-claiming those repeats on + // the next emit would report one burst twice across two crumbs. + it('does not re-claim repeats a snapshot already folded into the crumb', () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-07-22T12:00:00.000Z')) + const hit = (livePanes: number): { suppressedSinceLast: number } | undefined => + recordCoalescedCrashBreadcrumb({ + name: 'terminal_safe_fit_retry_exhausted', + data: { livePanes }, + coalesceKey: 'terminal_safe_fit_retry_exhausted', + minIntervalMs: 30_000 + }) + + hit(1) + vi.advanceTimersByTime(10) + hit(2) + getCrashBreadcrumbSnapshot() + vi.advanceTimersByTime(31_000) + const resumed = hit(3) + + expect(resumed).toEqual({ suppressedSinceLast: 0 }) + const bursts = getCrashBreadcrumbSnapshot().filter( + (entry) => entry.name === 'terminal_safe_fit_retry_exhausted' + ) + expect(bursts[0].data).toEqual({ livePanes: 2, suppressedSinceLast: 1 }) + expect(bursts[1].data).toEqual({ livePanes: 3 }) + + // The re-emitted crumb was born claiming nothing, so a fold onto it must + // claim only the new repeat — not the one the first crumb already owns. + vi.advanceTimersByTime(10) + hit(4) + const resolved = getCrashBreadcrumbSnapshot().filter( + (entry) => entry.name === 'terminal_safe_fit_retry_exhausted' + ) + expect(resolved[1].data).toEqual({ livePanes: 4, suppressedSinceLast: 1 }) + }) + + // A re-emitted crumb is born already claiming the previous window's count; + // a later fold must add to that claim, not overwrite it away. + it('keeps the carried count when a fold resolves onto a re-emitted crumb', () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-07-22T12:00:00.000Z')) + const hit = (livePanes: number): void => { + recordCoalescedCrashBreadcrumb({ + name: 'terminal_safe_fit_retry_exhausted', + data: { livePanes }, + coalesceKey: 'terminal_safe_fit_retry_exhausted', + minIntervalMs: 30_000 + }) + } + + hit(1) + vi.advanceTimersByTime(10) + hit(2) + vi.advanceTimersByTime(31_000) + hit(3) + vi.advanceTimersByTime(10) + hit(4) + + const bursts = getCrashBreadcrumbSnapshot().filter( + (entry) => entry.name === 'terminal_safe_fit_retry_exhausted' + ) + expect(bursts[1].data).toEqual({ livePanes: 4, suppressedSinceLast: 2 }) + }) + + // A crash storm records other breadcrumbs too; if they push the burst crumb + // out of the 30-entry ring mid-window, a snapshot's fold lands in evidence + // no snapshot can see. Marking those repeats resolved anyway would let the + // next emit claim nothing and the burst vanish from the record entirely. + it('re-claims repeats on the next emit when the burst crumb was evicted from the ring', () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-07-22T12:00:00.000Z')) + const hit = (livePanes: number): { suppressedSinceLast: number } | undefined => + recordCoalescedCrashBreadcrumb({ + name: 'terminal_safe_fit_retry_exhausted', + data: { livePanes }, + coalesceKey: 'terminal_safe_fit_retry_exhausted', + minIntervalMs: 30_000 + }) + + hit(1) + vi.advanceTimersByTime(10) + hit(2) + hit(3) + for (let index = 0; index < 30; index += 1) { + recordCrashBreadcrumb(`renderer_error_${index}`, { index }) + } + getCrashBreadcrumbSnapshot() + vi.advanceTimersByTime(31_000) + const resumed = hit(4) + + expect(resumed).toEqual({ suppressedSinceLast: 2 }) + const burst = getCrashBreadcrumbSnapshot().find( + (entry) => entry.name === 'terminal_safe_fit_retry_exhausted' + ) + expect(burst?.data).toEqual({ livePanes: 4, suppressedSinceLast: 2 }) + }) + + // Retained high-water profiles occupy snapshot slots, so the oldest ring + // entries past that budget are invisible to every future snapshot even + // though they are still in the array; folding there loses the burst too. + it('re-claims repeats when retained profiles push the burst crumb past the snapshot budget', () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-07-22T12:00:00.000Z')) + const hit = (livePanes: number): { suppressedSinceLast: number } | undefined => + recordCoalescedCrashBreadcrumb({ + name: 'terminal_safe_fit_retry_exhausted', + data: { livePanes }, + coalesceKey: 'terminal_safe_fit_retry_exhausted', + minIntervalMs: 30_000 + }) + + hit(1) + vi.advanceTimersByTime(10) + hit(2) + hit(3) + for (let index = 0; index < 4; index += 1) { + recordCrashBreadcrumb('renderer_memory_highwater', { + rendererSurface: `surface-${index}`, + thresholdPct: 80 + }) + } + // Ring stays at 30 (burst crumb still at index 0) but only the newest 26 + // ring entries fit a snapshot alongside the 4 retained profiles. + for (let index = 0; index < 29; index += 1) { + recordCrashBreadcrumb(`renderer_error_${index}`, { index }) + } + getCrashBreadcrumbSnapshot() + vi.advanceTimersByTime(31_000) + const resumed = hit(4) + + expect(resumed).toEqual({ suppressedSinceLast: 2 }) + }) + + // Two crash reports filed inside one window are immutable cumulative views; + // the next window must still start from zero unresolved debt. + it('keeps immutable snapshots cumulative without re-claiming resolved debt', () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-07-22T12:00:00.000Z')) + const hit = (livePanes: number): { suppressedSinceLast: number } | undefined => + recordCoalescedCrashBreadcrumb({ + name: 'terminal_safe_fit_retry_exhausted', + data: { livePanes }, + coalesceKey: 'terminal_safe_fit_retry_exhausted', + minIntervalMs: 30_000 + }) + + hit(1) + vi.advanceTimersByTime(10) + hit(2) + hit(3) + const firstSnapshot = getCrashBreadcrumbSnapshot() + vi.advanceTimersByTime(10) + hit(4) + const secondFold = getCrashBreadcrumbSnapshot().find( + (entry) => entry.name === 'terminal_safe_fit_retry_exhausted' + ) + expect(firstSnapshot[0]?.data).toEqual({ livePanes: 3, suppressedSinceLast: 2 }) + expect(secondFold?.data).toEqual({ livePanes: 4, suppressedSinceLast: 3 }) + + vi.advanceTimersByTime(31_000) + const resumed = hit(5) + expect(resumed).toEqual({ suppressedSinceLast: 0 }) + + // A fold onto the fresh crumb must claim only its own window's repeat — + // over-resolving in the first window would push this claim negative. + vi.advanceTimersByTime(10) + hit(6) + const resolved = getCrashBreadcrumbSnapshot().filter( + (entry) => entry.name === 'terminal_safe_fit_retry_exhausted' + ) + expect(resolved[1].data).toEqual({ livePanes: 6, suppressedSinceLast: 1 }) + }) + // A key that ages out loses its only handle on the ring entry it owns, so // the newest suppressed payload must be folded in before the entry is // dropped from the map. diff --git a/src/main/crash-reporting/crash-breadcrumb-store.ts b/src/main/crash-reporting/crash-breadcrumb-store.ts index f33856f5e77..e5f96e8f05e 100644 --- a/src/main/crash-reporting/crash-breadcrumb-store.ts +++ b/src/main/crash-reporting/crash-breadcrumb-store.ts @@ -13,9 +13,19 @@ const MAX_RETAINED_BREADCRUMBS = 4 // Bound the coalesce map the same way ProcessGoneDedupe bounds its key map. const MAX_COALESCE_KEYS = 128 +// Why: wall-clock corrections must not stretch or collapse suppression windows. +const monotonicNow = (): number => performance.now() + type CoalescedBreadcrumbState = { - recordedAt: number + /** Name needed to materialize unresolved repeats if the owned crumb is orphaned. */ + name: string + windowStartedAtMs: number suppressed: number + /** Count the crumb was emitted claiming (the previous window's repeats). */ + carried: number + /** Of `suppressed`, how many a resolve already folded into the crumb, so a + * later emit never claims the same repeats a snapshot attributed. */ + resolved: number /** Ring entry this key owns, refreshed in place while suppressing. */ emitted?: CrashReportBreadcrumb /** Newest suppressed payload, sanitized only if a snapshot actually asks for it. */ @@ -82,9 +92,9 @@ export function recordCoalescedCrashBreadcrumb({ coalesceKey: string minIntervalMs: number }): { suppressedSinceLast: number } | undefined { - const now = Date.now() + const now = monotonicNow() const previous = coalescedBreadcrumbs.get(coalesceKey) - if (previous && now - previous.recordedAt < minIntervalMs) { + if (previous && now - previous.windowStartedAtMs < minIntervalMs) { previous.suppressed += 1 // Stash the newest payload for the entry this key already owns: the burst // still costs exactly one ring slot, but the retained crumb ends up @@ -94,14 +104,8 @@ export function recordCoalescedCrashBreadcrumb({ // this coalescing was built to prevent. Sanitizing here would put that cost // on every suppressed hit of a 1459/min crash loop; the snapshot resolves it // once instead, on the rare path that actually reads breadcrumbs. - if (previous.emitted) { - previous.pending = data - } - // Re-anchor recency without touching recordedAt: a suppressed key is the - // hottest key in the map, but only the emit path below moves position, so - // a continuously-suppressed key would keep its original slot and be first - // out under high-cardinality churn. recordedAt stays put so the suppression - // window still expires on schedule instead of renewing on every hit. + previous.pending = data + // A hot key stays LRU-recent without renewing its fixed suppression window. coalescedBreadcrumbs.delete(coalesceKey) coalescedBreadcrumbs.set(coalesceKey, previous) return undefined @@ -112,28 +116,37 @@ export function recordCoalescedCrashBreadcrumb({ // recency so only genuinely idle keys are evicted. Resolve first: an expiring // key is about to lose its only handle on the ring entry it owns. for (const [key, entry] of coalescedBreadcrumbs) { - if (now - entry.recordedAt >= minIntervalMs) { + if (now - entry.windowStartedAtMs >= minIntervalMs) { // Why the key check: this key is about to emit a fresh crumb carrying // `suppressedSinceLast`, so folding the same events into its old slot // too would report one burst twice. if (key !== coalesceKey) { - resolvePendingCoalescedBreadcrumb(entry) + preservePendingCoalescedBreadcrumb(entry) } coalescedBreadcrumbs.delete(key) } } coalescedBreadcrumbs.delete(coalesceKey) - const state: CoalescedBreadcrumbState = { recordedAt: now, suppressed: 0 } + // Claim only repeats no resolve has already folded into the previous crumb — + // a snapshot mid-window attributes them there, and forensic totals must not + // count one burst twice. + const suppressedSinceLast = previous ? previous.suppressed - previous.resolved : 0 + const state: CoalescedBreadcrumbState = { + name, + windowStartedAtMs: now, + suppressed: 0, + carried: suppressedSinceLast, + resolved: 0 + } coalescedBreadcrumbs.set(coalesceKey, state) while (coalescedBreadcrumbs.size > MAX_COALESCE_KEYS) { const oldest = coalescedBreadcrumbs.entries().next() if (oldest.done) { break } - resolvePendingCoalescedBreadcrumb(oldest.value[1]) + preservePendingCoalescedBreadcrumb(oldest.value[1]) coalescedBreadcrumbs.delete(oldest.value[0]) } - const suppressedSinceLast = previous?.suppressed ?? 0 state.emitted = recordCrashBreadcrumb( name, suppressedSinceLast > 0 ? { ...data, suppressedSinceLast } : data @@ -141,15 +154,63 @@ export function recordCoalescedCrashBreadcrumb({ return { suppressedSinceLast } } +/** Whether any future snapshot can still include this crumb. The ring only + * appends and the retained map only grows toward its cap, so an entry pushed + * past the snapshot budget is invisible forever, not just for now. */ +function isCoalescedCrumbStillInEvidence(crumb: CrashReportBreadcrumb): boolean { + const visibleFrom = breadcrumbs.length - (MAX_BREADCRUMBS - retainedBreadcrumbs.size) + const index = breadcrumbs.indexOf(crumb) + if (index !== -1 && index >= visibleFrom) { + return true + } + for (const retained of retainedBreadcrumbs.values()) { + if (retained === crumb) { + return true + } + } + return false +} + /** Fold a key's newest suppressed payload into the ring entry it owns. */ function resolvePendingCoalescedBreadcrumb(state: CoalescedBreadcrumbState): void { - if (!state.pending || !state.emitted) { + // `data` is optional, so the count—not pending payload presence—marks unresolved work. + if (!state.emitted || state.suppressed <= state.resolved) { return } + // Eviction can orphan the crumb mid-window; folding into it would mark the + // repeats resolved into evidence no snapshot can see, and the next emit would + // then claim nothing — the burst vanishes from the record entirely. Drop the + // handle (keeping `resolved` for folds that landed while it was live) so a + // later emit or bounded cleanup can materialize the unclaimed repeats. + if (!isCoalescedCrumbStillInEvidence(state.emitted)) { + state.emitted = undefined + return + } + // The crumb's claim is a running total: what it was born claiming plus every + // repeat folded since. Dropping `carried` would erase the previous window's + // count from the record; omitting `resolved` bookkeeping would let the next + // emit claim these repeats a second time. state.emitted.data = sanitizeCrashReportDetails({ ...state.pending, - suppressedSinceLast: state.suppressed + suppressedSinceLast: state.carried + state.suppressed }) + state.resolved = state.suppressed + state.pending = undefined +} + +/** Resolve into the owned crumb, or emit the unclaimed repeats before bounded + * cleanup drops an orphan's last accounting state. */ +function preservePendingCoalescedBreadcrumb(state: CoalescedBreadcrumbState): void { + resolvePendingCoalescedBreadcrumb(state) + const unresolved = state.suppressed - state.resolved + if (state.emitted || unresolved <= 0) { + return + } + recordCrashBreadcrumb(state.name, { + ...state.pending, + suppressedSinceLast: unresolved + }) + state.resolved = state.suppressed state.pending = undefined } diff --git a/src/main/crash-reporting/process-gone-recorder.test.ts b/src/main/crash-reporting/process-gone-recorder.test.ts index 07ca376e963..450b79ff313 100644 --- a/src/main/crash-reporting/process-gone-recorder.test.ts +++ b/src/main/crash-reporting/process-gone-recorder.test.ts @@ -55,6 +55,7 @@ beforeEach(() => { }) afterEach(() => { + vi.useRealTimers() vi.restoreAllMocks() _resetTracerForTests() clearCrashBreadcrumbsForTest() @@ -161,6 +162,7 @@ describe('recordProcessGoneCrash', () => { }) it('reports how many repeats a coalesced suppression stands for', () => { + vi.useFakeTimers() const dedupe = new ProcessGoneDedupe() const utilityCrash = event({ source: 'child', @@ -168,13 +170,11 @@ describe('recordProcessGoneCrash', () => { reason: 'crashed', details: { serviceName: 'network.mojom.NetworkService' } }) - const nowSpy = vi.spyOn(Date, 'now') - nowSpy.mockReturnValue(0) for (let i = 0; i < 700; i++) { recordProcessGoneCrash({ record: vi.fn() } as never, utilityCrash, dedupe) } - nowSpy.mockReturnValue(30_000) + vi.advanceTimersByTime(30_000) recordProcessGoneCrash({ record: vi.fn() } as never, utilityCrash, dedupe) expect(getCrashBreadcrumbSnapshot()).toEqual([