Retry an engine that dies on the way up during startup replay

FOLLOWUPS.md

@@ -6,6 +6,18 @@
 - **Next action:** replace the switch (or at minimum its PSU); while at it, identify what owns `192.168.0.100` — still down after recovery, either on a dead port or powered off. Evidence + topology: `ops/runbooks/network-topology.md` outage note.
 - **Proof of closure:** new/verified switch in place; 2 weeks with no synchronized link-flaps in spark3/4 `journalctl -k`; `.100` owner identified and documented in the runbook.
 
+## [ainode] ~~BUG: startup replay can lose an engine to a GPU-release race~~ — FIXED 2026-08-19 (branch `fable/0.5.5-replay-retry`)
+- Fix: `_ensure_serving()` — replay now waits for each engine to bind and, if it died on the way up, waits 30s for the GPU to release and relaunches ONCE (both the boot primary and stacked instances). Single retry on purpose: a model that fails twice has a real problem and a loop would hide it. 6 tests.
+- **Correction to the original diagnosis below:** the engine did NOT fail its launch check. It passed (container reached Running) and died minutes later during weight load, so `start_solo()` was right to return True. The gap was that nothing watched it afterwards. Original notes kept for the symptom detail.
+
+### original note (2026-08-19, during the 0.5.4 rollout)
+- **Filed:** 2026-08-19, observed live on spark-3 upgrading 0.5.4-dev → released 0.5.4.
+- **Symptom:** restarting the orchestrator sweeps orphan engine containers and immediately replays them from the manifest. The replayed engine came up with NO GPU — `Can't initialize NVML`, `No CUDA runtime is found`, `Triton ... 0 active driver(s) found (expected 1)`, `No module named 'vllm._C'` — and exited(1). Host `nvidia-smi` was healthy the whole time, and a container launched from inside the orchestrator saw the GPU fine. **Re-issuing the identical load a few minutes later worked with zero GPU-failure lines**, so the driver was still releasing from the just-killed engine when the nvidia hook ran for the new one.
+- **Impact:** a node comes back from a restart advertising nothing, with the model silently absent until someone re-loads it. Cost ~15 min of Qwen3.8 downtime during the rollout.
+- **Why it was diagnosable at all:** the 0.5.4 `--rm` removal left the corpse (`Exited (1)`) with readable logs, and the launch-confirmation change means the failure is no longer reported as success. Before 0.5.4 this would have been pure silence.
+- **Next action:** replay should not fire the instant the sweep completes. Either wait for the GPU to report free before relaunching, or retry a failed replay launch once after ~30s (the launch already returns False correctly now, so a retry hook is cheap). Prefer the retry — it also covers other transient launch failures.
+- **Proof of closure:** kill a running engine container and restart the orchestrator in a loop; the model returns every time without manual intervention.
+
 ## [ainode] BUG: eject doesn't survive reboot + phantom rows (2 of 5 FIXED 2026-08-15)
 - **FIXED on `fable/0.5.4-native-engines`:** (a) engine containers no longer launch with `--rm`, so a crashed engine leaves a readable corpse (validated live: the entrypoint-collision crash left its "unrecognized arguments" error intact instead of self-erasing); (b) `start_solo()` now confirms the container reached Running and logs the engine's last output on failure, instead of returning True as soon as the docker CLI forked.
 - **ALSO FIXED 2026-08-15:** (c) eject now rewrites the instance manifest (it was memory-only, so replay resurrected ejected models on reboot) and clears `config.model` when the primary is ejected; (d) the boot path no longer launches the legacy host-venv engine when vLLM isn't importable — it uses the configured container backend instead of starting a guaranteed "No module named 'vllm'" failure behind an "Engine starting" banner.

ainode/models/api_routes.py

@@ -375,6 +375,40 @@ def _probe() -> bool:
     return False
 
 
+async def _ensure_serving(app, port: int, relaunch, label: str, timeout: float = 300.0) -> bool:
+    """Wait for an engine to bind, and if it died on the way up, relaunch ONCE.
+
+    An engine can pass the launch check (its container reached Running) and then
+    die minutes later during weight load. Observed 2026-08-19 on spark-3: the
+    startup sweep killed the previous engine and the replacement launched while
+    the driver was still releasing the GPU, so the nvidia hook handed it no
+    device — `Can't initialize NVML`, `0 active driver(s) found` — and it exited
+    during load. Nothing retried, so the node came back advertising nothing and
+    the model stayed missing until a human re-loaded it.
+
+    ``relaunch`` is a zero-arg callable that re-issues the launch. The retry is
+    deliberately single: a model that fails twice has a real problem, and a retry
+    loop would just hide it.
+    """
+    if await _wait_port_ready(port, timeout=timeout):
+        return True
+    logger.warning("%s never bound on :%s — relaunching once", label, port)
+    # Give the GPU time to finish releasing before asking for it again.
+    await asyncio.sleep(30)
+    loop = asyncio.get_event_loop()
+    try:
+        ok = await loop.run_in_executor(None, relaunch)
+    except Exception:
+        logger.exception("%s relaunch raised", label)
+        return False
+    if not ok:
+        logger.error("%s relaunch failed to start", label)
+        return False
+    served = await _wait_port_ready(port, timeout=timeout)
+    logger.info("%s relaunch %s", label, "is serving" if served else "still not serving")
+    return served
+
+
 async def replay_instances_on_startup(app) -> None:
     """Always-on: after boot, re-load the persisted solo instance set so a node
     restart brings every previously-loaded model back with no manual step. The
@@ -409,7 +443,14 @@ async def replay_instances_on_startup(app) -> None:
         logger.exception("orphan container sweep failed")
 
     # Wait for the boot primary to actually serve before stacking on top of it.
-    await _wait_port_ready(config.api_port, timeout=300)
+    # Retry once if it died on the way up — otherwise the node comes back with
+    # its main model silently missing.
+    boot_engine = app.get("engine")
+    if boot_engine is not None and getattr(config, "model", None):
+        await _ensure_serving(app, config.api_port, boot_engine.start,
+                              f"boot primary {config.model}")
+    else:
+        await _wait_port_ready(config.api_port, timeout=300)
 
     manager = app.get("instances")
     have = {i.record.model for i in manager.instances()} if manager is not None else set()
@@ -427,9 +468,16 @@ async def replay_instances_on_startup(app) -> None:
                 lambda mm=m, g=e.get("gpu_memory_utilization"), ov={k: e[k] for k in _OVERRIDE_KEYS if k in e}: append_solo_instance(app, mm, g, overrides=ov, persist=False),
             )
             have.add(m)
-            # Serialize: let this model bind before launching the next one.
+            # Serialize: let this model bind before launching the next one, and
+            # retry once if it died on the way up (same GPU-release race).
             if isinstance(res, dict) and res.get("ok") and res.get("api_port"):
-                await _wait_port_ready(res["api_port"], timeout=300)
+                inst = manager.by_model(m) if manager is not None else None
+                relaunch = (inst.backend.start if inst is not None
+                            else (lambda mm=m, g=e.get("gpu_memory_utilization"),
+                                  ov={k: e[k] for k in _OVERRIDE_KEYS if k in e}:
+                                  bool(append_solo_instance(app, mm, g, overrides=ov,
+                                                            persist=False).get("ok"))))
+                await _ensure_serving(app, res["api_port"], relaunch, f"replay {m}")
         except Exception:
             logger.exception("replay load failed for %s", m)
 

tests/test_replay_retry.py

@@ -0,0 +1,87 @@
+"""Startup replay retries an engine that dies on the way up.
+
+An engine can pass the launch check (container reached Running) and then die
+minutes later during weight load. Observed 2026-08-19 on spark-3: the startup
+sweep killed the previous engine, the replacement launched while the driver was
+still releasing the GPU, got no device, and exited during load. Nothing retried,
+so the node came back advertising nothing.
+"""
+
+from unittest import mock
+
+import pytest
+
+from ainode.models import api_routes
+
+
+@pytest.fixture(autouse=True)
+def _no_real_sleep(monkeypatch):
+    # The retry deliberately waits 30s for the GPU to release; don't in tests.
+    async def _fast(_):
+        return None
+    monkeypatch.setattr(api_routes.asyncio, "sleep", _fast)
+
+
+def _ready_sequence(*results):
+    """_wait_port_ready stub returning the given results in order."""
+    seq = list(results)
+
+    async def _stub(port, timeout=300.0):
+        return seq.pop(0) if seq else False
+    return _stub
+
+
+@pytest.mark.asyncio
+async def test_no_retry_when_the_engine_binds_first_time(monkeypatch):
+    monkeypatch.setattr(api_routes, "_wait_port_ready", _ready_sequence(True))
+    relaunch = mock.Mock(return_value=True)
+    ok = await api_routes._ensure_serving({}, 8000, relaunch, "x")
+    assert ok is True
+    relaunch.assert_not_called(), "a healthy engine must never be relaunched"
+
+
+@pytest.mark.asyncio
+async def test_relaunches_once_when_the_engine_never_binds(monkeypatch):
+    monkeypatch.setattr(api_routes, "_wait_port_ready", _ready_sequence(False, True))
+    relaunch = mock.Mock(return_value=True)
+    ok = await api_routes._ensure_serving({}, 8000, relaunch, "x")
+    assert ok is True
+    assert relaunch.call_count == 1
+
+
+@pytest.mark.asyncio
+async def test_gives_up_after_one_retry(monkeypatch):
+    # A model that fails twice has a real problem; looping would hide it.
+    monkeypatch.setattr(api_routes, "_wait_port_ready", _ready_sequence(False, False))
+    relaunch = mock.Mock(return_value=True)
+    ok = await api_routes._ensure_serving({}, 8000, relaunch, "x")
+    assert ok is False
+    assert relaunch.call_count == 1
+
+
+@pytest.mark.asyncio
+async def test_relaunch_that_fails_to_start_is_reported(monkeypatch):
+    monkeypatch.setattr(api_routes, "_wait_port_ready", _ready_sequence(False))
+    relaunch = mock.Mock(return_value=False)
+    assert await api_routes._ensure_serving({}, 8000, relaunch, "x") is False
+
+
+@pytest.mark.asyncio
+async def test_a_raising_relaunch_does_not_crash_replay(monkeypatch):
+    monkeypatch.setattr(api_routes, "_wait_port_ready", _ready_sequence(False))
+    relaunch = mock.Mock(side_effect=RuntimeError("docker gone"))
+    assert await api_routes._ensure_serving({}, 8000, relaunch, "x") is False
+
+
+@pytest.mark.asyncio
+async def test_retry_waits_before_reasking_for_the_gpu(monkeypatch):
+    # The delay is the point: the previous engine's device release is what the
+    # first attempt lost to.
+    slept = []
+
+    async def _record(sec):
+        slept.append(sec)
+    monkeypatch.setattr(api_routes.asyncio, "sleep", _record)
+    monkeypatch.setattr(api_routes, "_wait_port_ready", _ready_sequence(False, True))
+    await api_routes._ensure_serving({}, 8000, mock.Mock(return_value=True), "x")
+    assert slept and max(slept) >= 30