fix(sandbox): pre-pull images before run + capture timeout type in spawn-refusal log

`docker run postgres:16-alpine` pulled inline under a 20s deadline; on a cold
NAS the pull exceeded it, the run was killed, the pull cancelled, and every
retry re-pulled from scratch — a persistent spawn-refusal loop that
deadlocked board reviews on opted-in projects. `postgres:16-alpine` is
referenced nowhere in compose (the main service uses pgvector/pgvector:pg16),
so it was always a cold pull.

- sandbox: `_ensure_image` pulls with a 300s deadline when `image inspect`
  reports absent, before `docker run` (postgres + redis). Pull failure raises
  before any run, so it self-diagnoses instead of looping.
- orchestrator: log + raise `f"{type(e).__name__}: {e}"` — `str(TimeoutError())`
  is `""`, which made the failure mode invisible in the logs.
- tests: fake runner covers image/pull verbs; 3 new tests for skip/pull/fail.
This commit is contained in:
Renn F
2026-07-07 10:22:21 +02:00
parent 3849c1737e
commit 49bff15c78
3 changed files with 78 additions and 5 deletions
+5 -2
View File
@@ -2248,15 +2248,18 @@ class AgentOrchestrator:
try:
return await self._sandbox.provision(agent_id, services)
except Exception as e:
# str(TimeoutError()) == "" — include the type so a bare timeout
# (a cold image pull exceeding the run deadline) self-diagnoses.
err = f"{type(e).__name__}: {e}"
logger.error(
"sandbox provisioning failed; refusing spawn",
agent_id=agent_id,
task_id=task_id,
services=services,
error=str(e),
error=err,
)
raise AgentReadinessError(
f"sandbox provisioning failed for {agent_id} (task={task_id}): {e}"
f"sandbox provisioning failed for {agent_id} (task={task_id}): {err}"
) from e
async def _launch_spawn(
+20
View File
@@ -33,6 +33,11 @@ _DOCKER_RUN_TIMEOUT_SECONDS = 20.0
_DOCKER_EXEC_TIMEOUT_SECONDS = 10.0
_DOCKER_TEARDOWN_TIMEOUT_SECONDS = 15.0
_DOCKER_PS_TIMEOUT_SECONDS = 10.0
# `docker run` pulls inline when the image is absent, under the run deadline
# above; a NAS cold pull runs minutes, so the run is killed, the pull is
# cancelled, and every retry re-pulls from scratch — a persistent loop. Pulling
# explicitly with a generous deadline breaks it at the source.
_DOCKER_PULL_TIMEOUT_SECONDS = 300.0
# Readiness poll deadlines — pg's first-boot init (initdb + start) is slower
# than redis's near-instant start.
@@ -109,6 +114,19 @@ class SandboxProvisioner:
def _run(self) -> DockerRunner:
return self.runner or _default_docker_run
async def _ensure_image(self, image: str) -> None:
"""Pull `image` if absent so `docker run` never blocks on a cold pull."""
run = self._run()
rc, _, _ = await run(["image", "inspect", image], _DOCKER_EXEC_TIMEOUT_SECONDS)
if rc == 0:
return
rc, _, stderr = await run(["pull", image], _DOCKER_PULL_TIMEOUT_SECONDS)
if rc != 0:
raise SandboxProvisionError(
f"sandbox image pull failed for {image}: "
f"{stderr.decode(errors='replace')}"
)
async def provision(self, agent_id: str, services: list[str]) -> SandboxInfo:
"""Provision the requested services; on any failure, tear down + raise."""
unknown = sorted(set(services) - VALID_SANDBOX_SERVICES)
@@ -138,6 +156,7 @@ class SandboxProvisioner:
name = _pg_name(agent_id)
password = secrets.token_hex(16)
run = self._run()
await self._ensure_image("postgres:16-alpine")
rc, _, stderr = await run(
[
"run",
@@ -186,6 +205,7 @@ class SandboxProvisioner:
name = _redis_name(agent_id)
password = secrets.token_hex(16)
run = self._run()
await self._ensure_image("redis:8-alpine")
rc, _, stderr = await run(
[
"run",
+53 -3
View File
@@ -35,6 +35,10 @@ class _FakeRunner:
self.teardown_rc = teardown_rc
self.ps_output = ps_output
self.ps_live_output = ps_live_output
# Image state — defaults assume the image is already present (the happy
# path skips the pull). Tests exercising the pull path override these.
self.image_present: bool = True
self.pull_rc: int = 0
self._ps_call_count = 0
async def __call__(
@@ -48,12 +52,20 @@ class _FakeRunner:
return self.exec_rc, b"", b""
if verb in ("stop", "kill", "rm"):
return self.teardown_rc, b"", b""
if verb == "image":
# `image inspect <img>` — rc 0 means present (skip pull).
if args[1] != "inspect":
raise AssertionError(f"unexpected image subverb: {args[1]}")
return (0 if self.image_present else 1), b"", b""
if verb == "pull":
return self.pull_rc, b"", b"" if self.pull_rc == 0 else b"pull failed\n"
if verb == "ps":
self._ps_call_count += 1
# First ps call = the sandbox-labeled listing; second = live agents.
if self._ps_call_count == 1:
return 0, self.ps_output, b""
return 0, self.ps_live_output, b""
listing = (
self.ps_output if self._ps_call_count == 1 else self.ps_live_output
)
return 0, listing, b""
raise AssertionError(f"unexpected docker verb: {verb}")
@@ -222,3 +234,41 @@ async def test_janitor_reaps_after_grace_expiry() -> None:
rm_calls = [c for c in runner.calls if c[0] == "rm"]
assert any("roboco-sandbox-pg-old" in c for c in rm_calls)
assert provisioner._provisioned_at == {}
@pytest.mark.asyncio
async def test_provision_skips_pull_when_image_present() -> None:
runner = _FakeRunner(run_rc=0, exec_rc=0)
provisioner = SandboxProvisioner(network=_NETWORK, runner=runner)
await provisioner.provision("dev-7", ["postgres"])
assert any(c[0] == "image" and c[1] == "inspect" for c in runner.calls)
assert not any(c[0] == "pull" for c in runner.calls)
@pytest.mark.asyncio
async def test_provision_pulls_when_image_absent() -> None:
runner = _FakeRunner(run_rc=0, exec_rc=0)
runner.image_present = False
provisioner = SandboxProvisioner(network=_NETWORK, runner=runner)
await provisioner.provision("dev-8", ["postgres"])
inspect = [c for c in runner.calls if c[0] == "image" and c[1] == "inspect"]
pulls = [c for c in runner.calls if c[0] == "pull"]
assert inspect and pulls
assert pulls[0][-1] == "postgres:16-alpine"
@pytest.mark.asyncio
async def test_provision_pull_failure_raises() -> None:
runner = _FakeRunner(run_rc=0, exec_rc=0)
runner.image_present = False
runner.pull_rc = 1
provisioner = SandboxProvisioner(network=_NETWORK, runner=runner)
with pytest.raises(SandboxProvisionError, match="image pull failed"):
await provisioner.provision("dev-9", ["postgres"])
# `docker run` never reached — pull failed first.
assert not any(c[0] == "run" for c in runner.calls)