From df3dd226f68a035604ac3dc8408aceb032009952 Mon Sep 17 00:00:00 2001 From: Staff Engineer Date: Wed, 23 Sep 2026 15:42:18 +0000 Subject: [PATCH 1/3] fix(tests): fill stderr until it reports backpressure, not to a fixed 200 KB (BLO-25854) `still exits when stderr is not drained` was failing with "fixture exited before reporting stderr backpressure" on ~5 merge_group/master runs since 2026-09-16, making it the most persistent flake in the repo. Root cause is not CI load. The fixture bet a constant against the pipe: const accepted = process.stderr.write("P".repeat(200_000)); if (accepted) throw new Error("stderr did not report backpressure"); `stdio: "pipe"` is a unix socketpair, not the 64 KB pipe the comment assumed, and `write()` returns false only when libuv cannot take the WHOLE buffer at once. So what governs is the largest SINGLE write the socket accepts, which scales with the runner's net.core.wmem_default. On a runner whose threshold clears 200 KB the write was accepted, the fixture threw during setup, and it exited before stdout ever emitted BACKPRESSURE. That means on those runners the stalled-stderr path was never exercised at all -- the test was erroring out in setup, so this flake was also hiding a coverage hole, not just adding noise. Fill in chunks until the stream actually reports backpressure (bounded at 8 MB) instead of re-tuning the constant, so it holds whatever the host is tuned to. Also stop discarding the child's stderr on this failure path. `child.stderr .destroy()` ran before anything read it, which is why five occurrences were unattributable; the parent now reports the child's own message ("stderr did not report backpressure") alongside exit code and signal. Both ends are kept because the guard's writeSync breadcrumbs and the fixture's streamed padding interleave at the fd, and truncating to either end alone buries the line that names the cause. Verified by mutation: forcing the old single-write logic under this host's threshold reproduces the exact CI signature, and the looping fixture survives the same mutation. 10/10 consecutive local runs pass. --- .../fixtures/crash-guard-exit-fixture.ts | 42 +++++++++-- .../process-crash-guard-exit.test.ts | 73 +++++++++++++++++-- 2 files changed, 101 insertions(+), 14 deletions(-) diff --git a/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts b/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts index 76dfa2855a3f..5b7db795dc33 100644 --- a/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts +++ b/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts @@ -8,12 +8,12 @@ * * argv[2] — crash kind: "throw" (uncaughtException) | "reject" (unhandledRejection) * argv[3] — bytes of padding to inflate the error message, and therefore the - * stack breadcrumb, past the 64 KB pipe buffer. Real postgres errors - * embed query text and get large; padding makes the pressure - * deterministic instead of hoping a stack is big enough. - * argv[4] — "prefill-stderr" fills the pipe first, reports observed stream - * backpressure on stdout, then waits for a parent ack on stdin - * before triggering the crash. + * stack breadcrumb. Real postgres errors embed query text and get + * large; padding makes the pressure deterministic instead of hoping a + * stack is big enough. + * argv[4] — "prefill-stderr" fills stderr until the stream reports backpressure, + * reports that on stdout, then waits for a parent ack on stdin before + * triggering the crash. */ import { installProcessCrashGuard } from "../../process-crash-guard.js"; @@ -46,8 +46,34 @@ function triggerCrash(): void { } if (prefillStderr) { - const accepted = process.stderr.write("P".repeat(200_000)); - if (accepted) throw new Error("stderr did not report backpressure"); + // Fill until the stream actually reports backpressure, rather than betting a + // constant beats the buffer. + // + // `stdio: "pipe"` is a unix socketpair, not the 64 KB pipe this fixture used to + // assume. `write()` returns false only when libuv's non-blocking writev cannot + // take the WHOLE buffer at once, so what governs is the largest SINGLE write the + // socket accepts — not its total capacity. Those are not the same number and not + // close: measured on one host, single-write threshold ~146 KB against ~288 KB + // cumulative. Re-deriving this by measuring capacity alone yields a figure over + // 200 KB and the wrong conclusion that the old constant was safe. + // + // Both scale with the runner's net.core.wmem_default (212992 by default, higher on + // tuned hosts). On a runner whose single-write threshold clears 200 KB, the old + // `write("P".repeat(200_000))` was accepted, so this threw before stdout ever saw + // BACKPRESSURE and the parent reported only "fixture exited before reporting + // stderr backpressure" — reproduced exactly by lowering the constant under one + // host's threshold. That is the whole of BLO-25854: a host-dependent buffer + // assumption, not the CI-load race the issue was filed as. Looping removes the bet + // rather than re-tuning it, so it holds whatever the host is tuned to. + const CHUNK_BYTES = 64_000; + const CEILING_BYTES = 8_000_000; + let accepted = true; + let written = 0; + while (accepted && written < CEILING_BYTES) { + accepted = process.stderr.write("P".repeat(CHUNK_BYTES)); + written += CHUNK_BYTES; + } + if (accepted) throw new Error(`stderr did not report backpressure after ${written} bytes`); // Do not let child exit race the parent's stdout listener. The ack arrives // only after the parent has observed backpressure and started its deadline. diff --git a/server/src/__tests__/process-crash-guard-exit.test.ts b/server/src/__tests__/process-crash-guard-exit.test.ts index b4926507a561..2e354756161b 100644 --- a/server/src/__tests__/process-crash-guard-exit.test.ts +++ b/server/src/__tests__/process-crash-guard-exit.test.ts @@ -20,6 +20,7 @@ */ import { spawn } from "node:child_process"; +import type { Readable } from "node:stream"; import { fileURLToPath } from "node:url"; import path from "node:path"; import { describe, expect, it } from "vitest"; @@ -28,7 +29,16 @@ const here = path.dirname(fileURLToPath(import.meta.url)); const fixture = path.join(here, "fixtures", "crash-guard-exit-fixture.ts"); const tsx = path.resolve(here, "..", "..", "node_modules", ".bin", "tsx"); -/** Enough to overrun the 64 KB pipe buffer several times over. */ +/** + * Padding for the *crash message*, to make the guard's breadcrumb writes large. + * These four cases drain stderr, so they assert on content rather than on the channel + * filling up, and this constant carries no backpressure assumption. It used to be + * described as overrunning "the 64 KB pipe buffer": `stdio: "pipe"` is really a unix + * socketpair sized by net.core.wmem_default (212992 by default), and betting a + * constant against that unknown is exactly what made the stalled-stderr case flake + * (BLO-25854). The stalled case now fills until the stream reports backpressure + * instead of guessing. + */ const PIPE_PRESSURE_BYTES = 200_000; /** Child startup is outside the measured crash deadline and can lag on loaded CI runners. */ const FIXTURE_STARTUP_TIMEOUT_MS = 10_000; @@ -39,14 +49,24 @@ const FIXTURE_STARTUP_TIMEOUT_MS = 10_000; * literal because at a bare 5_000 it contradicted the constant directly above — this * budget spans spawn through child exit, a superset of the startup that * FIXTURE_STARTUP_TIMEOUT_MS already says can take 10s on a loaded runner, and it - * additionally has to cover the crash and draining PIPE_PRESSURE_BYTES through a - * 64 KB pipe. Deriving it keeps the two watchdogs in this file from disagreeing + * additionally has to cover the crash and draining PIPE_PRESSURE_BYTES through the + * stderr socket. Deriving it keeps the two watchdogs in this file from disagreeing * again about how slow a loaded runner is allowed to be. */ const FIXTURE_RUN_WATCHDOG_MS = FIXTURE_STARTUP_TIMEOUT_MS + 5_000; /** * The behaviour under test: with stderr stalled, the guard must still exit this fast. * This is the contract — tighten or loosen it only when the guard's own deadline moves. + * + * Deliberately left at 1_500 by BLO-25854, which fixed the *other* failure signature on + * this test and stopped short of this one. This bound spends only 30% of the guard's + * DEFAULT_CRASH_GUARD_TIMEOUT_MS, and has been seen failing at 1547ms on a loaded + * runner — a 3% overshoot against 70% unused budget. Deriving it from that constant is + * the obvious repair, but a mutation test (deleting the `timer.unref()` early exit the + * assertion exists to protect) failed through the startup watchdog rather than through + * this assertion, so the re-derivation could not be shown to preserve what it catches. + * Tracked as BLO-22985 (hardcoded wall-clock budgets under CI load) rather than changed + * here on an unvalidated rationale. */ const STALLED_EXIT_DEADLINE_MS = 1_500; /** @@ -108,6 +128,40 @@ function runFixture(kind: "throw" | "reject", padBytes: number, strictRejections }); } +/** + * Whatever the deliberately-undrained stderr pipe still holds now the child is gone. + * Reading it earlier would drain the stall this test exists to create; discarding it + * (what `child.stderr.destroy()` used to do on this path) is why five occurrences of + * `fixture exited before reporting stderr backpressure` were unattributable. + * + * Keep both ends, not one: the fixture's padding goes through the stream while the + * guard's breadcrumbs go through `writeSync`, so the two interleave at the fd in an + * order that depends on how much of the padding had flushed. Truncating to either end + * alone was observed burying the one line that names the cause under the padding. + */ +function readRemainingStderr(stream: Readable): Promise { + return new Promise((done) => { + let out = ""; + const finish = (): void => { + clearTimeout(bail); + stream.destroy(); + done( + out.length > 2_000 + ? `${out.slice(0, 1_000)} …(${out.length} bytes, middle elided)… ${out.slice(-1_000)}` + : out, + ); + }; + const bail = setTimeout(finish, 1_000); + stream.setEncoding("utf8"); + stream.on("data", (chunk: string) => { + out += chunk; + }); + stream.once("end", finish); + stream.once("error", finish); + stream.resume(); + }); +} + function runFixtureWithStalledStderr(): Promise { return new Promise((resolve, reject) => { const child = spawn(tsx, [fixture, "throw", "0", "prefill-stderr"], { @@ -140,14 +194,21 @@ function runFixtureWithStalledStderr(): Promise { }); child.on("error", reject); - child.on("exit", (code) => { + child.on("exit", (code, signal) => { clearTimeout(startupWatchdog); if (watchdog) clearTimeout(watchdog); - child.stderr.destroy(); if (startedAt === undefined) { - reject(new Error("fixture exited before reporting stderr backpressure")); + void readRemainingStderr(child.stderr).then((stderr) => { + reject( + new Error( + `fixture exited before reporting stderr backpressure ` + + `(code=${code}, signal=${signal}); its stderr said: ${stderr.trim() || ""}`, + ), + ); + }); return; } + child.stderr.destroy(); resolve({ code, elapsedMs: Date.now() - startedAt }); }); }); From 8f8c3bc223da1e74a86f91ee93ebe9966acd6114 Mon Sep 17 00:00:00 2001 From: Omar Ramadan Date: Wed, 23 Sep 2026 22:12:49 +0000 Subject: [PATCH 2/3] docs(tests): state the real write() backpressure predicate Ally flagged two comments in the BLO-25854 stderr-backpressure fix as wrong for the code they describe. The fixture said write() returns false only when libuv cannot take the whole buffer; it actually returns state.length < writableHighWaterMark after the synchronous writev, so the loop is governed by the high-water mark and overshoots the first refused write by ceil(hwm / CHUNK_BYTES) iterations. The test said the guard's breadcrumbs go through writeSync; with socket stderr they fall through isRegularFile to process.stderr.write, so padding and breadcrumbs are FIFO on one stream and a queued breadcrumb can be dropped at exit. Rewrite both comments, note that CHUNK_BYTES depends on the Node default high-water mark (16 KiB before Node 22, 64 KiB from 22), and take three behaviour-neutral suggestions: hoist the chunk string, a settled flag in readRemainingStderr, and .catch(reject) on its promise. Also correct the "four cases" count to the three runFixture cases using the padding. Controls: vitest on process-crash-guard-exit + process-crash-guard, 20/20 pass; server typecheck passes; a Node 24 probe showed write 4 returning true at writableLength 64000 < 65536 and write 5 false at 128000; CEILING_BYTES=64_000 turns the stalled case red with "stderr did not report backpressure after 64000 bytes", green again after revert. Co-Authored-By: Claude Opus 5.5 (1M context) Signed-off-by: Omar Ramadan --- .../fixtures/crash-guard-exit-fixture.ts | 43 +++++++++++------ .../process-crash-guard-exit.test.ts | 47 +++++++++++-------- 2 files changed, 56 insertions(+), 34 deletions(-) diff --git a/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts b/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts index 5b7db795dc33..efbc90b6d6c0 100644 --- a/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts +++ b/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts @@ -50,27 +50,40 @@ if (prefillStderr) { // constant beats the buffer. // // `stdio: "pipe"` is a unix socketpair, not the 64 KB pipe this fixture used to - // assume. `write()` returns false only when libuv's non-blocking writev cannot - // take the WHOLE buffer at once, so what governs is the largest SINGLE write the - // socket accepts — not its total capacity. Those are not the same number and not - // close: measured on one host, single-write threshold ~146 KB against ~288 KB - // cumulative. Re-deriving this by measuring capacity alone yields a figure over - // 200 KB and the wrong conclusion that the old constant was safe. + // assume. `write()` returns `state.length < writableHighWaterMark`, evaluated after + // libuv's synchronous non-blocking writev attempt. `state.length` only grows when + // the kernel refuses bytes, so false means "the kernel refused AND the userland + // queue has reached the high-water mark"; a false backpressure reading cannot + // happen. It also means this loop overshoots the first refused write by + // ceil(hwm / CHUNK_BYTES) iterations (measured on Node 24: write 4 was the first + // refused and still returned true at length 64000 < 65536; write 5 returned false). // - // Both scale with the runner's net.core.wmem_default (212992 by default, higher on - // tuned hosts). On a runner whose single-write threshold clears 200 KB, the old - // `write("P".repeat(200_000))` was accepted, so this threw before stdout ever saw - // BACKPRESSURE and the parent reported only "fixture exited before reporting - // stderr backpressure" — reproduced exactly by lowering the constant under one - // host's threshold. That is the whole of BLO-25854: a host-dependent buffer - // assumption, not the CI-load race the issue was filed as. Looping removes the bet - // rather than re-tuning it, so it holds whatever the host is tuned to. + // What sank the OLD single 200 KB write: for one write, the refusal comes from the + // socket not taking that whole buffer at once, and that single-write threshold is + // not the socket's cumulative capacity. Measured on one host, ~146 KB single-write + // against ~288 KB cumulative. Re-deriving the old constant by measuring capacity + // alone yields a figure over 200 KB and the wrong conclusion that it was safe. + // Neither number governs the loop below; the high-water mark does. + // + // Both socket numbers scale with the runner's net.core.wmem_default (212992 by + // default, higher on tuned hosts). On a runner whose single-write threshold clears + // 200 KB, the old `write("P".repeat(200_000))` was accepted, so this threw before + // stdout ever saw BACKPRESSURE and the parent reported only "fixture exited before + // reporting stderr backpressure", reproduced exactly by lowering the constant + // under one host's threshold. That is the whole of BLO-25854: a host-dependent + // buffer assumption, not the CI-load race the issue was filed as. Looping removes + // the bet rather than re-tuning it, so it holds whatever the host is tuned to. + // + // CHUNK_BYTES is chosen against `process.stderr.writableHighWaterMark`, not against + // the socket. That default was 16 KiB before Node 22 and is 64 KiB from Node 22, so + // the overshoot above is a silent Node-version dependency. const CHUNK_BYTES = 64_000; const CEILING_BYTES = 8_000_000; + const chunk = "P".repeat(CHUNK_BYTES); let accepted = true; let written = 0; while (accepted && written < CEILING_BYTES) { - accepted = process.stderr.write("P".repeat(CHUNK_BYTES)); + accepted = process.stderr.write(chunk); written += CHUNK_BYTES; } if (accepted) throw new Error(`stderr did not report backpressure after ${written} bytes`); diff --git a/server/src/__tests__/process-crash-guard-exit.test.ts b/server/src/__tests__/process-crash-guard-exit.test.ts index 2e354756161b..d2263d30eb9a 100644 --- a/server/src/__tests__/process-crash-guard-exit.test.ts +++ b/server/src/__tests__/process-crash-guard-exit.test.ts @@ -31,13 +31,13 @@ const tsx = path.resolve(here, "..", "..", "node_modules", ".bin", "tsx"); /** * Padding for the *crash message*, to make the guard's breadcrumb writes large. - * These four cases drain stderr, so they assert on content rather than on the channel - * filling up, and this constant carries no backpressure assumption. It used to be - * described as overrunning "the 64 KB pipe buffer": `stdio: "pipe"` is really a unix - * socketpair sized by net.core.wmem_default (212992 by default), and betting a - * constant against that unknown is exactly what made the stalled-stderr case flake - * (BLO-25854). The stalled case now fills until the stream reports backpressure - * instead of guessing. + * The three `runFixture` cases that pass it drain stderr, so they assert on content + * rather than on the channel filling up, and this constant carries no backpressure + * assumption. It used to be described as overrunning "the 64 KB pipe buffer": + * `stdio: "pipe"` is really a unix socketpair sized by net.core.wmem_default (212992 + * by default), and betting a constant against that unknown is exactly what made the + * stalled-stderr case flake (BLO-25854). The stalled case now fills until the stream + * reports backpressure instead of guessing. */ const PIPE_PRESSURE_BYTES = 200_000; /** Child startup is outside the measured crash deadline and can lag on loaded CI runners. */ @@ -134,15 +134,22 @@ function runFixture(kind: "throw" | "reject", padBytes: number, strictRejections * (what `child.stderr.destroy()` used to do on this path) is why five occurrences of * `fixture exited before reporting stderr backpressure` were unattributable. * - * Keep both ends, not one: the fixture's padding goes through the stream while the - * guard's breadcrumbs go through `writeSync`, so the two interleave at the fd in an - * order that depends on how much of the padding had flushed. Truncating to either end - * alone was observed burying the one line that names the cause under the padding. + * Stderr here is a socket, so `writeShutdownBreadcrumb` and + * `writeShutdownBreadcrumbsBounded` fall through their `isRegularFile` guard to + * `process.stderr.write`. Padding and breadcrumbs therefore share one stream and are + * strictly FIFO behind it; they do not interleave. Behind a full socket, a breadcrumb + * queued at crash time can be dropped at exit instead of landing after the padding. + * + * Keep both ends, not one: head and tail are both cheap context. Truncating to either + * end alone was observed burying the one line that names the cause under the padding. */ function readRemainingStderr(stream: Readable): Promise { return new Promise((done) => { let out = ""; + let settled = false; const finish = (): void => { + if (settled) return; + settled = true; clearTimeout(bail); stream.destroy(); done( @@ -198,14 +205,16 @@ function runFixtureWithStalledStderr(): Promise { clearTimeout(startupWatchdog); if (watchdog) clearTimeout(watchdog); if (startedAt === undefined) { - void readRemainingStderr(child.stderr).then((stderr) => { - reject( - new Error( - `fixture exited before reporting stderr backpressure ` + - `(code=${code}, signal=${signal}); its stderr said: ${stderr.trim() || ""}`, - ), - ); - }); + void readRemainingStderr(child.stderr) + .then((stderr) => { + reject( + new Error( + `fixture exited before reporting stderr backpressure ` + + `(code=${code}, signal=${signal}); its stderr said: ${stderr.trim() || ""}`, + ), + ); + }) + .catch(reject); return; } child.stderr.destroy(); From 476c0baabdbdadb51a62b472289b8743aaea046e Mon Sep 17 00:00:00 2001 From: Staff Engineer Date: Wed, 23 Sep 2026 22:46:41 +0000 Subject: [PATCH 3/3] test(crash-guard): report the fixture's ceiling failure on stdout (BLO-25854) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Last of Ally's suggestions on #2001, and the only one not taken in 8f8c3bc2. The `CEILING_BYTES` branch is the one failure mode the fill-until-backpressure loop introduces, and it is the worst place to be heard from: stderr is by definition still accepting there, so the throw's breadcrumb joins the padding and the parent's stderr diagnostic recovers nothing but "P"s once the head/tail elision bites. Write the reason on stdout, which the parent drains, and surface child stdout in the parent's reject message alongside stderr. Lower-case "backpressure" is deliberate — the parent's readiness match is on the exact token BACKPRESSURE and this line must not satisfy it. Not taken from the same suggestion: `written` does not overstate by a chunk. The throw is guarded on `accepted`, so it is only reached when every write returned true; the bytes it reports were all handed to `stderr.write`. The off-by-one would apply to the `accepted === false` exit, which reports no figure. Verification: mutating CEILING_BYTES to 64_000 turns the stalled case red with `its stdout said: FIXTURE-ERROR stderr did not report backpressure after 64000 bytes` leading the message instead of 64 KB of padding; green again after revert. Server typecheck clean; both crash-guard suites 20/20; the exit suite passed 10/10 consecutive runs under synthetic CPU load. Co-Authored-By: Claude --- .../__tests__/fixtures/crash-guard-exit-fixture.ts | 12 +++++++++++- .../src/__tests__/process-crash-guard-exit.test.ts | 8 +++++++- 2 files changed, 18 insertions(+), 2 deletions(-) diff --git a/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts b/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts index efbc90b6d6c0..7898c1d10134 100644 --- a/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts +++ b/server/src/__tests__/fixtures/crash-guard-exit-fixture.ts @@ -86,7 +86,17 @@ if (prefillStderr) { accepted = process.stderr.write(chunk); written += CHUNK_BYTES; } - if (accepted) throw new Error(`stderr did not report backpressure after ${written} bytes`); + if (accepted) { + // The ceiling is the one failure mode this loop adds, and it is the worst place + // to be heard from: stderr is by definition still accepting here, so the throw's + // breadcrumb joins ~8 MB of padding and the parent's stderr diagnostic recovers + // nothing but "P"s. Say it on stdout, which the parent drains, so this stays + // attributable by the same mechanism the rest of BLO-25854 is adding. + // Lower-case "backpressure" is deliberate: the parent's readiness match is on the + // exact token BACKPRESSURE, and this line must not satisfy it. + process.stdout.write(`FIXTURE-ERROR stderr did not report backpressure after ${written} bytes\n`); + throw new Error(`stderr did not report backpressure after ${written} bytes`); + } // Do not let child exit race the parent's stdout listener. The ack arrives // only after the parent has observed backpressure and started its deadline. diff --git a/server/src/__tests__/process-crash-guard-exit.test.ts b/server/src/__tests__/process-crash-guard-exit.test.ts index d2263d30eb9a..0b2a080708ff 100644 --- a/server/src/__tests__/process-crash-guard-exit.test.ts +++ b/server/src/__tests__/process-crash-guard-exit.test.ts @@ -184,7 +184,12 @@ function runFixtureWithStalledStderr(): Promise { }, FIXTURE_STARTUP_TIMEOUT_MS); child.stdout.setEncoding("utf8"); + // Captured for the failure path below. Once the fixture has deliberately filled + // stderr, stdout is the only channel it can still be heard on — see the ceiling + // branch in the fixture. + let stdout = ""; child.stdout.on("data", (chunk: string) => { + stdout += chunk; if (startedAt !== undefined || !chunk.includes("BACKPRESSURE")) return; clearTimeout(startupWatchdog); startedAt = Date.now(); @@ -210,7 +215,8 @@ function runFixtureWithStalledStderr(): Promise { reject( new Error( `fixture exited before reporting stderr backpressure ` + - `(code=${code}, signal=${signal}); its stderr said: ${stderr.trim() || ""}`, + `(code=${code}, signal=${signal}); its stdout said: ${stdout.trim() || ""}; ` + + `its stderr said: ${stderr.trim() || ""}`, ), ); })