Release v0.51.314 — Release KD (test infra: reliable test-server boot + diagnostics) (#3782)

Test-harness only. conftest test-server fixture now captures server output, fails fast on early subprocess death, retries once, raises timeout to 45s, and surfaces the log tail on failure — fixing the recurring ConnectionRefused boot-cascade flake. Full suite 8187 passed, Codex SAFE, Opus SHIP-IT. No app code changed.

CHANGELOG.md

@@ -3,6 +3,11 @@
 
 ## [Unreleased]
 
+## [v0.51.314] — 2026-06-07 — Release KD (test infra — reliable test-server boot + diagnostics)
+
+### Changed
+- **The pytest test-server fixture now boots reliably and reports WHY it failed.** Previously the session-scoped server subprocess sent its stdout/stderr to `/dev/null` and was waited on for a fixed 20s with no check for early death — so a slow import-heavy boot (or a transient port-bind race) timed out opaquely and every HTTP-dependent test then cascaded into hundreds of `ConnectionRefused` failures with no clue as to the cause. The fixture now captures server output to a temp log, polls the subprocess for early exit (failing fast instead of waiting out the timeout), raises the boot timeout to 45s, retries once with a fresh port-kill on failure, and surfaces the tail of the captured server log in the `pytest.fail` message. This is test-harness-only; it does not affect the shipped application. (internal)
+
 ## [v0.51.313] — 2026-06-07 — Release KC (instant profile switcher — skip the per-profile alias scan)
 
 ### Fixed

tests/conftest.py

@@ -494,16 +494,66 @@ def _post(base, path, body=None):
             return {}
 
 
-def _wait_for_server(base, timeout=20):
+def _wait_for_server(base, timeout=45, proc=None, log_path=None):
+    """Poll ``base/health`` until the server reports ready, or fail fast.
+
+    Returns ``(True, "")`` once ``/health`` returns ``status == "ok"``.
+
+    Returns ``(False, reason)`` when the server does not come up. ``reason`` is a
+    human-readable diagnostic that, crucially, includes WHY when we can tell:
+
+    * If ``proc`` is supplied and the subprocess has already exited, we stop
+      polling immediately (no point waiting out the full timeout for a process
+      that is already dead) and surface its exit code.
+    * If ``log_path`` is supplied, the tail of the captured server stdout/stderr
+      is included so an import error / bind failure / traceback is visible
+      instead of a bare "did not start" message.
+
+    The previous implementation polled for the whole timeout regardless of
+    whether the process had died, and the server's output was discarded to
+    ``DEVNULL`` — so a boot failure produced a generic timeout with no clue as
+    to the cause, and every HTTP-dependent test then cascaded with
+    ConnectionRefused. Capturing output + early-exit detection turns that opaque
+    cascade into a single actionable failure.
+    """
     deadline = time.time() + timeout
+    last_err = "no successful /health response"
     while time.time() < deadline:
+        # Fail fast if the server subprocess has already died — don't wait out
+        # the full timeout polling a port nothing is listening on.
+        if proc is not None and proc.poll() is not None:
+            return False, _server_boot_diagnostic(
+                f"server process exited early with code {proc.returncode}",
+                log_path,
+            )
         try:
             with urllib.request.urlopen(base + "/health", timeout=2) as r:
                 if json.loads(r.read()).get("status") == "ok":
-                    return True
-        except Exception:
+                    return True, ""
+                last_err = "/health responded but status != 'ok'"
+        except Exception as e:  # noqa: BLE001 — diagnostic capture, re-raised as text
+            last_err = f"{type(e).__name__}: {e}"
             time.sleep(0.3)
-    return False
+    return False, _server_boot_diagnostic(
+        f"timed out after {timeout}s waiting for /health (last: {last_err})",
+        log_path,
+    )
+
+
+def _server_boot_diagnostic(headline, log_path):
+    """Build a boot-failure message, appending the captured server log tail."""
+    parts = [headline]
+    if log_path is not None:
+        try:
+            text = pathlib.Path(log_path).read_text(encoding="utf-8", errors="replace")
+            tail = "".join(text.splitlines(keepends=True)[-40:]).strip()
+            if tail:
+                parts.append("---- server output (last 40 lines) ----\n" + tail)
+            else:
+                parts.append("(server produced no output)")
+        except Exception as e:  # noqa: BLE001
+            parts.append(f"(could not read server log {log_path}: {e})")
+    return "\n".join(parts)
 
 
 # ── Session-scoped test server ────────────────────────────────────────────────
@@ -630,23 +680,60 @@ def test_server():
     if HERMES_AGENT:
         env["HERMES_WEBUI_AGENT_DIR"] = str(HERMES_AGENT)
 
-    proc = subprocess.Popen(
-        [VENV_PYTHON, str(SERVER_SCRIPT)],
-        cwd=WORKDIR,
-        env=env,
-        stdout=subprocess.DEVNULL,
-        stderr=subprocess.DEVNULL,
-        **({"creationflags": subprocess.CREATE_NO_WINDOW} if sys.platform == "win32" else {}),
-    )
+    # Capture server stdout/stderr to a temp log instead of DEVNULL so a boot
+    # failure (import error, port-bind race, traceback) is diagnosable. Without
+    # this, _wait_for_server could only report a bare "did not start" timeout
+    # and every HTTP-dependent test then cascaded with ConnectionRefused —
+    # hundreds of opaque failures from a single root cause.
+    import tempfile as _tempfile
+    _server_log = pathlib.Path(_tempfile.gettempdir()) / f"hermes-webui-test-server-{TEST_PORT}.log"
 
-    if not _wait_for_server(TEST_BASE, timeout=20):
-        proc.kill()
+    # Boot the server, retrying once if it dies early or fails to bind. Boot
+    # failures here are most often transient (a port not yet released by a prior
+    # session, a momentary import hiccup under load), so one clean retry with a
+    # fresh port-kill turns an intermittent cascade into a reliable start.
+    proc = None
+    boot_attempts = 2
+    last_reason = ""
+    for _attempt in range(1, boot_attempts + 1):
+        with open(_server_log, "w", encoding="utf-8") as _logf:
+            proc = subprocess.Popen(
+                [VENV_PYTHON, str(SERVER_SCRIPT)],
+                cwd=WORKDIR,
+                env=env,
+                stdout=_logf,
+                stderr=subprocess.STDOUT,
+                **({"creationflags": subprocess.CREATE_NO_WINDOW} if sys.platform == "win32" else {}),
+            )
+        # 45s (up from 20s): server.py imports the full hermes-agent, which is
+        # import-heavy and can exceed 20s on a loaded runner — the old timeout
+        # turned a slow-but-fine boot into a whole-suite failure.
+        ok, reason = _wait_for_server(TEST_BASE, timeout=45, proc=proc, log_path=_server_log)
+        if ok:
+            break
+        last_reason = reason
+        # Tear down the failed attempt and free the port before retrying.
+        try:
+            proc.kill()
+            proc.wait(timeout=5)
+        except Exception:
+            pass
+        if _attempt < boot_attempts:
+            try:
+                import subprocess as _sp2
+                _sp2.run(['fuser', '-k', f'{TEST_PORT}/tcp'], capture_output=True, timeout=5)
+            except Exception:
+                pass
+            time.sleep(1.0)
+    else:
         pytest.fail(
-            f"Test server on port {TEST_PORT} did not start within 20s.\n"
+            f"Test server on port {TEST_PORT} did not start after {boot_attempts} attempts.\n"
+            f"  reason    : {last_reason}\n"
             f"  server.py : {SERVER_SCRIPT}\n"
             f"  python    : {VENV_PYTHON}\n"
             f"  agent dir : {HERMES_AGENT}\n"
             f"  workdir   : {WORKDIR}\n"
+            f"  log       : {_server_log}\n"
         )
 
     yield proc

tests/test_conftest_server_boot.py

@@ -0,0 +1,82 @@
+"""Tests for the test-server boot reliability helpers in conftest.py.
+
+These guard the diagnostics that turn an opaque "test server did not start"
+timeout (which previously cascaded into hundreds of ConnectionRefused failures
+with no clue as to the cause) into a single actionable failure:
+
+  * ``_wait_for_server`` returns ``(ok, reason)`` and fails FAST when the server
+    subprocess has already exited, instead of polling out the whole timeout.
+  * ``_server_boot_diagnostic`` appends the tail of the captured server log so
+    an import error / bind failure / traceback is visible in the failure.
+"""
+from __future__ import annotations
+
+import tests.conftest as conftest
+
+
+class _FakeProc:
+    """Minimal stand-in for subprocess.Popen with a controllable poll()."""
+
+    def __init__(self, returncode=None):
+        self._returncode = returncode
+
+    def poll(self):
+        return self._returncode
+
+    @property
+    def returncode(self):
+        return self._returncode
+
+
+def test_wait_for_server_fails_fast_on_early_exit(tmp_path):
+    """A dead subprocess must short-circuit the wait, not poll the full timeout."""
+    log = tmp_path / "server.log"
+    log.write_text("Traceback (most recent call last):\nImportError: boom\n", encoding="utf-8")
+    dead = _FakeProc(returncode=1)
+
+    # Point at a port nothing is listening on; with proc dead we must return
+    # almost immediately rather than waiting out the (large) timeout.
+    import time
+    start = time.time()
+    ok, reason = conftest._wait_for_server(
+        "http://127.0.0.1:9", timeout=30, proc=dead, log_path=str(log)
+    )
+    elapsed = time.time() - start
+
+    assert ok is False
+    assert elapsed < 5, f"should fail fast on early exit, took {elapsed:.1f}s"
+    assert "exited early with code 1" in reason
+    # The captured server output must be surfaced in the diagnostic.
+    assert "ImportError: boom" in reason
+
+
+def test_wait_for_server_times_out_with_log_tail(tmp_path):
+    """When the process stays alive but never serves, surface the log tail."""
+    log = tmp_path / "server.log"
+    log.write_text("starting up...\nstill binding...\n", encoding="utf-8")
+    alive = _FakeProc(returncode=None)
+
+    ok, reason = conftest._wait_for_server(
+        "http://127.0.0.1:9", timeout=1, proc=alive, log_path=str(log)
+    )
+
+    assert ok is False
+    assert "timed out" in reason
+    assert "still binding" in reason
+
+
+def test_server_boot_diagnostic_handles_missing_log():
+    """A missing/None log path must not raise — diagnostics are best-effort."""
+    msg = conftest._server_boot_diagnostic("headline only", None)
+    assert msg == "headline only"
+
+    msg2 = conftest._server_boot_diagnostic("hl", "/nonexistent/path/12345.log")
+    assert "hl" in msg2  # does not raise; appends a soft note
+
+
+def test_server_boot_diagnostic_reports_empty_output(tmp_path):
+    """An empty server log should say so rather than appear truncated."""
+    log = tmp_path / "empty.log"
+    log.write_text("", encoding="utf-8")
+    msg = conftest._server_boot_diagnostic("hl", str(log))
+    assert "no output" in msg