From 054a34cc7800527abea1546bd3591fc5fe21156f Mon Sep 17 00:00:00 2001 From: Amplifier <240397093+microsoft-amplifier@users.noreply.github.com> Date: Mon, 3 Aug 2026 07:12:15 -0700 Subject: [PATCH] fix(tests): drain pty master so macOS integration tests cannot hang; bound all waits MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The `pytest -m integration` job added in #251 and wired up in #253 hangs forever on the macOS runner. Root-caused on real macOS hardware to a test-harness bug (not a product bug): an un-drained pty master wedges the child on macOS. Both symptoms are harness bugs. The product is correct on macOS. Root cause: macOS wedges an exiting pty child whose output queue is never drained — not slowly, unreapably. A wedged child lands in ps state `?Es` (Exiting, session leader, controlling terminal already revoked). The fix introduces a shared pty harness (`tests/pty_harness.py`) that: - Drains the pty master via a dedicated thread on a dup() so the caller's master_fd keeps blocking-write semantics - Replaces parent-side sleeps with `wait_for_marker()` readiness handshake so sends land inside the child's live window - Bounds all `waitpid` calls — no blocking waits that can hang forever - Removes the un-drained-pty + SIGKILL condition that was a landmine in test_stdout_offload_freeze_integration.py:198 CI hardening: `timeout-minutes: 10` on both jobs. Typical runtime is 20-30s. A hung job now fails loudly in 10 minutes rather than burning runner hours. Verification: 5 consecutive integration runs on macOS, all green, no stray `?Es` children left behind. Generated with [Amplifier](https://github.com/microsoft/amplifier) Co-Authored-By: Amplifier <240397093+microsoft-amplifier@users.noreply.github.com> --- .github/workflows/ci.yml | 9 + tests/pty_harness.py | 246 ++++++++++++++++++ tests/test_ctrlc_functional_integration.py | 131 ++++------ .../test_stdout_offload_freeze_integration.py | 16 +- tests/test_terminal_echo_integration.py | 167 ++++++------ 5 files changed, 393 insertions(+), 176 deletions(-) create mode 100644 tests/pty_harness.py diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 40a627e..ecbfcea 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -9,6 +9,11 @@ jobs: test: name: pytest (${{ matrix.os }}, py${{ matrix.python-version }}) runs-on: ${{ matrix.os }} + # Typical runtime is ~20-30s. A hang must fail LOUDLY and fast, not sit + # burning runner time until the 6h default limit -- macOS minutes bill at + # 10x, and a job stuck at "in_progress" reads as "not done yet" rather + # than "broken", which is how a false green gets merged. + timeout-minutes: 10 strategy: fail-fast: false matrix: @@ -37,6 +42,10 @@ jobs: integration: name: pytest -m integration (${{ matrix.os }}) runs-on: ${{ matrix.os }} + # These fork real pty children. A pty child whose output is never drained + # can wedge unreapably on macOS (state ``?Es``), so this job is the most + # likely place in the repo for a hang to appear. Bound it. + timeout-minutes: 10 strategy: fail-fast: false matrix: diff --git a/tests/pty_harness.py b/tests/pty_harness.py new file mode 100644 index 0000000..01be099 --- /dev/null +++ b/tests/pty_harness.py @@ -0,0 +1,246 @@ +"""Shared driver for the integration tests that fork a real pty child process. + +Why this exists +~~~~~~~~~~~~~~~ +Both ``test_terminal_echo_integration.py`` and +``test_ctrlc_functional_integration.py`` fork a child onto a real pty and then +inspect what the child did to the terminal. Doing that portably requires three +things that are easy to get wrong -- and that were originally gotten wrong in +both files, in a way that only shows up on macOS/BSD: + +1. **The pty master must be drained continuously, from the moment of the fork.** + A pty's output queue is small (~1 KiB on macOS). Once it fills, the child + blocks in ``write()``. On macOS the damage is far worse than a stalled + write: if the child is *exiting* when the queue is full, it wedges in the + kernel's exit path (``ps`` state ``?Es`` -- "exiting", controlling terminal + already revoked) and **cannot be killed, not even with SIGKILL**. Measured + on macOS 26.6 / Darwin 25.6.0: + + child wrote 10B, parent_reads=False -> reaped@0.64s + child wrote 1000B, parent_reads=False -> reaped@0.63s + child wrote 10000B, parent_reads=False -> NEVER REAPED + (SIGKILL did NOT make it reapable) + + The same probe on Linux reaps the child every time. Linux tolerates an + un-drained pty at exit; macOS does not. + + Two distinct symptoms fall out of that single defect, which is why both + files needed the same fix: + + * The parent's ``os.write(master_fd, ...)`` raises ``OSError(EIO)``, because + a wedged-in-exit child has already had its pty slave revoked. (On Linux + the identical write silently succeeds into a pty nobody is reading, so + the race is invisible.) + * A blocking ``os.waitpid(pid, 0)`` after the SIGKILL never returns, because + the child can never be reaped -- an *unbounded* hang, not a slow test. + +2. **Every wait must be bounded.** A test may fail; a test may never hang. So + there is no blocking ``waitpid`` anywhere in this module: everything is a + ``WNOHANG`` poll against a deadline. + +3. **Input must be synchronised with the child, not with the clock.** Fixed + parent-side sleeps race the child's own timeline; the margin that happens to + hold on one platform does not hold on another. Callers use + ``wait_for_marker()`` to block until the child announces it is ready, and + ``PtyChild.send()`` treats an undeliverable keystroke as a hard failure + rather than silently testing nothing. + +Everything here is POSIX-only (``pty.fork``), matching the tests that use it. +""" + +from __future__ import annotations + +import os +import pty +import select +import signal +import threading +import time +from collections.abc import Callable + +__all__ = ["PtyChild", "fork_pty_child", "wait_for_marker"] + +# How long the drain thread waits on the master fd before re-checking whether +# it has been asked to stop. +_DRAIN_POLL_S = 0.05 + + +class PtyChild: + """A forked child attached to a real pty, with its master fd drained. + + A background thread reads the pty master for the whole lifetime of the + child, so the child can never block on a full output queue (see the module + docstring for why that is fatal on macOS). Reads happen on a ``dup()`` of + the master fd, so the caller's own ``master_fd`` keeps ordinary blocking + semantics for writes and for ``termios`` inspection. + """ + + def __init__(self, pid: int, master_fd: int) -> None: + self.pid = pid + self.master_fd = master_fd + self.status: int | None = None + self.exited = False + + self._sink = bytearray() + self._stop = threading.Event() + self._closed = False + self._drain_fd = os.dup(master_fd) + self._thread = threading.Thread( + target=self._drain, name=f"pty-drain-{pid}", daemon=True + ) + self._thread.start() + + # -- output ------------------------------------------------------------ + + @property + def output(self) -> bytes: + """Everything the child has written to the pty so far.""" + return bytes(self._sink) + + def _drain(self) -> None: + fd = self._drain_fd + while not self._stop.is_set(): + try: + readable, _, _ = select.select([fd], [], [], _DRAIN_POLL_S) + except OSError: + return # fd closed underneath us during shutdown + if not readable: + continue + try: + chunk = os.read(fd, 65536) + except BlockingIOError: + continue + except OSError: + # Linux raises EIO on a master read once the slave side is + # gone; macOS returns EOF for the same condition (below). + # Either way nothing more will arrive -- idle until closed so + # that close() stays the sole owner of the fd's lifetime. + self._stop.wait(_DRAIN_POLL_S) + continue + if not chunk: + self._stop.wait(_DRAIN_POLL_S) + continue + self._sink.extend(chunk) + + # -- input ------------------------------------------------------------- + + def send(self, data: str | bytes) -> None: + """Write ``data`` to the pty as if typed. Undeliverable input fails loudly. + + A failed write means the child is no longer holding the pty slave open + -- it exited, or wedged in exit, before the input under test could + reach it. Swallowing that would leave a test that passes while + exercising nothing, so it is raised as an assertion failure instead. + """ + payload = data.encode() if isinstance(data, str) else data + try: + os.write(self.master_fd, payload) + except OSError as exc: + raise AssertionError(self._undeliverable(payload, exc)) from exc + + def signal(self, sig: int) -> None: + """Send a real OS signal to the child. A missing child fails loudly.""" + try: + os.kill(self.pid, sig) + except ProcessLookupError as exc: + raise AssertionError(self._undeliverable(f"signal {sig}", exc)) from exc + + def _undeliverable(self, what: object, exc: BaseException) -> str: + return ( + f"could not deliver {what!r} to the pty child (pid={self.pid}): {exc!r}. " + f"The child is no longer holding the pty slave open, so it exited (or " + f"wedged while exiting) before the input under test could reach it -- " + f"this scenario did not actually exercise what it claims to. " + f"child_reaped={self.poll()} child_output={self.output!r}" + ) + + # -- lifecycle --------------------------------------------------------- + + def poll(self) -> bool: + """True once the child has been reaped. Never blocks.""" + if self.exited: + return True + try: + wpid, status = os.waitpid(self.pid, os.WNOHANG) + except ChildProcessError: + self.exited = True + return True + if wpid == self.pid: + self.exited = True + self.status = status + return self.exited + + def wait(self, timeout: float) -> bool: + """Poll for exit until ``timeout``. Returns whether the child exited.""" + deadline = time.monotonic() + timeout + while time.monotonic() < deadline: + if self.poll(): + return True + time.sleep(0.02) + return self.poll() + + def kill(self, grace: float = 2.0) -> bool: + """SIGKILL the child and poll (never block) for it to become reapable. + + Returns False if it never does -- which on macOS is a real outcome, not + a theoretical one, for a child wedged in the kernel's exit path. + """ + try: + os.kill(self.pid, signal.SIGKILL) + except ProcessLookupError: + pass + return self.wait(grace) + + def close(self) -> None: + """Stop draining and release both fds. Safe to call more than once. + + Joins the drain thread so that no extra thread is alive across a + subsequent ``pty.fork()`` in the same process. + """ + if self._closed: + return + self._closed = True + self._stop.set() + self._thread.join(timeout=1.0) + for fd in (self._drain_fd, self.master_fd): + try: + os.close(fd) + except OSError: + pass + + +def fork_pty_child(child_body: Callable[[], None]) -> PtyChild: + """Fork a child onto a fresh pty and start draining its master fd. + + ``child_body`` runs in the child, whose fds 0/1/2 are the pty slave. The + child always terminates via ``os._exit`` so it can never re-enter the test + runner's own teardown. + """ + pid, master_fd = pty.fork() + if pid == 0: + try: + child_body() + except BaseException: # noqa: BLE001 - a fork child must never escape into the test runner + os._exit(1) + os._exit(0) + return PtyChild(pid, master_fd) + + +def wait_for_marker(path: str, child: PtyChild, timeout: float, what: str) -> None: + """Block until the child creates ``path``, or fail with a useful message. + + This is the readiness handshake that replaces fixed parent-side sleeps: it + ties "the parent may now send input" to an event in the child rather than + to a wall-clock margin that differs per platform. + """ + deadline = time.monotonic() + timeout + while not os.path.exists(path): + if time.monotonic() > deadline: + reaped = child.poll() + child.kill() + raise AssertionError( + f"child never signaled {what} within {timeout}s " + f"(pid={child.pid}, already_reaped={reaped}, " + f"output={child.output!r})" + ) + time.sleep(0.01) diff --git a/tests/test_ctrlc_functional_integration.py b/tests/test_ctrlc_functional_integration.py index 0f5970f..6e4e089 100644 --- a/tests/test_ctrlc_functional_integration.py +++ b/tests/test_ctrlc_functional_integration.py @@ -48,13 +48,13 @@ import json import os -import pty import signal import sys import time from pathlib import Path import pytest +from pty_harness import fork_pty_child, wait_for_marker pytestmark = pytest.mark.integration @@ -232,95 +232,64 @@ def _run_pty_scenario(scenario: str, timeout: float = 8.0) -> dict: if os.path.exists(p): os.remove(p) - pid, master_fd = pty.fork() - if pid == 0: + def _child() -> None: sys.path.insert(0, str(REPO_ROOT)) - try: - _child_main(scenario, result_path, ready_path) - except BaseException: - os._exit(1) - os._exit(0) - - # Wait for the deterministic readiness signal (raw_mode actually - # entered) instead of a fixed sleep -- see _child_main's docstring for - # why sending keystrokes before raw_mode clears ISIG would silently - # test the wrong code path (a real kernel SIGINT instead of the raw - # byte). - ready_deadline = time.time() + 5.0 - while not os.path.exists(ready_path): - if time.time() > ready_deadline: - raise TimeoutError( - f"child never signaled raw_mode readiness for scenario={scenario!r}" - ) - time.sleep(0.01) - # Tiny settle margin: raw_mode.__enter__ has returned, but give - # prompt_toolkit's own input-reader registration a moment to actually - # start polling the fd before we write to it. - time.sleep(0.05) - - def send(text: str) -> None: - os.write(master_fd, text.encode()) - - if scenario == "single_ctrlc": - # One physical \x03 keypress, NO real OS signal at all -- the exact - # keystroke a user's terminal sends while raw_mode() has ISIG off. - send("\x03") - elif scenario == "double_ctrlc": - # Two keypresses, NO real signal -- proves the keystroke-only path - # escalates graceful -> immediate on its own. - send("\x03") - time.sleep(0.1) - send("\x03") - elif scenario == "typing_then_ctrlc": - # Ctrl-C arrives mid-compose of a steer message. - send("hello wor") - time.sleep(0.1) - send("\x03") - elif scenario == "sigint_only": - # Regression: the pre-existing real-OS-signal path must still work. - try: - os.kill(pid, signal.SIGINT) - except ProcessLookupError: - pass - - deadline = time.time() + timeout - exited = False - while time.time() < deadline: - try: - wpid, _status = os.waitpid(pid, os.WNOHANG) - except ChildProcessError: - exited = True - break - if wpid == pid: - exited = True - break + _child_main(scenario, result_path, ready_path) + + # ``fork_pty_child`` starts draining the pty master immediately, for the + # whole life of the child. That is load-bearing on macOS: a child that + # reaches exit with an un-drained pty output queue wedges inside the + # kernel's exit path and can no longer be reaped -- SIGKILL included -- + # which turned the reap below into an unbounded hang. See + # tests/pty_harness.py for the measurements. + child = fork_pty_child(_child) + try: + # Wait for the deterministic readiness signal (raw_mode actually + # entered) instead of a fixed sleep -- see _child_main's docstring for + # why sending keystrokes before raw_mode clears ISIG would silently + # test the wrong code path (a real kernel SIGINT instead of the raw + # byte). + wait_for_marker(ready_path, child, timeout=10.0, what="raw_mode readiness") + # Tiny settle margin: raw_mode.__enter__ has returned, but give + # prompt_toolkit's own input-reader registration a moment to actually + # start polling the fd before we write to it. time.sleep(0.05) - if not exited: - try: - os.kill(pid, signal.SIGKILL) - os.waitpid(pid, 0) - except ProcessLookupError: - pass - - os.set_blocking(master_fd, False) - try: - for _ in range(20): - try: - chunk = os.read(master_fd, 65536) - except (BlockingIOError, OSError): - break - if not chunk: - break - except OSError: - pass - os.close(master_fd) + if scenario == "single_ctrlc": + # One physical \x03 keypress, NO real OS signal at all -- the exact + # keystroke a user's terminal sends while raw_mode() has ISIG off. + child.send("\x03") + elif scenario == "double_ctrlc": + # Two keypresses, NO real signal -- proves the keystroke-only path + # escalates graceful -> immediate on its own. + child.send("\x03") + time.sleep(0.1) + child.send("\x03") + elif scenario == "typing_then_ctrlc": + # Ctrl-C arrives mid-compose of a steer message. + child.send("hello wor") + time.sleep(0.1) + child.send("\x03") + elif scenario == "sigint_only": + # Regression: the pre-existing real-OS-signal path must still work. + child.signal(signal.SIGINT) + + exited = child.wait(timeout) + if not exited: + child.kill() + finally: + if not child.poll(): + child.kill() + child.close() + if os.path.exists(ready_path): + os.remove(ready_path) if not os.path.exists(result_path): return { "scenario": scenario, "exited_cleanly": False, "error": "no result file written", + "child_output": child.output.decode(errors="replace"), } result = json.loads(Path(result_path).read_text()) diff --git a/tests/test_stdout_offload_freeze_integration.py b/tests/test_stdout_offload_freeze_integration.py index 962d470..1f62b55 100644 --- a/tests/test_stdout_offload_freeze_integration.py +++ b/tests/test_stdout_offload_freeze_integration.py @@ -195,8 +195,20 @@ def _run_scenario(fixed: bool, timeout: float = 6.0) -> tuple[bool, list[float] if not exited: try: os.kill(pid, signal.SIGKILL) - os.waitpid(pid, 0) - except ProcessLookupError: + # Bounded WNOHANG poll, never a blocking waitpid(pid, 0). This test + # deliberately constructs the un-drained-pty condition, and on macOS + # a pty child whose output queue is never drained wedges in state + # ``?Es`` -- controlling terminal already revoked, exiting, and NOT + # reapable even after SIGKILL. A blocking waitpid there hangs the + # run forever (this is exactly how the macOS CI job burned 25 + # minutes before being cancelled). A test may fail; a test must + # never hang. + kill_deadline = time.time() + 5.0 + while time.time() < kill_deadline: + if os.waitpid(pid, os.WNOHANG)[0] == pid: + break + time.sleep(0.05) + except (ProcessLookupError, ChildProcessError): pass ticks: list[float] | None = None diff --git a/tests/test_terminal_echo_integration.py b/tests/test_terminal_echo_integration.py index 1d815bb..a854994 100644 --- a/tests/test_terminal_echo_integration.py +++ b/tests/test_terminal_echo_integration.py @@ -33,7 +33,6 @@ from __future__ import annotations import os -import pty import signal import sys import termios @@ -41,6 +40,7 @@ from pathlib import Path import pytest +from pty_harness import fork_pty_child, wait_for_marker pytestmark = pytest.mark.integration @@ -68,7 +68,7 @@ def _is_healthy(state: dict) -> bool: # --------------------------------------------------------------------------- -def _child_main(scenario: str) -> None: +def _child_main(scenario: str, ready_path: str) -> None: import asyncio import time as _time @@ -213,7 +213,15 @@ def sigint_handler(signum, frame): def _traced_enter(self): log(f"raw_mode.__enter__ (fd={self.fileno}, id={id(self)})") - return _orig_enter(self) + result = _orig_enter(self) + # Readiness handshake for the parent (see _run_pty_scenario): raw_mode + # is now actually in force, so the child is inside the window the + # scenario intends to interrupt. Written AFTER __enter__ returns so a + # \x03 byte that arrives immediately cannot land while ISIG is still + # set (which would deliver a real kernel SIGINT instead of the raw + # byte, silently exercising a different code path). + Path(ready_path).write_text("ready", encoding="utf-8") + return result def _traced_exit(self, *a): log(f"raw_mode.__exit__ (fd={self.fileno}, id={id(self)})") @@ -244,99 +252,72 @@ def _traced_exit(self, *a): def _run_pty_scenario(scenario: str, timeout: float = 8.0) -> dict: - pid, master_fd = pty.fork() - if pid == 0: - # ----- CHILD ----- - try: - _child_main(scenario) - except BaseException: - os._exit(1) - os._exit(0) - - # ----- PARENT ----- - time.sleep(0.6) # let the child boot python/prompt_toolkit - - def send(text: str) -> None: - os.write(master_fd, text.encode()) - - if scenario == "ctrlc_midturn": - time.sleep(0.3) - send("\x03") # Ctrl-C byte (prompt_toolkit key path) - elif scenario == "doublectrlc": - time.sleep(0.3) - send("\x03") - time.sleep(0.05) - send("\x03") - try: - os.kill(pid, signal.SIGINT) # real OS signal racing the byte - except ProcessLookupError: - pass - elif scenario == "sigint_only": - time.sleep(0.35) - try: - os.kill(pid, signal.SIGINT) - except ProcessLookupError: - pass - elif scenario == "bytes_only": - time.sleep(0.3) - send("\x03") - time.sleep(0.05) - send("\x03") - # "normal", "approval_cycle", "multi_orphan": driven entirely by the - # child's own internal timers -- no parent-side input needed. - - deadline = time.time() + timeout - exited = False - status = None - while time.time() < deadline: - try: - wpid, status = os.waitpid(pid, os.WNOHANG) - except ChildProcessError: - exited = True - break - if wpid == pid: - exited = True - break + ready_path = f"/tmp/test_terminal_echo_ready_{scenario}_{os.getpid()}.marker" + if os.path.exists(ready_path): + os.remove(ready_path) + + # ``fork_pty_child`` starts draining the pty master immediately. That is + # not an optimisation: on macOS a child that exits with an un-drained pty + # output queue wedges in the kernel's exit path, its controlling terminal + # already revoked -- which makes the parent's writes below fail with EIO + # and makes the child unreapable even by SIGKILL. See tests/pty_harness.py. + child = fork_pty_child(lambda: _child_main(scenario, ready_path)) + try: + # Readiness handshake, not a fixed sleep: block until the child has + # actually entered prompt_toolkit's raw_mode(), so the keystrokes below + # land inside the window the scenario intends to interrupt rather than + # at whatever point a hardcoded parent-side delay happens to reach on + # this platform. (The previous fixed 0.6s + 0.3s sleeps raced the + # child's own timeline: on macOS the child was already gone by the time + # the parent wrote, so the Ctrl-C under test was never delivered.) + wait_for_marker(ready_path, child, timeout=10.0, what="raw_mode entry") + # Tiny settle margin: raw_mode.__enter__ has returned, but give + # prompt_toolkit's input-reader registration a moment to start polling + # the fd before we write to it. time.sleep(0.05) - if not exited: + if scenario == "ctrlc_midturn": + child.send("\x03") # Ctrl-C byte (prompt_toolkit key path) + elif scenario == "doublectrlc": + child.send("\x03") + time.sleep(0.05) + child.send("\x03") + child.signal(signal.SIGINT) # real OS signal racing the byte + elif scenario == "sigint_only": + child.signal(signal.SIGINT) + elif scenario == "bytes_only": + child.send("\x03") + time.sleep(0.05) + child.send("\x03") + # "normal", "approval_cycle", "multi_orphan": driven entirely by the + # child's own internal timers -- no parent-side input needed. + + exited = child.wait(timeout) + if not exited: + child.kill() + + # Read the terminal state back through the master fd while it is still + # open -- this is the actual subject of the test. try: - os.kill(pid, signal.SIGKILL) - os.waitpid(pid, 0) - except ProcessLookupError: - pass - - # Drain any remaining child output (avoids leaving data in the pty buffer). - output = b"" - try: - os.set_blocking(master_fd, False) - for _ in range(20): - try: - chunk = os.read(master_fd, 65536) - except (BlockingIOError, OSError): - break - if not chunk: - break - output += chunk - except OSError: - pass - - try: - attrs = termios.tcgetattr(master_fd) - state = _describe_termios(attrs) - except OSError as e: - state = {"error": str(e)} - - os.close(master_fd) - - return { - "scenario": scenario, - "exit_status": status, - "exited_cleanly": exited, - "termios": state, - "healthy": _is_healthy(state), - "output": output.decode(errors="replace"), - } + attrs = termios.tcgetattr(child.master_fd) + state = _describe_termios(attrs) + except OSError as e: + state = {"error": str(e)} + + return { + "scenario": scenario, + "exit_status": child.status, + "exited_cleanly": exited, + "termios": state, + "healthy": _is_healthy(state), + "output": child.output.decode(errors="replace"), + } + finally: + if not child.poll(): + child.kill() + child.close() + if os.path.exists(ready_path): + os.remove(ready_path) # ---------------------------------------------------------------------------