Skip to content

Fix: DockerDeployment.start() hangs on startup timeout instead of reporting it - #301

Open
lavneethora wants to merge 2 commits into
SWE-agent:mainfrom
lavneethora:fix/docker-deployment-parallel-start
Open

lavneethora wants to merge 2 commits into
SWE-agent:mainfrom
lavneethora:fix/docker-deployment-parallel-start

Conversation

@lavneethora

Copy link
Copy Markdown

Fixes #261.

What happens

DockerDeployment launches the container with Popen(cmds, stdout=PIPE, stderr=PIPE)
and never drains either pipe. When start() hits its startup_timeout, the handler does:

self.logger.error(self._container_process.stdout.read().decode())

.read() on a pipe blocks until the writer exits. The container is still running at that
point, so this never returns. start() does not raise the timeout, it hangs on it, and
because the read is synchronous it hangs the event loop, so every deployment started
alongside it in asyncio.gather freezes too. The await self.stop() on the next line
never runs, so the container is leaked as well.

That is why the reporter only sees this in parallel: one deployment reaching its timeout
is enough to wedge the whole program.

Two further problems on the same path:

  • A pipe holds 64kiB. Once it fills, docker run blocks writing and everything after
    that is lost, so the output the handler exists to report is truncated. (The container
    itself keeps running; the daemon buffers its output.)
  • If the read does return, await self.stop() raises ClientOSError against the
    unreachable runtime, and that replaces the TimeoutError. Callers get a connection
    error instead of the timeout they configured.

Separately, start() and stop() are async def but do their work with blocking calls
(docker inspect, docker pull, docker build, find_free_port, docker kill, and a
wait(timeout=5) loop). None of it is offloaded, so concurrent deployments stall each
other's event loop while _wait_until_alive's deadline runs on a wall clock and each
is_alive probe gets only _runtime_timeout = 0.15s.

What changed

src/swerex/deployment/docker.py only:

  • Capture the container process to tempfile.TemporaryFile() rather than pipes. Reads
    never block and nothing is discarded. Closed in stop().
  • One _read_container_output() helper replaces the four blocking .read() calls, and
    the dead assert that sat after the reads it was meant to guard is gone.
  • Guard the cleanup in the timeout handler so it cannot mask the TimeoutError.
  • Run the blocking container runtime calls through asyncio.to_thread. The kill and
    image removal blocks moved into _kill_container() / _remove_container_image() so
    stop() stays readable.

No public API or config change.

Verification

Before, test_docker_deployment_startup_timeout hangs indefinitely (killed at 180s,
leaving the container running). After, it raises TimeoutError in ~6s and cleans up.

Output capture, same container emitting 1MB: 1,000,272 bytes captured, where a pipe
caps at 65,536.

Full suite (pytest -k "not cloud") goes from 76 passed to 78 passed. The 5 failures in
test_execution.py, test_get_deployment.py and test_server.py are identical before
and after and unrelated to this change.

Notes

  • Two deployments needing the same missing image will now run concurrent docker pulls
    where they previously serialised. Docker deduplicates layer pulls, so this is safe.
  • Cleanup via AbstractDeployment.__del__ while a loop is already shutting down is
    marginally more best-effort than before, since stop() now needs one more loop
    iteration to resume from its thread. That path was already best-effort.
  • swerex/utils/free_port.py also blocks the loop with time.sleep and releases its
    socket before docker binds the port. Left alone: it is shared with other deployments
    and the test fixtures, and I have no evidence it contributes to this issue. Happy to
    follow up separately.

DockerDeployment captured the container process on pipes that nothing ever
drained. Reading a pipe blocks until the writer exits, so the startup-timeout
handler blocked forever on a still-running container, taking the event loop
and every concurrent deployment down with it and leaking the container because
cleanup never ran. A full 64kiB pipe also silently discarded the rest of the
output, which is exactly the output the handler wanted to report.

Capture to temporary files instead, so reads never block and nothing is lost.
Guard the cleanup in the handler so a failing stop() cannot replace the
TimeoutError the caller needs to see.

Also run the blocking container runtime calls in start() and stop() via
asyncio.to_thread. They stalled the event loop for every deployment started
alongside them, while the startup deadline is wall clock.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Bug: DockerDeployment.start() times out when run in parallel with asyncio.gather

1 participant