From 61a4f4183c166a6829b5badec9e100fc245bb5a7 Mon Sep 17 00:00:00 2001 From: Diego Rodrigues de Sa e Souza Date: Sat, 11 Jul 2026 10:03:16 -0300 Subject: [PATCH] fix(cli): waitForServer must not report ready on bare TCP accept (#6800) waitForServer() polled /api/monitoring/health but fell back to declaring the server ready once the port had merely accepted TCP connections for >= 3s, even if no HTTP response was ever received. On CPU-bound warmup (e.g. small VPS running Next.js standalone), the OS-level listener accepts TCP almost immediately while the request pipeline is still compiling, so the fallback fired within ~3-7s and the CLI printed 'OmniRoute is running!' 30-60s before any route actually answered. Classify each health poll into ready / fast-reject / hanging / not-listening: only a fast HTTP rejection (fetch error that is not a timeout, e.g. ECONNRESET before the route mounts) grants the original #2460 Windows-cold-start grace window. A request that times out with zero response (the reported #6800 symptom) resets the grace window instead of accumulating toward it. Regression tests: tests/unit/waitForServer-tcp-fallback-6800.test.mjs (new RED-then-GREEN probe from the bug analysis) and tests/unit/cli-waitForServer.test.mjs (existing suite realigned to the corrected contract, plus a new case for the hanging-socket scenario). --- bin/cli/utils/pid.mjs | 52 +++++++++---- .../fixes/6800-6800-listen-banner-early.md | 1 + tests/unit/cli-waitForServer.test.mjs | 45 +++++++++-- .../waitForServer-tcp-fallback-6800.test.mjs | 78 +++++++++++++++++++ 4 files changed, 151 insertions(+), 25 deletions(-) create mode 100644 changelog.d/fixes/6800-6800-listen-banner-early.md create mode 100644 tests/unit/waitForServer-tcp-fallback-6800.test.mjs diff --git a/bin/cli/utils/pid.mjs b/bin/cli/utils/pid.mjs index 6c94437e37..1149c67251 100644 --- a/bin/cli/utils/pid.mjs +++ b/bin/cli/utils/pid.mjs @@ -65,34 +65,52 @@ export function sleep(ms) { // cold start due to filesystem watchers, antivirus, etc.) get a working // "server ready" signal instead of a phantom timeout while the server is // still booting. TCP fallback marks the server as ready when the port -// has been listening for >= 3s consecutively but /api/monitoring/health -// has not yet been mounted — common during dev cold start. +// has been listening for >= 3s consecutively AND the health route is +// actively rejecting/resetting connections fast (route not mounted yet, +// but the HTTP server is clearly alive and responsive) — never for a +// socket that merely accepts TCP and then hangs without ever completing +// a single request (#6800: that's a still-booting/CPU-bound process, not +// a "route not mounted" gap, and must NOT be reported as ready). export async function waitForServer(port, timeout = 60000) { const start = Date.now(); let tcpListeningSince = null; while (Date.now() - start < timeout) { - try { - const res = await fetch(`http://localhost:${port}/api/monitoring/health`, { - signal: AbortSignal.timeout(2000), - }); - if (res.ok) return true; - // Server responded but health endpoint is not ready yet — keep - // polling, but the fact that we got a response means TCP is open. + const outcome = await pollHealthOnce(port); + if (outcome === "ready") return true; + if (outcome === "fast-reject") { if (tcpListeningSince === null) tcpListeningSince = Date.now(); - } catch { - const listening = await isPortListening(port).catch(() => false); - if (listening) { - if (tcpListeningSince === null) tcpListeningSince = Date.now(); - if (Date.now() - tcpListeningSince >= 3000) return true; - } else { - tcpListeningSince = null; - } + if (Date.now() - tcpListeningSince >= 3000) return true; + } else { + // "hanging" (request timed out with no response at all) or + // "not-listening" — neither counts toward the grace window. + tcpListeningSince = null; } await sleep(500); } return false; } +// Polls /api/monitoring/health once and classifies the outcome: +// - "ready": got a 2xx HTTP response. +// - "fast-reject": got a non-2xx HTTP response, or the connection was +// actively refused/reset (not a timeout) — the HTTP server is alive and +// answering quickly, just not routing this endpoint yet (#2460). +// - "hanging": the request timed out waiting for any response — the +// process accepted the TCP connection but never answered (#6800). +// - "not-listening": nothing is accepting connections on the port at all. +async function pollHealthOnce(port) { + try { + const res = await fetch(`http://localhost:${port}/api/monitoring/health`, { + signal: AbortSignal.timeout(2000), + }); + return res.ok ? "ready" : "fast-reject"; + } catch (err) { + if (err?.name === "TimeoutError") return "hanging"; + const listening = await isPortListening(port).catch(() => false); + return listening ? "fast-reject" : "not-listening"; + } +} + async function isPortListening(port) { const net = await import("node:net"); return new Promise((resolve) => { diff --git a/changelog.d/fixes/6800-6800-listen-banner-early.md b/changelog.d/fixes/6800-6800-listen-banner-early.md new file mode 100644 index 0000000000..c53bae5d7f --- /dev/null +++ b/changelog.d/fixes/6800-6800-listen-banner-early.md @@ -0,0 +1 @@ +- fix(cli): waitForServer() no longer reports ready from a raw TCP accept alone — requires a fast HTTP rejection or a real health response, so the "OmniRoute is running!" banner no longer fires 30-60s before the server can actually answer requests (#6800) diff --git a/tests/unit/cli-waitForServer.test.mjs b/tests/unit/cli-waitForServer.test.mjs index 716127057d..b58a0ce0e9 100644 --- a/tests/unit/cli-waitForServer.test.mjs +++ b/tests/unit/cli-waitForServer.test.mjs @@ -4,10 +4,13 @@ import net from "node:net"; import { waitForServer } from "../../bin/cli/utils/pid.mjs"; -// #2460: waitForServer must (a) respect a 60s default timeout, (b) return -// true when the port is listening for >= 3s even if /api/monitoring/health -// is not yet mounted (common on Windows during slow Next.js cold start), -// and (c) return false cleanly when nothing is listening. +// #2460 / #6800: waitForServer must (a) respect a 60s default timeout, +// (b) return true when the port is listening for >= 3s and health requests +// are being fast-rejected/reset (route not yet mounted, common on Windows +// during slow Next.js cold start), (c) return false cleanly when nothing is +// listening, and (d) return false when the port merely accepts TCP and then +// hangs without ever answering a request (#6800 — a still-booting/CPU-bound +// process must NOT be reported as ready just because the socket is open). async function freePort() { return new Promise((resolve) => { @@ -29,12 +32,13 @@ test("waitForServer returns false on a closed port within the given timeout (#24 assert.ok(elapsed >= 1200 && elapsed < 4000, `elapsed ${elapsed}ms outside expected range`); }); -test("waitForServer returns true via TCP fallback when port listens but health endpoint is absent (#2460)", async () => { +test("waitForServer returns true via TCP fallback when health requests are fast-rejected (route not yet mounted) (#2460)", async () => { const port = await freePort(); const server = net.createServer((socket) => { - // Accept the connection but never respond — simulates a Node process - // that has bound the port but not yet mounted HTTP routes. - socket.on("data", () => {}); + // Actively reset the connection quickly — simulates a Node process + // that has bound the port and is responsive, but has not yet mounted + // the health route (the original #2460 Windows cold-start scenario). + socket.destroy(); }); await new Promise((resolve, reject) => { server.once("error", reject); @@ -48,3 +52,28 @@ test("waitForServer returns true via TCP fallback when port listens but health e await new Promise((resolve) => server.close(() => resolve())); } }); + +test("waitForServer returns false when the port accepts TCP but never answers a request (#6800)", async () => { + const port = await freePort(); + const server = net.createServer((socket) => { + // Accept the connection but never respond and never close it — a + // still-booting/CPU-bound process that has bound the port but cannot + // yet process any request. This must NOT be reported as ready. + socket.on("data", () => {}); + }); + await new Promise((resolve, reject) => { + server.once("error", reject); + server.listen(port, "127.0.0.1", () => resolve()); + }); + + try { + const result = await waitForServer(port, 8000); + assert.equal( + result, + false, + "expected waitForServer to NOT report ready for a TCP-open-but-never-responding socket" + ); + } finally { + await new Promise((resolve) => server.close(() => resolve())); + } +}); diff --git a/tests/unit/waitForServer-tcp-fallback-6800.test.mjs b/tests/unit/waitForServer-tcp-fallback-6800.test.mjs new file mode 100644 index 0000000000..71f3938b76 --- /dev/null +++ b/tests/unit/waitForServer-tcp-fallback-6800.test.mjs @@ -0,0 +1,78 @@ +// Regression test for issue #6800 item 1: waitForServer() must NOT declare the +// server "ready" based on a raw-TCP-accept fallback when the HTTP layer never +// answers a single request. This reproduces exactly the reported symptom: port +// enters LISTEN / accepts TCP, but GET /api/monitoring/health (and any other +// route) hangs indefinitely — yet the CLI still printed "OmniRoute is running!". + +import { test } from "node:test"; +import assert from "node:assert/strict"; +import net from "node:net"; +import { waitForServer } from "../../bin/cli/utils/pid.mjs"; + +test("#6800: waitForServer must NOT report ready when TCP accepts but HTTP never responds", async () => { + const server = net.createServer((socket) => { + // Accept the TCP connection (this is what makes the port show LISTEN and + // "accepts connections"), but never write an HTTP response and never + // close the socket — exactly the observed 30-60s hang before HTTP + // responds. + }); + + await new Promise((resolve, reject) => { + server.once("error", reject); + server.listen(0, "127.0.0.1", resolve); + }); + const port = server.address().port; + + try { + const start = Date.now(); + const ready = await waitForServer(port, 20000); + const elapsedMs = Date.now() - start; + + assert.equal( + ready, + false, + `waitForServer() incorrectly reported ready=true after ${elapsedMs}ms even though ` + + `/api/monitoring/health never returned a response (only a TCP-accepting, ` + + `non-responding socket) — this is the readiness-lies-about-HTTP bug from #6800.` + ); + } finally { + server.close(); + } +}); + +test("#2460: waitForServer still recovers when health route briefly errors before mounting", async () => { + // Simulate the original Windows dev-cold-start scenario this fallback was + // built for: the port is open, but the very first few requests get an + // ECONNRESET / abrupt close (health route not mounted yet) before the + // server starts answering normally. + let attempts = 0; + const server = net.createServer((socket) => { + attempts += 1; + if (attempts <= 3) { + // Abruptly reset the connection — simulates a not-yet-mounted route. + socket.destroy(); + return; + } + socket.on("data", () => { + socket.end("HTTP/1.1 200 OK\r\nContent-Length: 2\r\n\r\nok"); + }); + }); + + await new Promise((resolve, reject) => { + server.once("error", reject); + server.listen(0, "127.0.0.1", resolve); + }); + const port = server.address().port; + + try { + const ready = await waitForServer(port, 20000); + assert.equal( + ready, + true, + "waitForServer() should still recover once the health route starts answering " + + "(regression guard for the original #2460 Windows cold-start fix)" + ); + } finally { + server.close(); + } +});