test: fix the three Windows CI races (C6 multipart reset, store lock wait, smoke keep-alive reuse)

docs/CHANGELOG.md

@@ -2,6 +2,12 @@
 
 ## Unreleased
 
+### Follow-up `windows-ci-races`: races the Windows leg lost under load, and the same races beside them
+- **`tools/test-bundle-compare.mjs` C6: a multipart request to the child server leaves no tail unread** (a test fix; no runtime, `tools/lib`, golden or output change). C6 failed the `windows (node 22)` job of run 38737724941 (`not ok 810 - C6 retrofeed in the shim`, `fetch failed` at the `serverFetch` call in `same()`) on the tree that had passed at 7950b03. Its `multipart/form-data is not parsed` case POSTs a `FormData`, which fetch streams in parts: the headers and the first part in one write, the closing boundary in a later one. The server parses no multipart, so retrofeed answers its 404 from the headers alone, and with `connection: close` (which `serverFetch` sets since the C3 keep-alive fix) Node's server closes the socket right after the answer, the closing boundary unread: its TCP stack sends an RST behind the 404. Linux still hands the client the 404; Windows discards bytes the client had not read when the RST lands (`WSAECONNRESET`), and fetch, with no status line yet, fails. `serverFetch`, in this file and in `tools/test-bundle-compare-pairs.mjs` (the same text, C3 pins it), now builds the request through `new Request()` and hands fetch its body as one `ArrayBuffer`, so the body leaves in the headers' write and the server reads all of it before it closes; the bytes and the Content-Type, boundary included, are the ones fetch would send, the shim still receives the original `FormData`, and a GET sends no body. On Linux (node 22.22.2), 40 multipart requests to a real child server made the server's kernel send 26–29 RSTs before and 0 after; through a relay that discards unread data on an RST as Winsock does, `TypeError: fetch failed` (cause `ECONNRESET`) came back 1–5 times in 40 before and 0 after, and C6's other request kinds 0 either way. Under four busy loops, ten runs of the 40: 6–16 RSTs and 3–10 failures in each before, 0 and 0 in each after. C3 now also pins it: a `FormData` goes to fetch as one buffer, with the bytes fetch serializes it to, `connection: close`, and a GET with a null body — an assertion in an existing test (it fails against the previous `serverFetch`), so Suite total 1519 → 1519.
+- **`server/test-store.mjs` Concurrency: a parent waits out the lock-holding child for as long as the child takes to commit** (a test fix; no runtime, `tools/lib`, golden or output change — the store's `BUSY_TIMEOUT_MS`, 5000 ms, is unchanged and still pinned on `openStore`). `Concurrency: a migration waits out a child holding BEGIN IMMEDIATE, then applies` failed the `windows (node 22)` job of run 38737678276 with `database is locked` (9.9 s; the same run's write sibling waited 2355 ms of a 700 ms hold). Each of the three Concurrency tests races two clocks: the parent's busy_timeout, 5000 ms from the child's "locked", against the child's hold of 700 ms plus its COMMIT plus however long a loaded runner keeps it off the CPU; the migration's child pays the most, since `closeStore` removed the `-wal` and `openRaw` leaves `synchronous` at FULL, so its commit syncs a new WAL header and then the commit inside the window. When the child's window outlasts the parent's budget, SQLite's busy handler gives up and `BEGIN IMMEDIATE` fails. The lock holder now sets `synchronous=OFF` (its durability is not under test, its lock is: no fsync between "locked" and its exit), and every parent that waits one out — the write, the migration and the repository write — waits up to `LOCK_WAIT_LIVENESS_MS`, 30 s, a liveness bound nothing asserts (the tests assert only that the wait was at least 300 ms, and what was written); a successful wait still ends at the child's COMMIT, about 700 ms. Reproduced on Linux (node 22.22.2) by delaying every `fsync` 1.8 s (`strace -f -e inject=fsync:delay_exit=1800000`) over the three tests, ten runs each: before, the write and the repository write waited 4.2–4.3 s and passed and the migration failed with `database is locked` in every run, as on CI; after, all three passed in every run (the write and the repository write waiting 0.6–0.7 s; the migration's 4.3 s is its own commit's syncs, outside the lock wait). And with the child's hold raised to 6 s, a window past the 5000 ms budget as a stalled child's would be, all three failed with `database is locked` before and pass after. No test added or removed: the suite total stays 1519.
+- **`server/test-store.mjs` `Migrations: two openers racing the same step apply it once`: the parent waits out the migrating child as the Concurrency tests wait out their lock holder** (a test fix; no runtime, `tools/lib`, golden or output change). It is the fourth test in which a parent waits on a lock another process holds, and it ran the same race: the child's `runMigrations` takes `BEGIN IMMEDIATE`, says "locked" from inside the step, holds 700 ms and commits into a fresh rollback-journal file at `openRaw`'s `synchronous` FULL (the journal and the database fsynced inside the window), while the parent's `openRaw` waited at the store's 5000 ms. The child now sets `synchronous=OFF` and the parent opens with `LOCK_WAIT_LIVENESS_MS` (30 s, liveness only); every assertion stands (the child applied `[1]`, the parent `[]` after re-reading `user_version` inside its transaction, and `applied` holds only `child`). With every `fsync` delayed 1.8 s on Linux (node 22.22.2), ten runs each: before, `database is locked` in 10 of 10 (the three Concurrency tests passing beside it); after, 10 of 10 pass. With the child's hold raised to 6 s: `database is locked` after 5.1 s before, a pass after. A sweep of the `server/` and `tools/` tests for a parent waiting on a lock another process holds (`lockHolder`, `BEGIN IMMEDIATE`, `Atomics.wait`, `openRaw` beside a spawned holder) finds four — `Concurrency: a write waits out a child holding BEGIN IMMEDIATE for less than busy_timeout, then succeeds`, `Concurrency: a migration waits out a child holding BEGIN IMMEDIATE, then applies` and `Concurrency: a repository write waits out a child holding BEGIN IMMEDIATE, then succeeds with its audit row` (the entry above) and this one — and no other: `packc store backup while a server holds the store` runs beside a `lockHolder(2500)`, but its `VACUUM INTO` only reads a WAL database and never waits on the writer (it passes under the same fsync delay); the restore tests expect the in-use refusal, with no busy wait; and the suites that plant rows with `openRaw` into a running server's store (`test-authz`, `test-auth-proxy`, `test-transport-hook`) write while the server is idle and holds no lock. No test added or removed: the suite total stays 1519.
+- **`server/test-smoke.mjs`: the boot-line check boots its three servers off the event loop, so the next request does not go out on a keep-alive socket both sides' timers have expired** (a test fix; no runtime, `tools/lib`, golden or output change — the server is unchanged). The smoke suite failed the `windows (node 22.16.0)` job of run 38737724941 at `server/test-smoke.mjs:1578`, the `POST /api/refresh-live` with no `mcpUrl` that expects a 400: `TypeError: fetch failed`, cause `read ECONNRESET`. Just before it, the boot-line check runs three `boot()`s from `server/fixtures/serve-child.mjs`, each a `spawnSync` of a whole server start, and `spawnSync` stops this process's event loop for the whole boot. That loop also runs the suite's own server: `start()` in the same process, with Node's default `keepAliveTimeout` (5 s; an idle socket closes about 6 s after its last answer). fetch's socket to that server, pooled since the request before the check, sits idle through the boots, past fetch's keep-alive (the server's advertised 5 s less 2 s) and past the server's, and neither timer can run. The POST takes that socket at once. When the loop resumes in its poll, check or close phase, the server's timer runs before the server reads the socket: it closes the socket with the request unread, the kernel answers with a reset, and fetch fails. fetch retries nothing on a socket error (undici's idle-socket check that defers such a reuse first shipped in undici 7.28.0 and 8.5.0, not in node 22's 6.21.2 and 6.24.1; the commit that made this change says "undici 7", which is too broad). On a runner where the three boots take less than about 6 s, the socket is still open and the POST is answered, so the race fired only where a boot is slow. `serve-child.mjs` now also exports `bootAsync`: the same child, the same environment and the same result as `boot`, through `spawn`. The smoke awaits it for its three boots, so both keep-alive timers run while the children boot and the POST opens a new connection. `boot` is unchanged for its other callers. Reproduced on Linux with each boot child delayed 2 s by a `--require` preload (a slow runner's boot), `node server/test-smoke.mjs`: on node 22.22.2 the base failed all 40 runs of its last two batches (30 and 10) with `fetch failed` / `read ECONNRESET` at `test-smoke.mjs:1578`, as on CI (two earlier batches of 10 had passed: whether the reset comes depends on the phase the loop resumes in), and the fix passed 50 of 50; on node 22.16.0, 3 of 3 failed before and 3 of 3 passed after. In a reduced model (an in-process server, one pooled request, the loop blocked 6 s by `spawnSync`, then a POST) the reset comes back every time when the test resumes in a check or poll phase and never when it resumes inside a timer callback, and 0 times in 15 when the block is an awaited `spawn`. A sweep of the whole `npm test` at base timed every `fetch` and `node:http` request against the event loop's last timer tick. It found two more requests issued at least 0.7 s after a synchronous block on an origin used before. One is the `serverFetch` of `tools/test-bundle-compare.mjs`, which already sends every request with `connection: close`. The other is T8 in `tools/test-studio-bundle.mjs`: its `GET /api/taxonomy` to its `serve()` child follows two `spawnSync` bundle builds (2.0 s under the suite's load), with the registration's socket pooled. With each build delayed 3 s (an 8 s idle) T8 passed 10 of 10 at base, so the race was not seen there. That socket has served a single request, and in the model such a socket's next request after the block was answered, while a socket that had served two failed (`other side closed`) in alternate runs. T8's two requests to the child now go out with `Connection: close`, as `serverFetch` does, so no socket outlives a build (10 of 10 pass with the fix). No test is added or removed: the suite total stays 1519.
+
 ## 0.6.0 — 2026-10-15
 
 **The store-and-seams release.** The store now holds the studio's state, not only its identities: the pack registry moved into the database; services, their environments and an org's MCP endpoints are records managed over HTTP; every change a principal makes through the server is an audit row that can be read; the home is the org's services table with a page per service; and Settings is the org's administration as a studio mode (STORE_PLAN slices 4 to 6). A downstream can vendor and rebadge Observogram without forking it: a manifest of the vendorable modules, the MCP transport hook, the artefact taxonomy classifier, reverse-proxy identity passthrough, one brand config and an embeddable static bundle, which now runs Compare and loads no font over the network. The rebadge batches built on those seams: a reviewer's verdicts, waivers and an exportable service audit report; canonical pack production, where a fresh crawl is a valid pack; a true-snapshot live pack behind a connection test; comparison identity modes; the MCP server's settings in the page. Spec 1.4 keeps a repository's operational alert rules and pairs them with the live ones. Windows has a CI leg, and a path there is compared by what it names, not by how it is spelled: a journey's org scope holds, and `packc store purge-org` decides the users file by what deleting the org's root takes. Also: a malformed JSON body is answered as JSON on every route, a server-run journey's notification reads only its org's hooks, the settings-policy deadline is per rule, and the id clocks time the pattern, not the machine.

server/fixtures/serve-child.mjs

@@ -98,14 +98,49 @@ export function parseBoot(stdout) {
   return { listening: false, message: null };
 }
 
+const bootEnv = (ws, { host = '127.0.0.1', env = {}, silent = true, port = 0 } = {}) =>
+  childEnv(ws, { ...env, BOOT_HOST: host, BOOT_SILENT: silent ? '1' : '0', BOOT_PORT: String(port) });
+
+function bootOutcome({ stdout, stderr, status }) {
+  const out = { ...parseBoot(stdout), stdout, stderr, status };
+  if (out.message === null) throw new Error(`the boot child printed neither LISTENING nor REFUSED (status ${status}): ${stderr}`);
+  return out;
+}
+
 // One boot that exits: { listening, port?, message?, code?, nothingMoved?, stdout, stderr }.
-export function boot(ws, { host = '127.0.0.1', env = {}, silent = true, port = 0 } = {}) {
-  const r = spawnSync(process.execPath, ['--input-type=module', '-e', BOOT_CODE], {
-    env: childEnv(ws, { ...env, BOOT_HOST: host, BOOT_SILENT: silent ? '1' : '0', BOOT_PORT: String(port) }), encoding: 'utf8', timeout: 60_000,
+export function boot(ws, opts) {
+  const r = spawnSync(process.execPath, ['--input-type=module', '-e', BOOT_CODE], { env: bootEnv(ws, opts), encoding: 'utf8', timeout: 60_000 });
+  return bootOutcome(r);
+}
+
+// boot() for a suite that keeps a server in this process (or a keep-alive
+// connection to one) across the boot: the same child and result, but this
+// process's event loop runs while the child boots. spawnSync stops the loop
+// for the whole boot, a second or more each on a loaded Windows runner. A
+// pooled socket idle past the server's keepAliveTimeout (Node's 5 s) then
+// takes the suite's next request before either side's keep-alive timer has
+// run. When the loop resumes in its check or poll phase, the server's timer
+// fires next and closes its end with the request unread, and the client reads
+// ECONNRESET ("fetch failed"; a POST is not retried). With the loop running,
+// fetch closes an idle socket at its own keep-alive (the server's timeout less
+// 2 s) and the next request opens a new one.
+export function bootAsync(ws, opts) {
+  return new Promise((resolve, reject) => {
+    const proc = spawn(process.execPath, ['--input-type=module', '-e', BOOT_CODE], { env: bootEnv(ws, opts), stdio: ['ignore', 'pipe', 'pipe'] });
+    let stdout = '';
+    let stderr = '';
+    proc.stdout.setEncoding('utf8');
+    proc.stderr.setEncoding('utf8');
+    proc.stdout.on('data', (c) => { stdout += c; });
+    proc.stderr.on('data', (c) => { stderr += c; });
+    const t = setTimeout(() => proc.kill('SIGTERM'), 60_000);
+    proc.on('error', (e) => { clearTimeout(t); reject(e); });
+    // 'close': the output read to its end.
+    proc.on('close', (status) => {
+      clearTimeout(t);
+      try { resolve(bootOutcome({ stdout, stderr, status })); } catch (e) { reject(e); }
+    });
   });
-  const out = { ...parseBoot(r.stdout), stdout: r.stdout, stderr: r.stderr, status: r.status };
-  if (out.message === null) throw new Error(`the boot child printed neither LISTENING nor REFUSED (status ${r.status}): ${r.stderr}`);
-  return out;
 }
 
 // A server that keeps running: { base, stop(), logs() }. logs() is

server/test-smoke.mjs

@@ -22,7 +22,7 @@ import { startFakeMcp, registerMcpEndpoint, endpointIdFor } from './fixtures/fak
 // mode's contract is asserted there), so the server imports below are
 // dynamic: a static one is hoisted above this line and would read the shell.
 // server/test-hermetic-suites.mjs guards the shape.
-const { STRIP, boot, dropInheritedOrgVars } = await import('./fixtures/serve-child.mjs');
+const { STRIP, bootAsync, dropInheritedOrgVars } = await import('./fixtures/serve-child.mjs');
 for (const k of STRIP) {
   delete process.env[`OBSERVOGRAM_${k}`];
   delete process.env[`TOMOGRAPH_${k}`];
@@ -1545,6 +1545,9 @@ try {
     // one planted in the checkout's examples/, which tools/test-validator.mjs,
     // tools/test-packs.mjs and tools/test-backend-validate.mjs enumerate
     // while this suite runs (an invalid pack there turns them red).
+    // bootAsync, not boot: this process serves `base`, and a boot through
+    // spawnSync stops its event loop with fetch's keep-alive socket to it
+    // pooled (server/fixtures/serve-child.mjs says what that costs).
     {
       const installLegacy = resolvePath(dirname(fileURLToPath(import.meta.url)), '..', 'examples', 'production-live.pack.yaml');
       const installBefore = existsSync(installLegacy) ? readFileSync(installLegacy, 'utf8') : null;
@@ -1557,16 +1560,16 @@ try {
       try {
         mkdirSync(bootWs, { recursive: true });
         const LINE = '[studio] the studio no longer reads examples/production-live.pack.yaml: each org\'s live pack is <org root>/live/production-live.pack.yaml, written by the MCP panel\'s refresh (npm run detect-drift and the dry run still read the old file; OUTPUT=<org root>/live/production-live.pack.yaml npm run fetch-live writes the new one)';
-        const none = boot(bootWs, { silent: false, env: bootEnv });
+        const none = await bootAsync(bootWs, { silent: false, env: bootEnv });
         assert(none.listening && !none.stdout.includes('no longer reads'), 'boot: no old live pack → no boot line', none.stdout);
         mkdirSync(dirname(legacyLive), { recursive: true });
         writeFileSync(legacyLive, PACK);
-        const first = boot(bootWs, { silent: false, env: bootEnv });
+        const first = await bootAsync(bootWs, { silent: false, env: bootEnv });
         assert(first.listening && first.stdout.includes(LINE), 'boot: the old live pack exists, the default org has none → the boot line', first.stdout);
         assert(installUntouched(), 'boot line: the check plants nothing in the checkout\'s examples/ (suites enumerating examples/*.pack.yaml run alongside)');
         mkdirSync(join(bootWs, 'live'), { recursive: true });
         writeFileSync(join(bootWs, 'live', 'production-live.pack.yaml'), PACK);
-        const second = boot(bootWs, { silent: false, env: bootEnv });
+        const second = await bootAsync(bootWs, { silent: false, env: bootEnv });
         assert(second.listening && !second.stdout.includes('no longer reads'), 'boot: after the default org\'s first refresh → no boot line', second.stdout);
       } finally {
         rmSync(scratch, { recursive: true, force: true });