fix(tests): fill stderr until it reports backpressure, not to a fixed 200 KB (BLO-25854)

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,57 @@ 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 `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).
+  //
+  // 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(chunk);
+    written += CHUNK_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.

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.
+ * 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. */
 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,47 @@ 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.
+ *
+ * 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<string> {
+  return new Promise((done) => {
+    let out = "";
+    let settled = false;
+    const finish = (): void => {
+      if (settled) return;
+      settled = true;
+      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<StalledCrashResult> {
   return new Promise((resolve, reject) => {
     const child = spawn(tsx, [fixture, "throw", "0", "prefill-stderr"], {
@@ -123,7 +184,12 @@ function runFixtureWithStalledStderr(): Promise<StalledCrashResult> {
     }, 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();
@@ -140,14 +206,24 @@ function runFixtureWithStalledStderr(): Promise<StalledCrashResult> {
     });
 
     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 stdout said: ${stdout.trim() || "<nothing>"}; ` +
+                  `its stderr said: ${stderr.trim() || "<nothing>"}`,
+              ),
+            );
+          })
+          .catch(reject);
         return;
       }
+      child.stderr.destroy();
       resolve({ code, elapsedMs: Date.now() - startedAt });
     });
   });