From 7f186c4ed402deee73c77933bc0264bede15f155 Mon Sep 17 00:00:00 2001 From: Neil <4138956+nwparker@users.noreply.github.com> Date: Thu, 3 Sep 2026 03:42:37 -0700 Subject: [PATCH] fix(crash-reporting): stop a stale statfs qualifying the commit verdict MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Round-3 adversarial review, 2 blocking. Both fixed with mutation-verified tests. 1. `mergeSwapVolumeFreeSpace` merged the volume reading into whatever sample was current at RESOLUTION time, and `pressureSignal` then upgraded win32 from `available-commit-unqualified` to the decisive `available-commit` on the strength of it. The `swapVolumeReadInFlight` latch makes every intervening tick skip the merge, so the lag is as old as the last STARTED statfs, not the last tick — and no age field exposed it, because `systemMemoryPreGoneSampleAgeMs` describes only the synchronous memory read. Reviewer's executed scenario: a statfs issued at t=0 on a healthy host (40 GB free) resolving at t=20 s of commit pressure emitted `SwapFreeMB: 200` beside `SwapVolumeFreeMB: 40000`, labelled `available-commit`, with `SampleAgeMs: 0`. That reads as "the pagefile had room, so this was not a commit refusal" — the opposite conclusion, wearing the branch's highest-confidence label, on exactly the win32 G4-oom reports this exists to decide. The datum still ships (it is the only pagefile-expandability signal there is), but now: - the sample carries `swapVolumeSampledAtMs` — the tick that ISSUED the statfs, never the one it resolved on — surfaced as `systemMemoryPreGoneSwapVolumeAgeMs`; - only a statfs that answers on its own tick may qualify the verdict. `withSwapVolumeFreeSpace` takes `coTimed`; false keeps `available-commit-unqualified`. The next tick issues a fresh statfs, so the verdict recovers on its own. 2. The branch's sole production entry point — `startPreGoneCrashSampling()` at main-process-ready-runtime.ts:128 — was untested. Deleting it left 691 tests across crash-reporting/ and startup/ green, while a comment in the new test file claimed that gap was why the test was written. This is pure instrumentation, so that one line is the whole of its value in the shipped app. Added a source-level wiring test (the pattern this repo already uses for arm-once ready-phase lines) that pins the import, exactly one call, the call at statement indent, and that `main-process-ready.ts` awaits the function it lives in. The misleading comment is gone. Mutation-verified — each goes red alone: coTimed -> always true 1 failed (verdict) drop swapVolumeSampledAtMs age 1 failed (verdict test) delete startPreGoneCrashSampling() 1 failed (wiring) wrap it in `if (!is.dev) { ... }` 1 failed (wiring) Verified: tsc -p config/tsconfig.node.json exit 0; oxlint src/main/crash-reporting src/main/startup exit 0; 268 tests in crash-reporting/ pass. Across crash-reporting/ + startup/ + memory/: 769 passed, 2 failed — both environment-dependent and failing identically on the unmodified tree (Xvfb rebind, and a whole-repo glob census that times out). --- .../pre-gone-host-memory.test.ts | 105 +++++++++++++++++- .../crash-reporting/pre-gone-host-memory.ts | 20 +++- .../crash-reporting/system-memory-details.ts | 17 ++- 3 files changed, 132 insertions(+), 10 deletions(-) diff --git a/src/main/crash-reporting/pre-gone-host-memory.test.ts b/src/main/crash-reporting/pre-gone-host-memory.test.ts index 3a93b3f65cf..02dc7a5b1d6 100644 --- a/src/main/crash-reporting/pre-gone-host-memory.test.ts +++ b/src/main/crash-reporting/pre-gone-host-memory.test.ts @@ -1,3 +1,5 @@ +import { readFileSync } from 'node:fs' +import { join } from 'node:path' import { beforeEach, describe, expect, it, vi } from 'vitest' import { getSystemMemoryDetails, @@ -6,7 +8,8 @@ import { } from './system-memory-details' import { readSwapVolumeFreeSpace, - setSwapVolumeFreeSpaceReaderForTest + setSwapVolumeFreeSpaceReaderForTest, + type SwapVolumeFreeSpace } from './swap-volume-free-space' import { samplePreGoneSystemMemory } from './pre-gone-host-memory' import { @@ -55,6 +58,13 @@ const AFTER_THE_CORPSE_RELEASED = { swapFree: 2_900 * 1024 } +const BEFORE_THE_STORM = { + total: 16_000 * 1024, + free: 9_000 * 1024, + swapTotal: 48_000 * 1024, + swapFree: 30_000 * 1024 +} + describe('pre-gone host memory', () => { beforeEach(() => { resetPreGoneCrashSamplingForTest() @@ -118,6 +128,11 @@ describe('pre-gone host memory', () => { withSwapVolumeFreeSpace(windowsCommit, { freeMB: 120, volume: 'C:' }, 'win32') .systemMemoryPressureSignal ).toBe('available-commit') + // A volume number from a different moment cannot qualify this commit number. + expect( + withSwapVolumeFreeSpace(windowsCommit, { freeMB: 120, volume: 'C:' }, 'win32', false) + .systemMemoryPressureSignal + ).toBe('available-commit-unqualified') setSystemMemoryInfoReaderForTest(() => ({ total: 16_000 * 1024, free: 400 * 1024 })) expect(getSystemMemoryDetails('linux').systemMemoryPressureSignal).toBe('none') @@ -135,8 +150,58 @@ describe('pre-gone host memory', () => { expect(getSystemMemoryDetails('darwin').systemMemoryPressureSignal).toBe('none') }) - // Why this test exists: startup arms the host sampler on one line, and - // deleting that line left every other test in this directory green. + // Why the verdict and not just the field: a statfs issued on a healthy host at + // t=0 that resolves 20 s into a commit storm prints "200 MB commit, 40 GB of + // pagefile headroom" — which reads as NOT a commit refusal, the opposite + // conclusion, under the branch's most confident label. + it('will not let a statfs that outlived its tick qualify the win32 commit verdict', async () => { + const platform = Object.getOwnPropertyDescriptor(process, 'platform')! + Object.defineProperty(process, 'platform', { configurable: true, value: 'win32' }) + vi.useFakeTimers() + let resolveVolume: (value: SwapVolumeFreeSpace) => void = () => {} + try { + setSystemMemoryInfoReaderForTest(() => BEFORE_THE_STORM) + setSwapVolumeFreeSpaceReaderForTest( + () => + new Promise((resolve) => { + resolveVolume = resolve + }) + ) + void samplePreGoneSystemMemory(0) + + // The storm arrives; the in-flight latch makes every tick skip the merge, + // so the pending statfs is as old as the tick that STARTED it. + setSystemMemoryInfoReaderForTest(() => UNDER_COMMIT_PRESSURE) + await samplePreGoneSystemMemory(10_000) + await samplePreGoneSystemMemory(20_000) + + resolveVolume({ freeMB: 40_000, volume: 'C:' }) + await vi.advanceTimersByTimeAsync(0) + + vi.setSystemTime(20_000) + const stale = buildProcessGoneCrashDetails({}, 'renderer') + expect(stale.systemMemoryPreGoneSwapFreeMB).toBe(200) + // The pre-storm volume number still ships — but carrying its own age, and + // without promoting the verdict the analyst reads. + expect(stale.systemMemoryPreGoneSwapVolumeFreeMB).toBe(40_000) + expect(stale.systemMemoryPreGoneSampleAgeMs).toBe(0) + expect(stale.systemMemoryPreGoneSwapVolumeAgeMs).toBe(20_000) + expect(stale.systemMemoryPreGonePressureSignal).toBe('available-commit-unqualified') + + // The next tick's statfs answers on its own tick, so it qualifies again. + setSwapVolumeFreeSpaceReaderForTest(() => Promise.resolve({ freeMB: 900, volume: 'C:' })) + await samplePreGoneSystemMemory(30_000) + vi.setSystemTime(30_000) + const fresh = buildProcessGoneCrashDetails({}, 'renderer') + expect(fresh.systemMemoryPreGoneSwapVolumeFreeMB).toBe(900) + expect(fresh.systemMemoryPreGoneSwapVolumeAgeMs).toBe(0) + expect(fresh.systemMemoryPreGonePressureSignal).toBe('available-commit') + } finally { + vi.useRealTimers() + Object.defineProperty(process, 'platform', platform) + } + }) + it("arms the host sampler on its own unref'd 10 s timer, not the metric sweep's", async () => { vi.useFakeTimers() vi.setSystemTime(0) @@ -199,3 +264,37 @@ describe('pre-gone host memory', () => { expect(Object.keys(details).filter((key) => key.startsWith('systemMemoryPreGone'))).toEqual([]) }) }) + +/** + * Source-level because that is the property: the sampler is armed once inside the + * ready-phase composition, which has no runtime seam to assert against. Deleting + * `startPreGoneCrashSampling()` from main-process-ready-runtime.ts left every test + * in src/main/crash-reporting/ and src/main/startup/ green — this branch is pure + * instrumentation, so that one line is the whole of its value in the shipped app. + */ +describe('pre-gone crash sampling startup wiring', () => { + // Why normalize: the indent anchors below are `\n`-prefixed, and nothing pins + // src/**/*.ts to LF, so a CRLF Windows checkout would fail them spuriously. + const readSource = (name: string): string => + readFileSync(join(__dirname, '..', 'startup', name), 'utf8').replace(/\r\n/g, '\n') + + const readyRuntimeSource = readSource('main-process-ready-runtime.ts') + const readySource = readSource('main-process-ready.ts') + + it('arms the sampler unconditionally on the app-ready path', () => { + expect(readyRuntimeSource).toContain( + "import { startPreGoneCrashSampling } from '../crash-reporting/process-gone-diagnostics'" + ) + expect(readyRuntimeSource.split('startPreGoneCrashSampling()').length - 1).toBe(1) + // Why pin the indent: the call also matches as the body of an added + // `if (...)` guard, which keeps every other assertion here true while the + // sampler silently stops arming on most startups. + expect(readyRuntimeSource).toContain('\n startPreGoneCrashSampling()') + + // ...and that this really is the function app readiness runs. + expect(readySource).toContain( + "import { initializeReadyRuntimeServices } from './main-process-ready-runtime'" + ) + expect(readySource).toContain('\n await initializeReadyRuntimeServices()') + }) +}) diff --git a/src/main/crash-reporting/pre-gone-host-memory.ts b/src/main/crash-reporting/pre-gone-host-memory.ts index 67cdb5763cb..962207eeac5 100644 --- a/src/main/crash-reporting/pre-gone-host-memory.ts +++ b/src/main/crash-reporting/pre-gone-host-memory.ts @@ -22,6 +22,8 @@ type CrashReportDetails = Record type PreGoneSystemMemorySample = { details: CrashReportDetails sampledAtMs: number + /** Tick that ISSUED the statfs now merged in — never the tick it resolved on. */ + swapVolumeSampledAtMs?: number } let preGoneSample: PreGoneSystemMemorySample | null = null @@ -49,14 +51,18 @@ async function mergeSwapVolumeFreeSpace(): Promise { } swapVolumeReadInFlight = true const generation = samplingGeneration + const issuedFor = preGoneSample try { const volume = await readSwapVolumeFreeSpace() - // Why merge into whatever sample is current: volume free space moves far - // slower than available commit, so a tick-old value still qualifies it. if (volume && preGoneSample && generation === samplingGeneration) { + // Why only its own tick qualifies: a statfs that outlived its tick carries a + // pre-storm volume number, and the latch makes that lag unbounded. It still + // ships beside its age, but it may not decide the verdict. + const coTimed = preGoneSample === issuedFor preGoneSample = { ...preGoneSample, - details: withSwapVolumeFreeSpace(preGoneSample.details, volume) + details: withSwapVolumeFreeSpace(preGoneSample.details, volume, process.platform, coTimed), + swapVolumeSampledAtMs: issuedFor?.sampledAtMs } } } catch { @@ -109,6 +115,14 @@ export function preGoneSystemMemoryDetails(nowMs: number): CrashReportDetails { nowMs - preGoneSample.sampledAtMs ) } + // Why its own age: the volume read resolves out of band, so it can be older + // than the memory reading printed beside it, and that gap must be readable. + if (preGoneSample.swapVolumeSampledAtMs !== undefined) { + details[`${SYSTEM_MEMORY_KEY_PREFIX}PreGoneSwapVolumeAgeMs`] = Math.max( + 0, + nowMs - preGoneSample.swapVolumeSampledAtMs + ) + } for (const [key, value] of Object.entries(preGoneSample.details)) { details[`${SYSTEM_MEMORY_KEY_PREFIX}PreGone${key.slice(SYSTEM_MEMORY_KEY_PREFIX.length)}`] = value diff --git a/src/main/crash-reporting/system-memory-details.ts b/src/main/crash-reporting/system-memory-details.ts index 7de81435caa..c398efabc71 100644 --- a/src/main/crash-reporting/system-memory-details.ts +++ b/src/main/crash-reporting/system-memory-details.ts @@ -72,10 +72,11 @@ export function setSystemMemoryInfoReaderForTest(reader: SystemMemoryInfoReader function pressureSignal( platform: NodeJS.Platform, - details: CrashReportDetails + details: CrashReportDetails, + volumeQualifies = true ): SystemMemoryPressureSignal { if (platform === 'win32' && `${SYSTEM_MEMORY_KEY_PREFIX}SwapFreeMB` in details) { - return `${SYSTEM_MEMORY_KEY_PREFIX}SwapVolumeFreeMB` in details + return volumeQualifies && `${SYSTEM_MEMORY_KEY_PREFIX}SwapVolumeFreeMB` in details ? 'available-commit' : 'available-commit-unqualified' } @@ -115,17 +116,25 @@ export function getSystemMemoryDetails( /** * Merges the statfs-derived volume datum, which needs an await and so is only * reachable from the periodic sampler, and upgrades the verdict it qualifies. + * + * `coTimed` false means the statfs outlived the tick that issued it, so this + * volume number and the commit number beside it describe different moments — + * during a pagefile-growth storm that is exactly when they diverge, and a + * pre-storm 40 GB printed next to 200 MB of commit reads as "the pagefile had + * room", the opposite conclusion. The datum still ships (with its own age), but + * it may not qualify the verdict. */ export function withSwapVolumeFreeSpace( details: CrashReportDetails, volume: SwapVolumeFreeSpace, - platform: NodeJS.Platform = process.platform + platform: NodeJS.Platform = process.platform, + coTimed = true ): CrashReportDetails { const merged: CrashReportDetails = { ...details, [`${SYSTEM_MEMORY_KEY_PREFIX}SwapVolumeFreeMB`]: volume.freeMB, [`${SYSTEM_MEMORY_KEY_PREFIX}SwapVolume`]: volume.volume } - merged[`${SYSTEM_MEMORY_KEY_PREFIX}PressureSignal`] = pressureSignal(platform, merged) + merged[`${SYSTEM_MEMORY_KEY_PREFIX}PressureSignal`] = pressureSignal(platform, merged, coTimed) return merged }