emrg: the daemon start window is the host's to set (#1276)

DEVELOPMENT.md

@@ -452,6 +452,33 @@ Two gaps get mistaken for a broken fix:
 
 Check `emrg -v` and when the daemon started before re-reading the source.
 
+### `emrgd failed to start within N s`
+
+The client spawns the daemon and waits for it to accept connections. When that
+wait runs out, the error carries what is known about the attempt: whether the
+child is still running, its exit code if it is not, the daemon log lines **this**
+attempt appended, and the contents of `~/.emrg/emrgd-start.err` (the child's own
+stderr, which is where a failure before logging starts can be read at all).
+
+The window defaults to **4.5 s** (15 polls, 0.3 s apart). A start that is merely
+slower than that on a cold machine is worth raising it for; set the variable on
+the command that starts the client, since the client is what waits:
+
+```bash
+EMRG_START_TIMEOUT=30 emrg
+```
+
+It takes seconds as a number. A value that is not a positive, finite number is
+ignored, with a warning in the client log — a typo in a tuning variable must
+never be the reason a start fails, so it falls back to the default rather than
+raising.
+
+Two facts make the window cheap to raise: a child that has **exited** is reported
+on the first poll with its exit code, so the window only ever bounds a child that
+is alive but not yet listening; and the failure report names the bound it really
+waited, not the one you asked for, because the window is quantised to the 0.3 s
+poll.
+
 ### Why is a write blocked at `workspace-write`?
 
 `workspace-write` is the default tier, and it allows a write only when the

emrg/client/daemon_manager.py

@@ -13,6 +13,7 @@
 import asyncio
 import json
 import logging
+import math
 import os
 import signal
 import subprocess
@@ -332,14 +333,81 @@ def _startup_failure_detail(
     )
 
 
+# ── the start window (issue #1276 item 5) ───────────────────────────────────
+# How long the client waits for a spawned emrgd to accept connections before it
+# reports a failure. This was the literal pair in `_await_daemon_ready`'s
+# signature — 15 x 0.3 s = 4.5 s — so a host whose cold start is slower than that
+# had no way to raise it: the failure reappeared identically on every retry, and
+# nothing distinguished "still starting" from "wedged".
+#
+# The default is unchanged, deliberately. Raising it is a behaviour change, and
+# the premise (a cold start needs more than 4.5 s) did not reproduce here: this
+# machine's daemon module imports in 0.14-0.16 s warm, which is the wrong regime
+# to argue a cold figure from. What the code *does* establish is that the window
+# is now cheap to extend — `_child_exit_code` reports a child that died on the
+# first poll, so the window only ever bounds a child that is **alive** — but
+# "cheap to extend" is not a measurement of how far to extend it.
+_START_WINDOW_ENV = "EMRG_START_TIMEOUT"
+_START_WINDOW_DEFAULT_SECONDS = 4.5
+_START_WINDOW_POLL_SECONDS = 0.3
+
+
+def _start_window_seconds() -> float:
+    """The wait window in seconds: ``EMRG_START_TIMEOUT`` if set, else the default.
+
+    The host-facing knob for a start that is slower than the default (issue #1276
+    item 5) — the same shape as ``EMRG_TASK_DIRTY_OVERRIDE``, and documented for
+    the same reason: an escape hatch whose effect is "you asked for X and got Y"
+    has to be findable without reading this file.
+
+    A malformed value falls back to the default instead of raising. The rule is
+    `_truncate_start_stderr`'s: **a diagnostic must never be able to make a start
+    fail**, and a typo in a tuning variable would be exactly that. It is logged
+    once, where a host who is reading the client log can see it.
+
+    Two shapes that parse as a float are rejected anyway, because "float-shaped"
+    is not the same test as "a duration": a non-positive number would produce a
+    loop that never waits and then reports a start it never waited for, and a
+    non-finite one (`inf`, `nan`) raises inside the arithmetic that turns seconds
+    into polls. Whitespace-only counts as unset — that is how a shell spells it.
+    """
+    raw = (os.environ.get(_START_WINDOW_ENV) or "").strip()
+    if not raw:
+        return _START_WINDOW_DEFAULT_SECONDS
+    try:
+        seconds = float(raw)
+    except ValueError:
+        logger.warning(
+            "%s=%r is not a number — using %.1fs",
+            _START_WINDOW_ENV, raw, _START_WINDOW_DEFAULT_SECONDS,
+        )
+        return _START_WINDOW_DEFAULT_SECONDS
+    if not math.isfinite(seconds) or seconds <= 0:
+        logger.warning(
+            "%s=%r is not a positive number of seconds — using %.1fs",
+            _START_WINDOW_ENV, raw, _START_WINDOW_DEFAULT_SECONDS,
+        )
+        return _START_WINDOW_DEFAULT_SECONDS
+    return seconds
+
+
+def _start_window_attempts() -> int:
+    """``_start_window_seconds()`` in polls of ``_START_WINDOW_POLL_SECONDS``.
+
+    Quantised to the poll interval, so the reported window is the bound the loop
+    really waits and not the number that was asked for.
+    """
+    return max(1, int(round(_start_window_seconds() / _START_WINDOW_POLL_SECONDS)))
+
+
 async def _await_daemon_ready(
     proc,
     log_path: Path,
     since: tuple[int, int | None],
     probe=None,
     *,
-    attempts: int = 15,
-    delay: float = 0.3,
+    attempts: int | None = None,
+    delay: float = _START_WINDOW_POLL_SECONDS,
     stderr_path: Path | None = None,
 ) -> None:
     """Wait for the daemon to accept connections; raise with what is known.
@@ -353,7 +421,14 @@ async def _await_daemon_ready(
     *only* there, so without it the failure report had nothing to quote.
     ``None`` is not a path: it says the capture did not happen, and the report
     says so instead of claiming the channel was silent.
+
+    ``attempts=None`` means "use the host's window" — ``EMRG_START_TIMEOUT`` if
+    set, else ``_START_WINDOW_DEFAULT_SECONDS`` (issue #1276 item 5). A caller
+    that passes a number still overrides it, which is what keeps the tests below
+    deterministic and independent of the machine's environment.
     """
+    if attempts is None:
+        attempts = _start_window_attempts()
     probe = probe or is_running
     for _ in range(attempts):
         await asyncio.sleep(delay)

tests/test_daemon_start_diagnostics.py

@@ -251,6 +251,75 @@ async def fake_sleep(seconds):
         asyncio.sleep = real_sleep
 
 
+# ── the start window is the host's to set (issue #1276 item 5) ───────────────
+
+
+def test_the_window_defaults_to_the_pair_the_signature_used_to_hold(monkeypatch):
+    """No variable set → the window is unchanged, so this is not a behaviour change.
+
+    15 x 0.3 s is what the loop waited before it was configurable, and a host who
+    never sets anything must keep waiting exactly that.
+    """
+    monkeypatch.delenv(dm._START_WINDOW_ENV, raising=False)
+    assert dm._start_window_seconds() == 4.5
+    assert dm._start_window_attempts() == 15
+
+
+def test_the_window_is_what_the_host_asked_for(tmp_path, monkeypatch):
+    """`EMRG_START_TIMEOUT` reaches the loop, and the failure reports it.
+
+    Driven end to end through `_await_daemon_ready` rather than asserted on the
+    resolver alone: a value that is read but never used is the defect this whole
+    issue is about, so the test has to see the wait change, not the variable.
+    """
+    log = tmp_path / "emrgd.log"
+    ticks: list[float] = []
+
+    async def fake_sleep(seconds):
+        ticks.append(seconds)
+
+    monkeypatch.setenv(dm._START_WINDOW_ENV, "1.2")
+    real_sleep = asyncio.sleep
+    asyncio.sleep = fake_sleep
+    try:
+        with pytest.raises(RuntimeError) as err:
+            asyncio.run(dm._await_daemon_ready(
+                StubProc(returncode=None), log, dm._log_mark(log),
+                probe=lambda: False))
+    finally:
+        asyncio.sleep = real_sleep
+
+    assert "failed to start within 1.2s" in str(err.value)
+    # 1.2 s at the 0.3 s poll — four polls, not the default fifteen.
+    assert len(ticks) == 4
+
+
+@pytest.mark.parametrize("raw", ["soon", "-5", "0", "nan", "inf"])
+def test_a_window_that_is_not_a_duration_falls_back_instead_of_failing(raw, monkeypatch):
+    """A typo in a tuning variable must not be able to fail a start.
+
+    The same rule `_truncate_start_stderr` follows: a diagnostic never gets to be
+    the reason a start dies. `-5`, `0` and `nan` are the interesting ones — each
+    parses as a float and would otherwise produce a loop that never waits, so
+    "float-shaped" is not the same test as "a duration".
+    """
+    monkeypatch.setenv(dm._START_WINDOW_ENV, raw)
+    assert dm._start_window_seconds() == 4.5
+    assert dm._start_window_attempts() == 15
+
+
+def test_a_whitespace_only_window_is_unset_not_a_parse_error(monkeypatch):
+    """`EMRG_START_TIMEOUT=""` is how a shell says unset; it must not warn."""
+    monkeypatch.setenv(dm._START_WINDOW_ENV, "   ")
+    assert dm._start_window_seconds() == 4.5
+
+
+def test_a_window_too_short_for_one_poll_still_polls_once(monkeypatch):
+    """A floor of one poll: a zero-iteration loop would report a start it never waited for."""
+    monkeypatch.setenv(dm._START_WINDOW_ENV, "0.01")
+    assert dm._start_window_attempts() == 1
+
+
 # ── a stop is not a crash ───────────────────────────────────────────────────