Skip to content
Open
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
37 changes: 36 additions & 1 deletion composer/spec/source/autosetup.py
Original file line number Diff line number Diff line change
Expand Up @@ -85,6 +85,36 @@ async def _drain(
sink(buf)


#: How long to give the AutoSetup child to exit before we stop waiting on it. The wait below sits
#: in a ``finally`` that a cancellation also travels through, so it has to be bounded: an
#: unbounded wait there parks the whole run behind one subprocess, with no timeout above it that
#: can help and nothing left running to say why.
_REAP_TIMEOUT_S = 30.0


async def _reap(proc: asyncio.subprocess.Process) -> int | None:
"""Wait for ``proc`` to exit, escalating to a kill, and stop waiting rather than block forever.

Returns the exit status, or ``None`` if the child could not be reaped at all — a child that
will not die tells us nothing about whether AutoSetup succeeded, so the caller treats that as
a failure.
"""
for escalate in (False, True):
if escalate and proc.returncode is None:
_logger.warning(
"AutoSetup child still alive after %.0fs, killing it", _REAP_TIMEOUT_S
)
proc.kill()
try:
async with asyncio.timeout(_REAP_TIMEOUT_S):
# Shielded: the timeout must cancel our wait, not the child's exit plumbing.
return await asyncio.shield(proc.wait())
except TimeoutError:
continue
_logger.error("AutoSetup child outlived a kill, giving up on it and continuing")
return proc.returncode


async def run_autosetup(
project_root: Path,
relative_path: str,
Expand Down Expand Up @@ -176,7 +206,12 @@ def log_complete(self, returncode: int):
raise
finally:
_logger.debug("AutoSetup process complete, waiting for exit")
returncode = await proc.wait()
returncode = await _reap(proc)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm confused, do we know why this hung? how did proc.kill(); proc.wait() not work??

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am also confused how it happened, but either the kill in the exception didn't kill the process on a timely manner, or gather returned without the process actually ending. The question is whether we think that this fix is hiding a more serious issue.

Claude's commentary:
▎ We don't. The run sat in that wait until the job's hard time cap killed
▎ the process, so there was nothing left to inspect.

▎ On the kill: it only runs in the except BaseException branch. If the gather returns
▎ normally with the child still alive, nothing kills it, and the old await proc.wait()
▎ in the finally just blocks. And where we do kill, the wait after it was that same
▎ unbounded wait, so a child that doesn't die on SIGKILL parks the run the same way. The
▎ bound is what ends it either way.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Claude answers: We do now, from the container logs. One of the two runs ends with the CancelledError coming out of _drain, then the debug line in the finally. So asyncio.run's teardown cancelled the drain, proc.kill() did run, and the run was last seen going into the unbounded proc.wait().

The kill only exists in the except branch, and the wait after it is that same unbounded wait, so nothing there was a bound on anything. Whether the wait itself is what held for 22h I can't tell from that log, because nothing logged when it returned. The other run froze at the same point in teardown with its autosetup already exited 0, so this isn't the whole incident.

I've pushed the rest: the task holding the subprocess is now cancelled with the extraction it runs beside instead of being left for teardown, the reap logs how it ended, and there's a test for the path that actually happened.

if returncode is None:
return SetupFailure(
error="AutoSetup did not exit",
stderr="\n".join(stderr_lines),
)
cb.log_complete(returncode)
if returncode != 0:
return SetupFailure(
Expand Down
38 changes: 38 additions & 0 deletions tests/test_autosetup_reap.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,38 @@
"""Tests for the bounded reap of the AutoSetup subprocess (``composer/spec/source/autosetup.py``).

The wait for the child sits in a ``finally``, which is also the path a cancelled run takes on its
way out. Whatever the child is doing, that wait has to end.
"""

import asyncio
import sys

import pytest

from composer.spec.source import autosetup

pytestmark = pytest.mark.asyncio


async def _spawn(code: str) -> asyncio.subprocess.Process:
return await asyncio.create_subprocess_exec(
sys.executable, "-c", code,
stdout=asyncio.subprocess.DEVNULL,
stderr=asyncio.subprocess.DEVNULL,
stdin=asyncio.subprocess.DEVNULL,
)


async def test_a_child_that_exits_reports_its_status():
proc = await _spawn("raise SystemExit(3)")
assert await autosetup._reap(proc) == 3


async def test_a_child_that_will_not_exit_is_killed(monkeypatch):
monkeypatch.setattr(autosetup, "_REAP_TIMEOUT_S", 0.2)
# Ignores SIGTERM, so only the kill ends it.
proc = await _spawn(
"import signal, time; signal.signal(signal.SIGTERM, signal.SIG_IGN); time.sleep(300)"
)
returncode = await asyncio.wait_for(autosetup._reap(proc), timeout=10)
assert returncode is not None and returncode < 0
Loading