Skip to content

Commit 45a4d4d

Browse files
AbirAbbasclaude
andauthored
fix(sdk/python): bound the harness subprocess exit wait — silent reasoner wedge (#778)
A reasoner calling a CLI harness provider could wedge silently forever: stuck 'running' with no child process, no logs, and a healthy event loop. Root-caused from a production swe-planner run that sat 26 minutes in that state: run_cli's finally block ended with a bare `await proc.wait()`, which parks indefinitely in two real situations — 1. Windows proactor loop loses the RegisterWaitWithQueue completion that resolves proc.wait() even though the child already exited (CPython gh-81562 / gh-111604). Both pipes are at EOF, no process remains, and nothing ever wakes the coroutine. 2. An orphaned grandchild outlives a killed parent while holding the inherited output pipes: asyncio resolves proc.wait() only after every pipe disconnects, and on Windows proc.kill() cannot reach grandchildren (pre-fix, test_run_cli_idle_watchdog_aborts_stalled_child hangs >100s on a real Windows machine because of exactly this). Fix: - _wait_process_exit(): bound the exit wait with a grace period; on expiry, kill whatever remains and recover the real exit status from proc.returncode or by polling the underlying Popen object, which needs no event delivery. - _kill_group(): use `taskkill /F /T` on Windows as the killpg analog so kills reach the whole tree (also guards os.killpg with hasattr — it does not exist on Windows). - run_cli now also kills the child when the wait loop exits abnormally (cancellation included); previously a cancelled run_cli left the CLI subprocess running and awaited its natural exit. Tests: unit regressions for the lost-notification recovery and kill-on-cancellation, plus a real-subprocess regression where a grandchild holds the pipes — run_cli must conclude in bounded time on every platform. Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
1 parent b0fc271 commit 45a4d4d

3 files changed

Lines changed: 174 additions & 4 deletions

File tree

sdk/python/agentfield/harness/_cli.py

Lines changed: 78 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@
77
import os
88
import re
99
import signal
10+
import subprocess
1011
from typing import Any, Dict, List, Optional, Tuple
1112

1213
from agentfield.openrouter_attribution import apply_subprocess_env
@@ -61,6 +62,53 @@ async def _drain(
6162
last_activity[0] = asyncio.get_event_loop().time()
6263

6364

65+
# Grace period for the child's exit notification after its pipes hit EOF (or
66+
# after it was killed). Post-EOF a child is dead or exiting, so this only
67+
# delays the pathological cases handled in _wait_process_exit.
68+
_PROC_EXIT_GRACE_SECONDS = 10.0
69+
70+
71+
async def _wait_process_exit(
72+
proc: asyncio.subprocess.Process, kill_group
73+
) -> Optional[int]:
74+
"""Await the child's exit without trusting the exit notification.
75+
76+
A bare ``await proc.wait()`` can park forever on Windows' proactor loop:
77+
the RegisterWaitWithQueue completion that resolves it is occasionally lost
78+
even though the child already exited (CPython gh-81562 / gh-111604 —
79+
observed in production as a swe-planner reasoner silently wedged for 26
80+
minutes with no child process and a perfectly healthy event loop; the
81+
coroutine sat here, after both pipes had hit EOF, waiting on an exit
82+
notification that never came). It also parks when an orphaned grandchild
83+
outlives a killed parent while holding the output pipes, since asyncio
84+
resolves ``wait()`` only once every pipe disconnects. Bound the wait; on
85+
timeout, kill whatever may remain and recover the real exit status by
86+
polling the underlying Popen object, which needs no event delivery.
87+
Returns the exit code, or None if it cannot be determined.
88+
"""
89+
try:
90+
return await asyncio.wait_for(proc.wait(), timeout=_PROC_EXIT_GRACE_SECONDS)
91+
except (asyncio.TimeoutError, TimeoutError):
92+
pass
93+
# The notification may have landed while we grace-waited (in which case
94+
# the transport finalizer may already have dropped its Popen reference —
95+
# but ``proc.returncode`` stays available), so check it at every step.
96+
if proc.returncode is not None:
97+
return proc.returncode
98+
kill_group()
99+
popen = getattr(getattr(proc, "_transport", None), "_proc", None)
100+
for _ in range(100): # <= 10s; TerminateProcess/SIGKILL act promptly
101+
if proc.returncode is not None:
102+
return proc.returncode
103+
if popen is None:
104+
break
105+
returncode = popen.poll()
106+
if returncode is not None:
107+
return returncode
108+
await asyncio.sleep(0.1)
109+
return proc.returncode
110+
111+
64112
async def run_cli(
65113
cmd: List[str],
66114
*,
@@ -106,19 +154,37 @@ async def run_cli(
106154

107155
def _kill_group() -> None:
108156
pid = proc.pid
109-
if isinstance(pid, int) and pid > 0:
157+
# killpg only exists on POSIX; on Windows use taskkill /T instead.
158+
if hasattr(os, "killpg") and isinstance(pid, int) and pid > 0:
110159
try:
111160
os.killpg(pid, signal.SIGKILL)
112161
return
113162
except (ProcessLookupError, PermissionError, OSError):
114163
pass
164+
if os.name == "nt" and isinstance(pid, int) and pid > 0:
165+
# proc.kill() terminates only the direct child. CLI shims
166+
# (.cmd -> cmd.exe -> node/bun) do their real work in
167+
# grandchildren that inherit the output pipes; if they outlive
168+
# the parent they hold the pipes open and asyncio's proc.wait()
169+
# — which resolves only after every pipe disconnects — blocks
170+
# indefinitely. taskkill /T is the closest analog to killpg.
171+
try:
172+
subprocess.run(
173+
["taskkill", "/F", "/T", "/PID", str(pid)],
174+
capture_output=True,
175+
timeout=5,
176+
check=False,
177+
)
178+
except (OSError, subprocess.SubprocessError):
179+
pass
115180
try:
116181
proc.kill()
117182
except ProcessLookupError:
118183
pass
119184

120185
timed_out = False
121186
idle_timed_out = False
187+
completed = False
122188
deadline = asyncio.get_event_loop().time() + timeout if timeout else None
123189

124190
try:
@@ -135,6 +201,7 @@ def _kill_group() -> None:
135201

136202
try:
137203
await asyncio.wait_for(asyncio.shield(drain), timeout=wait_for)
204+
completed = True
138205
break # both pipes hit EOF: child is done
139206
except asyncio.TimeoutError:
140207
now = asyncio.get_event_loop().time()
@@ -146,14 +213,18 @@ def _kill_group() -> None:
146213
break
147214
# Spurious wakeup (progress reset the idle window): loop again.
148215
finally:
149-
if timed_out or idle_timed_out:
216+
if not completed:
217+
# Timeout, cancellation, or an internal error: stop the child so
218+
# nothing keeps running and the exit wait below can conclude.
219+
# (Previously only the timeout paths killed; a cancelled run_cli
220+
# left the child running and awaited its natural exit.)
150221
_kill_group()
151222
drain.cancel()
152223
try:
153224
await drain
154225
except BaseException:
155226
pass
156-
await proc.wait()
227+
fallback_returncode = await _wait_process_exit(proc, _kill_group)
157228

158229
if idle_timed_out:
159230
raise TimeoutError(
@@ -162,10 +233,13 @@ def _kill_group() -> None:
162233
if timed_out:
163234
raise TimeoutError(f"CLI command timed out after {timeout}s: {' '.join(cmd)}")
164235

236+
returncode = proc.returncode
237+
if returncode is None:
238+
returncode = fallback_returncode
165239
return (
166240
b"".join(stdout_chunks).decode("utf-8", errors="replace"),
167241
b"".join(stderr_chunks).decode("utf-8", errors="replace"),
168-
proc.returncode if proc.returncode is not None else -1,
242+
returncode if returncode is not None else -1,
169243
)
170244

171245

sdk/python/tests/test_harness_cli.py

Lines changed: 65 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -58,6 +58,71 @@ async def test_run_cli_success():
5858
assert kwargs["stderr"] is asyncio.subprocess.PIPE
5959

6060

61+
@pytest.mark.asyncio
62+
async def test_run_cli_survives_lost_exit_notification(monkeypatch):
63+
"""Regression: CPython gh-81562 — Windows' proactor loop can lose the
64+
RegisterWaitWithQueue completion, so ``proc.wait()`` never resolves even
65+
though the child exited (both pipes at EOF). run_cli used to park there
66+
forever, silently wedging the calling reasoner. It must instead recover
67+
the exit status from the underlying Popen object and return."""
68+
from agentfield.harness import _cli
69+
70+
monkeypatch.setattr(_cli, "_PROC_EXIT_GRACE_SECONDS", 0.05)
71+
72+
async def _never_resolves():
73+
await asyncio.Event().wait()
74+
75+
process = MagicMock()
76+
process.pid = 2147483647 # nonexistent pid: group kill falls back to kill()
77+
process.stdout = _stream_reader([b"partial output"])
78+
process.stderr = _stream_reader([])
79+
process.returncode = None # transport never learns the exit status
80+
process.wait = _never_resolves
81+
process.kill = MagicMock()
82+
# Underlying Popen: first poll still racing, then the real exit code.
83+
process._transport._proc.poll = MagicMock(side_effect=[None, 7])
84+
85+
with patch("asyncio.create_subprocess_exec", AsyncMock(return_value=process)):
86+
stdout, stderr, returncode = await asyncio.wait_for(
87+
run_cli(["opencode", "run"], timeout=5),
88+
timeout=5, # the whole call must conclude promptly, not hang
89+
)
90+
91+
assert stdout == "partial output"
92+
assert returncode == 7
93+
process.kill.assert_called()
94+
95+
96+
@pytest.mark.asyncio
97+
async def test_run_cli_kills_child_on_cancellation():
98+
"""A cancelled run_cli must kill the child instead of leaving it running
99+
and awaiting its natural exit (which for a coding-agent CLI can be many
100+
minutes away, or forever)."""
101+
102+
async def never_ready(_n):
103+
await asyncio.sleep(30)
104+
return b""
105+
106+
process = MagicMock()
107+
process.pid = 2147483647
108+
process.returncode = None
109+
process.stdout = MagicMock(read=AsyncMock(side_effect=never_ready))
110+
process.stderr = MagicMock(read=AsyncMock(side_effect=never_ready))
111+
process.kill = MagicMock()
112+
process.wait = AsyncMock(return_value=1)
113+
114+
with patch("asyncio.create_subprocess_exec", AsyncMock(return_value=process)):
115+
task = asyncio.ensure_future(
116+
run_cli(["opencode", "run"], timeout=60, idle_seconds=0)
117+
)
118+
await asyncio.sleep(0.05) # let it spawn and park on the drain
119+
task.cancel()
120+
with pytest.raises(asyncio.CancelledError):
121+
await task
122+
123+
process.kill.assert_called()
124+
125+
61126
@pytest.mark.asyncio
62127
async def test_run_cli_timeout():
63128
async def never_ready(_n):

sdk/python/tests/test_run_cli_env.py

Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@
1414
from __future__ import annotations
1515

1616
import asyncio
17+
import sys
1718
import time
1819

1920
import pytest
@@ -175,3 +176,33 @@ async def test_run_cli_idle_seconds_from_env(monkeypatch):
175176
)
176177
elapsed = time.monotonic() - start
177178
assert elapsed < 10.0, f"env idle watchdog did not fire promptly ({elapsed:.1f}s)"
179+
180+
181+
@pytest.mark.asyncio
182+
async def test_run_cli_bounded_when_grandchild_holds_pipes():
183+
"""Functional regression for the silent-wedge class (real subprocesses).
184+
185+
A grandchild that inherits the output pipes and outlives its parent used
186+
to park run_cli forever at the exit wait: asyncio resolves ``proc.wait()``
187+
only once every pipe disconnects, and on Windows the group kill cannot
188+
reach an already-orphaned grandchild. Observed in production as a
189+
swe-planner reasoner stuck ``running`` for 26 minutes with no harness
190+
process and a healthy event loop. run_cli must now conclude in bounded
191+
time on every platform.
192+
"""
193+
parent = (
194+
"import subprocess, sys; "
195+
"subprocess.Popen([sys.executable, '-c', 'import time; time.sleep(120)']); "
196+
"print('parent-exiting', flush=True)"
197+
)
198+
start = time.monotonic()
199+
with pytest.raises(TimeoutError):
200+
await run_cli(
201+
[sys.executable, "-c", parent],
202+
timeout=60.0,
203+
idle_seconds=2.0,
204+
)
205+
elapsed = time.monotonic() - start
206+
# POSIX: killpg reaps the whole group at the idle deadline (~2s).
207+
# Windows: worst case idle (2s) + exit-notification grace (10s) + poll.
208+
assert elapsed < 45.0, f"exit wait not bounded ({elapsed:.1f}s)"

0 commit comments

Comments
 (0)