runpod: give a booting pod a voice, and stop timing out on a cold image pull

The port a pod exposes appears only AFTER its image is pulled, so the 300s
budget had to cover the download — it was written assuming the container was
already there. The same 7.3 GB image took 133s on a machine with the layers
cached and failed repeatedly at 300s on cold ones, and each failure rented a
fresh machine and paid for the whole pull again, three times. 900s, overridable
per model; being wrong now costs six cents instead of three pods.

RunPod publishes no pod-log API: the REST OpenAPI spec lists 23 routes and none
serve logs, and GraphQL refuses introspection. Every attempt returning HTTP 400
was code guessing at URLs that never existed. So the pod reports on itself —
boot.sh is the entrypoint and logs timestamped phases from the first instant the
container exists (including the seed list, which is where "not available. Use
one of: " would have been caught in one line), and /boot serves that record plus
the app's own phases. A failed boot now asks the pod before falling back to a
console link a human has to open.

Nothing covers the pull window — no code of ours is running yet — so wait_ready
reports status and uptime every 60s instead of going silent for minutes.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0182DhR1eFNPQyGmDrpHbedY

codai/__init__.py

@@ -16,7 +16,7 @@
 
 # Canonical product version for CoderAI — single source of truth. Both the API
 # metadata and the admin web UI read from here.
-__version__ = "0.2.11"
+__version__ = "0.2.12"
 
 # Configure the CUDA caching allocator BEFORE torch is imported anywhere.
 # expandable_segments lets the allocator return freed pages to the driver even

codai/api/app.py

@@ -21,6 +21,7 @@ Contains the FastAPI app initialization, lifespan, and core endpoints.
 
 import logging
 import os
+import time
 from contextlib import asynccontextmanager
 from typing import List
 
@@ -67,10 +68,29 @@ def set_global_file_path_wrapper(path: str):
     set_global_file_path(path)
 
 
+#: Boot phases recorded on the way up, served by /boot. Bounded and trivial:
+#: this must never be a reason a process fails to start.
+_BOOT_PHASES: list = []
+_BOOT_T0 = time.time()
+
+
+def boot_phase(what: str) -> None:
+    """Record and print one boot step, with seconds since process start.
+
+    Printed as well as recorded: the phases have to be in the pod console for
+    the window before the port opens, and readable over HTTP after it.
+    """
+    line = f"[boot +{time.time() - _BOOT_T0:.1f}s] {what}"
+    if len(_BOOT_PHASES) < 200:
+        _BOOT_PHASES.append(line)
+    print(line, flush=True)
+
+
 @asynccontextmanager
 async def lifespan(app: FastAPI):
     """Lifespan context manager for startup/shutdown."""
     import asyncio as _asyncio
+    boot_phase("lifespan start")
 
     async def _archive_cleanup_loop():
         from codai.api.archive import archive_manager
@@ -275,6 +295,30 @@ from fastapi.responses import FileResponse, Response as _FaviconResponse
 _favicon_path = admin_static_dir / "favicon.ico"
 
 
+@app.get("/boot", include_in_schema=False)
+async def boot_progress():
+    """What this process did on the way up, with timings.
+
+    A pod is opaque: from container start to the first answered request there
+    were minutes of silence, and a boot that failed looked exactly like a boot
+    that was merely slow. The RunPod log API answered HTTP 400 when we went
+    looking, so the pod has to be able to say it itself — this is readable the
+    instant the port opens, which is well before the pod is useful.
+
+    Includes boot.sh's phases (container start, GPU, seed list) when present, so
+    one request covers the whole boot rather than just the Python half.
+    """
+    import os as _os
+    out = {"ok": True, "pid": _os.getpid(), "phases": list(_BOOT_PHASES)}
+    log = _os.environ.get("CODERAI_BOOT_LOG", "/tmp/coderai-boot.log")
+    try:
+        with open(log) as fh:
+            out["container"] = [ln.rstrip("\n") for ln in fh][-40:]
+    except OSError:
+        pass          # not a pod, or the wrapper was bypassed
+    return out
+
+
 @app.get("/healthz", include_in_schema=False)
 async def healthz():
     """Cheap liveness probe that touches no torch/model state.

codai/api/runpod_client.py

@@ -376,8 +376,15 @@ class RunpodClient:
     def get_pod_logs(self, pod_id: str, tail: int = 200) -> dict:
         """Best-effort container/vLLM logs for a pod via the REST API.
 
-        RunPod's log surface is the web console; this tries the REST logs route and
-        always returns a console URL to fall back to. Returns
+        There is no public pod-log API. RunPod's REST OpenAPI spec lists 23
+        routes (pods, billing, endpoints, volumes) and not one of them serves
+        logs; GraphQL refuses introspection, and its documented Pod type exposes
+        none either. The console is a human surface, not an API.
+
+        The routes below are kept because they cost one request on a path that
+        only runs when a boot already failed, and RunPod has moved this surface
+        before. The real answer is the pod's own /boot record — see
+        RunpodPodPool._dump_pod_logs, which asks the pod first. Returns
         {console_url, logs?: str, error?: str}."""
         import requests
         out = {"console_url": pod_console_url(pod_id)}
@@ -406,8 +413,9 @@ class RunpodClient:
                     out["logs"] = r.text
                 return out
             errors.append(f"HTTP {r.status_code}")
-        out["error"] = ("logs API unavailable (" + "; ".join(errors[:3])
-                        + ") — use the console link")
+        out["error"] = ("RunPod publishes no pod-log API (" + "; ".join(errors[:3])
+                        + "); a coderai pod serves its own boot record at /boot — "
+                        "for other images use the console link")
         return out
 
     def wait_ready(self, pod_id: str, port: int, ready_timeout: float = 900.0,
@@ -417,11 +425,27 @@ class RunpodClient:
         Only waits for the port to be exposed — the HTTP service inside (vLLM) is
         health-checked separately by the worker."""
         deadline = time.time() + ready_timeout
+        started = time.time()
+        next_report = started + 60.0
+        last = {}
         while time.time() < deadline:
             info = self.get_pod(pod_id)
+            last = info
             if info.get("status") in ("TERMINATED", "FAILED"):
                 raise RunpodError(f"Pod {pod_id} entered status {info.get('status')} before ready.")
             if info.get("ready"):
                 return pod_proxy_url(pod_id, port)
+            # A multi-GB image pull is minutes of silence otherwise, which reads
+            # exactly like a hung pod. Say what is actually being waited on.
+            if time.time() >= next_report:
+                next_report = time.time() + 60.0
+                print(f"[runpod] pod {pod_id}: still no port after "
+                      f"{time.time() - started:.0f}s "
+                      f"(status={info.get('status')} uptime={info.get('uptime_s')}s) "
+                      f"— image pull in progress", flush=True)
             time.sleep(poll_every)
-        raise RunpodError(f"Pod {pod_id} did not expose port {port} within {ready_timeout}s.")
+        raise RunpodError(
+            f"Pod {pod_id} did not expose port {port} within {ready_timeout}s "
+            f"(last status={last.get('status')} uptime={last.get('uptime_s')}s). "
+            f"A cold machine pulling a multi-GB image is the usual cause — raise "
+            f"`boot_timeout_s` on the model if this repeats.")

codai/api/runpod_worker.py

@@ -1333,15 +1333,44 @@ class RunpodPodPool:
                 raise
         raise last or RunpodError("RunPod: no candidate GPU could be deployed (capacity).")
 
-    # Port should appear once the pod's container is running; a much longer wait
-    # only bills for a pod that failed to start. The OpenAI server (image pull +
-    # model load) gets a longer, separate budget.
-    PORT_TIMEOUT_S = 300.0
+    # The port appears only AFTER the image is pulled, so this budget has to
+    # cover the download — the original 300s assumed the container was already
+    # there. Measured on the same 7.3 GB capability image: 133s on a machine
+    # that had the layers cached, and repeated failures at 300s on cold ones,
+    # which needs a sustained ~25 MB/s to beat. Each failure then rented a fresh
+    # machine and paid for the whole pull again, three times over.
+    #
+    # 15 minutes is bounded and cheap to be wrong about (a quarter-hour of a
+    # $0.25/hr card is 6 cents) where being too tight costs three pods and still
+    # fails. Override per model with `boot_timeout_s`.
+    PORT_TIMEOUT_S = 900.0
     HEALTH_TIMEOUT_S = 600.0
 
-    def _dump_pod_logs(self, client, pod_id, why):
-        """Fetch + log the pod's container/vLLM output so a failed boot is
-        self-diagnosing (the user's #1 cause: vLLM OOM / launch error)."""
+    def _dump_pod_logs(self, client, pod_id, why, url: str = ""):
+        """Say what the pod was doing, from whichever source can still answer.
+
+        RunPod publishes no pod-log API — the REST OpenAPI spec lists 23 routes
+        and none of them serve logs, which is why every attempt came back 400.
+        The console is a human surface. So a coderai pod keeps its own boot
+        record and serves it at /boot: if the port ever opened, that is the real
+        log, and it covers the container phases too (boot.sh writes them to the
+        same file). Tried first, because it is the only one that ever works.
+        """
+        if url:
+            try:
+                import requests
+                headers = ({"Authorization": f"Bearer {self.api_key}"}
+                           if self.api_key else {})
+                r = requests.get(url.rstrip("/") + "/boot", headers=headers, timeout=15)
+                if r.status_code == 200:
+                    data = r.json()
+                    lines = list(data.get("container") or []) + list(data.get("phases") or [])
+                    if lines:
+                        print(f"[runpod] pod {pod_id} boot record ({why}):\n  "
+                              + "\n  ".join(lines[-40:]), flush=True)
+                        return
+            except Exception:
+                pass          # port never opened, or it died before answering
         try:
             info = client.get_pod_logs(pod_id, tail=120)
         except Exception as exc:
@@ -1392,6 +1421,7 @@ class RunpodPodPool:
             # diagnosis: the image pull, the server start and the model load are
             # different problems with different fixes.
             t_created = time.time()
+            url = ""
             try:
                 url = client.wait_ready(pod_id, port, ready_timeout=boot_to)
                 t_port = time.time()
@@ -1418,7 +1448,7 @@ class RunpodPodPool:
                 last_exc = exc
                 print(f"[runpod] pod {pod_id} boot FAILED for {self.model_key!r}: {exc}",
                       flush=True)
-                self._dump_pod_logs(client, pod_id, "boot failed")
+                self._dump_pod_logs(client, pod_id, "boot failed", url)
                 try:
                     client.terminate_pod(pod_id)
                 except Exception:

packaging/runpod/Dockerfile.capability

@@ -56,4 +56,10 @@ EXPOSE 8000
 HEALTHCHECK --interval=30s --timeout=5s --start-period=120s \
     CMD curl -fsS http://127.0.0.1:8000/healthz || exit 1
 
-CMD ["python", "-m", "uvicorn", "codai.api.app:app", "--host", "0.0.0.0", "--port", "8000"]
+COPY packaging/runpod/boot.sh /opt/coderai/boot.sh
+RUN chmod +x /opt/coderai/boot.sh
+
+# Not uvicorn directly: boot.sh logs each phase with a timestamp from the first
+# instant the container exists, so a slow boot and a failed one stop looking the
+# same from outside.
+CMD ["/opt/coderai/boot.sh"]

packaging/runpod/boot.sh

+#!/bin/sh
+# Pod entrypoint: say what is happening, from the first instant there is a
+# container to say it in.
+#
+# A rented pod is opaque in two separate windows, and they need different fixes.
+# Before the image is pulled NOTHING of ours runs, so no amount of application
+# logging helps — that window is diagnosed from outside, by polling the pod's
+# status. But from container start to the first answered request there were
+# minutes of total silence, which looks exactly like a hung pod; a boot that
+# failed and a boot that was merely slow produced the same evidence, and the
+# RunPod log API answered HTTP 400 when we went looking.
+#
+# So: timestamped phase lines on stdout (the pod console always has these, even
+# when the log API does not), and the same phases written to a file the app
+# serves at /boot, so the moment the port opens we can ask the pod where it is
+# instead of guessing.
+set -u
+
+BOOT_LOG="${CODERAI_BOOT_LOG:-/tmp/coderai-boot.log}"
+: > "$BOOT_LOG"
+
+t0=$(date +%s)
+phase() {
+    now=$(date +%s)
+    line="[boot +$((now - t0))s] $*"
+    echo "$line"
+    echo "$line" >> "$BOOT_LOG"
+}
+
+phase "container started"
+phase "profile=${PROFILE:-unknown} image=${CODERAI_IMAGE_TAG:-unknown}"
+phase "python=$(python -V 2>&1)"
+
+# What the pod was actually told to serve. A pod that answers "not available"
+# for its own model is the single most common failure, and the seed list is the
+# first place to look — it is worth one line at boot rather than an exec into a
+# machine that has since been reaped.
+if [ -n "${CODERAI_SEED_MODELS:-}" ]; then
+    phase "seed models: $(echo "$CODERAI_SEED_MODELS" | head -c 400)"
+else
+    phase "seed models: NONE (this pod will only serve what its image ships)"
+fi
+
+if command -v nvidia-smi >/dev/null 2>&1; then
+    phase "gpu: $(nvidia-smi --query-gpu=name,memory.total --format=csv,noheader 2>/dev/null | head -1)"
+else
+    phase "gpu: nvidia-smi not present"
+fi
+
+phase "starting uvicorn on 0.0.0.0:8000"
+exec python -m uvicorn codai.api.app:app --host 0.0.0.0 --port 8000 \
+     --log-level "${CODERAI_LOG_LEVEL:-info}"

tests/test_burst_placement.py

@@ -542,3 +542,30 @@ def test_a_surviving_pods_token_is_remembered_across_a_restart(tmp_path, monkeyp
                                           api_key="cra-freshly-generated")
     assert (pod_id, url, key) == ("pod-survivor", "http://pod-a:8000", "cra-original")
     assert seen["key"] == "cra-original", "probed with the pod's token, not ours"
+
+
+def test_the_port_wait_covers_a_cold_image_pull(monkeypatch):
+    """The port appears only after the image is pulled, so the budget has to
+    cover the download. At 300s the same 7.3 GB image succeeded on a machine
+    with cached layers (133s) and failed on cold ones — three times, renting a
+    fresh machine and re-pulling for each."""
+    import codai.api.runpod_worker as rw
+
+    assert rw.RunpodPodPool.PORT_TIMEOUT_S >= 900.0
+
+
+def test_a_port_timeout_says_what_it_was_waiting_on(monkeypatch):
+    """'did not expose port 8000 within 300.0s' gives nothing to act on."""
+    import codai.api.runpod_client as rc
+
+    client = rc.RunpodClient.__new__(rc.RunpodClient)
+    monkeypatch.setattr(client, "get_pod",
+                        lambda pid: {"status": "RUNNING", "uptime_s": 42,
+                                     "ready": False}, raising=False)
+    try:
+        client.wait_ready("pod-x", 8000, ready_timeout=0.1, poll_every=0.01)
+    except rc.RunpodError as exc:
+        assert "last status='RUNNING'" in str(exc) or "status=RUNNING" in str(exc)
+        assert "boot_timeout_s" in str(exc)
+    else:
+        raise AssertionError("expected a RunpodError")