From f334fe9d20b13638933ff52561f7f0a4155dc5dd Mon Sep 17 00:00:00 2001 From: Timmy Date: Thu, 5 Nov 2026 10:59:23 +0000 Subject: [PATCH 1/2] fix(test): decide base-path rejection from the server's own startup line (#93) The old gate raced child exit against a fixed 800 ms timer. Under full-suite CPU contention the child was still importing modules, so it was killed and the timeout was asserted as acceptance: 2/2 full-suite runs on main failed with '"timmy-staging" was accepted' while the file alone passed 3/3 and the server rejected the value directly. Acceptance is now decided by the child printing 'Timmy is listening on http://'; a child that neither exits nor listens inside 20 s is reported as indeterminate. Rejection assertions (non-zero exit, TIMMY_BASE_PATH in stderr) still run. Mutation check: with the leading-slash validation disabled the repaired test fails in 398 ms with the acceptance message. --- tests/staging-health.test.js | 45 ++++++++++++++++++++++++++++-------- 1 file changed, 35 insertions(+), 10 deletions(-) diff --git a/tests/staging-health.test.js b/tests/staging-health.test.js index 6258f99..bec1a7f 100644 --- a/tests/staging-health.test.js +++ b/tests/staging-health.test.js @@ -125,6 +125,30 @@ test('agent cookie is constrained to the normalized base path', async t => { assert.match(response.headers.get('set-cookie'), /; Path=\/timmy-staging\//); }); +// The child's own startup line is the only trustworthy evidence that a base path was accepted. +// A fixed timer cannot tell "still importing modules" from "server is up": on a loaded host the +// old 800 ms race killed a correctly-rejecting child and reported it as accepted. +function startupOutcome(child, deadlineMs = 20_000) { + return new Promise(resolve => { + let stdout = ''; + let stderr = ''; + let settled = false; + const finish = outcome => { + if (settled) return; + settled = true; + clearTimeout(timer); + resolve({ ...outcome, stdout, stderr }); + }; + const timer = setTimeout(() => finish({ timedOut: true }), deadlineMs); + child.stdout.on('data', chunk => { + stdout += chunk; + if (/^Timmy is listening on http:\/\//m.test(stdout)) finish({ listening: true }); + }); + child.stderr.on('data', chunk => { stderr += chunk; }); + child.once('exit', code => finish({ code })); + }); +} + test('malformed and escaping base paths are rejected at startup', async () => { const invalid = [ 'timmy-staging', @@ -152,16 +176,17 @@ test('malformed and escaping base paths are rejected at startup', async () => { const child = spawn(process.execPath, ['server.mjs'], { cwd: root, env: { ...process.env, PORT: '0', TIMMY_BASE_PATH: value }, - stdio: ['ignore', 'ignore', 'pipe'], + stdio: ['ignore', 'pipe', 'pipe'], }); - let stderr = ''; - child.stderr.on('data', chunk => { stderr += chunk; }); - const exitCode = await Promise.race([ - new Promise(resolve => child.once('exit', resolve)), - new Promise(resolve => setTimeout(() => { child.kill('SIGTERM'); resolve('timeout'); }, 800)), - ]); - assert.notEqual(exitCode, 'timeout', `${JSON.stringify(value)} was accepted`); - assert.notEqual(exitCode, 0, `${JSON.stringify(value)} exited successfully`); - assert.match(stderr, /TIMMY_BASE_PATH/); + const outcome = await startupOutcome(child); + if (outcome.listening) { + const closed = new Promise(resolve => child.once('close', resolve)); + child.kill('SIGKILL'); + await closed; + } + assert.equal(outcome.listening, undefined, `${JSON.stringify(value)} was accepted: the server announced it was listening`); + assert.notEqual(outcome.timedOut, true, `${JSON.stringify(value)} neither exited nor announced listening within the startup deadline`); + assert.notEqual(outcome.code, 0, `${JSON.stringify(value)} exited successfully`); + assert.match(outcome.stderr, /TIMMY_BASE_PATH/); } }); From fd347d515992f7d64feea6fe82017937f38093d1 Mon Sep 17 00:00:00 2001 From: Timmy Date: Thu, 5 Nov 2026 12:07:01 +0000 Subject: [PATCH 2/2] fix(test): take staging ports from the kernel instead of a fixed 43100 block MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The harness derived every server port from a fixed `nextPort = 43100`, which lives inside this host's ephemeral range (32768-60999). The kernel can already have handed one of those numbers to an unrelated outbound socket — a Caddy -> Gitea connection held 43102 — so the spawn died with EADDRINUSE before a single assertion ran, and the suite reported a failure for a reason that is not the code under test. Reproduced 3/3 on main; 6/6 with the block moved out of range. Ports now come from a bind on :0, readiness is the child's own "Timmy is listening on http://" line rather than a poll deadline, and a port stolen in the probe-then-spawn gap is retried (4 attempts) instead of failing the release. Hold-out: with the leading-slash branch of resolveBasePath disabled, the gate still fails in ~336 ms with "the server announced it was listening" — the retry cannot make a broken validator pass. --- tests/staging-health.test.js | 85 ++++++++++++++++++++++++++---------- 1 file changed, 62 insertions(+), 23 deletions(-) diff --git a/tests/staging-health.test.js b/tests/staging-health.test.js index bec1a7f..7e324f9 100644 --- a/tests/staging-health.test.js +++ b/tests/staging-health.test.js @@ -2,38 +2,77 @@ import test from 'node:test'; import assert from 'node:assert/strict'; import { spawn } from 'node:child_process'; import { chmod, mkdtemp, rm } from 'node:fs/promises'; +import { createServer } from 'node:net'; import { tmpdir } from 'node:os'; import { join } from 'node:path'; import { fileURLToPath } from 'node:url'; const root = fileURLToPath(new URL('..', import.meta.url)); const hermesFixture = fileURLToPath(new URL('./fixtures/fake-hermes.mjs', import.meta.url)); -let nextPort = 43100; + +// A hard-coded base port is not ours to take: 43100 sits inside this host's ephemeral range +// (32768-60999), so the kernel can already have handed it to an unrelated outbound socket +// (a Caddy -> Gitea connection held 43102) and the spawn dies with EADDRINUSE before any +// assertion runs. Ask the kernel for a free port, then retry if one is stolen in the gap. +function freePort() { + return new Promise((resolve, reject) => { + const probe = createServer(); + probe.once('error', reject); + probe.listen(0, '127.0.0.1', () => { + const { port } = probe.address(); + probe.close(() => resolve(port)); + }); + }); +} + +function waitForListening(child, readStdout, timeoutMs = 20_000) { + return new Promise(resolve => { + let settled = false; + const finish = value => { + if (settled) return; + settled = true; + clearTimeout(timer); + resolve(value); + }; + const timer = setTimeout(() => finish({ state: 'timeout' }), timeoutMs); + child.stdout.on('data', () => { + if (/^Timmy is listening on http:\/\//m.test(readStdout())) finish({ state: 'listening' }); + }); + child.once('exit', code => finish({ state: 'exit', code })); + }); +} async function startServer(t, env = {}) { - const port = nextPort++; - const origin = `http://127.0.0.1:${port}`; - const child = spawn(process.execPath, ['server.mjs'], { - cwd: root, - env: { ...process.env, PORT: String(port), ...env, ...(env.TIMMY_PUBLIC_ORIGIN === '__ORIGIN__' ? { TIMMY_PUBLIC_ORIGIN: origin } : {}) }, - stdio: ['ignore', 'pipe', 'pipe'], - }); - let stderr = ''; - let stdout = ''; - child.stdout.on('data', chunk => { stdout += chunk; }); - child.stderr.on('data', chunk => { stderr += chunk; }); - t.after(() => child.kill('SIGTERM')); - const deadline = Date.now() + 10_000; - const basePath = (env.TIMMY_BASE_PATH || '').replace(/\/$/, ''); - while (Date.now() < deadline) { - if (child.exitCode !== null) throw new Error(`server exited ${child.exitCode}: ${stderr}`); - try { - const response = await fetch(`${origin}${basePath}/api/healthz`); - if (response.status) return { origin, child, getStdout: () => stdout }; - } catch {} - await new Promise(resolve => setTimeout(resolve, 40)); + for (let attempt = 1; attempt <= 4; attempt++) { + const port = await freePort(); + const origin = `http://127.0.0.1:${port}`; + const child = spawn(process.execPath, ['server.mjs'], { + cwd: root, + env: { ...process.env, PORT: String(port), ...env, ...(env.TIMMY_PUBLIC_ORIGIN === '__ORIGIN__' ? { TIMMY_PUBLIC_ORIGIN: origin } : {}) }, + stdio: ['ignore', 'pipe', 'pipe'], + }); + let stderr = ''; + let stdout = ''; + child.stdout.on('data', chunk => { stdout += chunk; }); + child.stderr.on('data', chunk => { stderr += chunk; }); + + const outcome = await waitForListening(child, () => stdout); + if (outcome.state === 'listening') { + t.after(() => child.kill('SIGTERM')); + return { origin, child, getStdout: () => stdout }; + } + + const closed = new Promise(resolve => child.once('close', resolve)); + if (child.exitCode === null) child.kill('SIGKILL'); + await closed; + + const stolen = /EADDRINUSE/.test(stderr); + if (!stolen || attempt === 4) { + throw new Error(outcome.state === 'timeout' + ? `server did not announce listening: ${stderr}` + : `server exited ${outcome.code}${stolen ? ' (port stolen again)' : ''}: ${stderr}`); + } } - throw new Error(`server did not become ready: ${stderr}`); } test('staging host can bind loopback instead of every network interface', async t => {