From fdcf3cb7c0187acc374ac9eb318bd5dd4d714ca5 Mon Sep 17 00:00:00 2001 From: hellices Date: Fri, 23 Oct 2026 19:20:45 +0900 Subject: [PATCH 1/2] test: drop the relay child-watcher race from stdio stderr checks test_stdout_noise_is_diverted_and_wire_is_restored[True] failed on 3.12 because the stdio server's stderr carried "child process pid 3098 exit status already read: will report returncode 255" (#472). relay=True forces the Windows-only relays onto POSIX. When the stdin relay exits on its own as the test closes stdin, and _relay_stdin's cleanup runs before the event loop has processed that exit, process.kill() goes through Popen.send_signal, which polls first (bpo-38630). That waitpid reaps the relay, and asyncio's child watcher then finds it gone, reports 255 and logs the warning. On Windows, where the relays run in production, nothing reaps. The three forced-relay tests that compare the server's stderr exactly now read it through _server_stderr, which drops whole lines matching either watcher's warning (pidfd: "exit status already read", threaded: "Unknown child process pid") and keeps everything else. Two tests pin both directions: both warnings are dropped with the surrounding lines intact, and a line that only contains one is kept. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- tests/mcp/test_stdio.py | 58 ++++++++++++++++++++++++++++++++++++++--- 1 file changed, 55 insertions(+), 3 deletions(-) diff --git a/tests/mcp/test_stdio.py b/tests/mcp/test_stdio.py index 8e8a097f7..8bdfab68e 100644 --- a/tests/mcp/test_stdio.py +++ b/tests/mcp/test_stdio.py @@ -7,6 +7,7 @@ import io import json import os +import re import signal import sys from collections.abc import AsyncIterator @@ -58,6 +59,54 @@ def _parameters(state: Path, *args: str, relay: bool = False) -> StdioServerPara ) +#: asyncio's child-watcher warning when a child it watches was reaped first +#: (#472). The tests force the Windows-only relays onto POSIX, where killing a +#: relay that just exited on its own runs `Popen.send_signal`'s poll +#: (bpo-38630); that `waitpid` reaps the relay before the event loop's watcher +#: does, and the watcher logs this line. On Windows nothing reaps, so +#: production never writes it. Pidfd watcher first, then the threaded one. +_RELAY_WATCHER_RACE = re.compile( + r"child process pid \d+ exit status already read: +will report returncode 255" + r"|Unknown child process pid \d+, will report returncode 255" +) + + +def _server_stderr(err: bytes) -> str: + """The stdio server's stderr, without the relay child-watcher race.""" + return "".join( + line + for line in err.decode().splitlines(keepends=True) + if not _RELAY_WATCHER_RACE.fullmatch(line.rstrip("\r\n")) + ) + + +@pytest.mark.parametrize( + "warning", + [ + "child process pid 3098 exit status already read: will report returncode 255", + "Unknown child process pid 3098, will report returncode 255", + ], + ids=["pidfd-watcher", "threaded-watcher"], +) +def test_server_stderr_drops_the_relay_child_watcher_race(warning: str) -> None: + """Forcing the Windows-only relays onto POSIX lets asyncio's child watcher + lose a race with `Popen.send_signal`'s poll (#472). Its warning is the + interpreter racing itself, not output the server chose to write.""" + err = f"fd-handler-noise\n{warning}\nkorvid: MCP stdio connection interrupted.\n" + assert _server_stderr(err.encode()) == ( + "fd-handler-noise\nkorvid: MCP stdio connection interrupted.\n" + ) + + +def test_server_stderr_keeps_every_other_line() -> None: + err = ( + "korvid: MCP stdio connection interrupted.\n" + "relay: Unknown child process pid 7, will report returncode 255\n" + "child process pid 7 exit status already read\n" + ) + assert _server_stderr(err.encode()) == err + + @asynccontextmanager async def _backend( state: Path, executor: RecordingExecutor | None = None @@ -572,7 +621,7 @@ async def test_sigint_exits_without_host_stdin_eof( err = await process.stderr.read() assert process.returncode == 1, err.decode() assert all(json.loads(line)["jsonrpc"] == "2.0" for line in out.splitlines()) - assert err.decode() == "korvid: MCP stdio connection interrupted.\n" + assert _server_stderr(err) == "korvid: MCP stdio connection interrupted.\n" finally: executor.release.set() @@ -621,7 +670,7 @@ async def test_shutdown_exits_without_draining_stdout( assert process.stderr is not None assert process.returncode == (1 if interrupt else 0) expected = b"korvid: MCP stdio connection interrupted.\n" if interrupt else b"" - assert await process.stderr.read() == expected + assert _server_stderr(await process.stderr.read()) == expected.decode() finally: host.close() @@ -872,7 +921,10 @@ async def noisy_list_tools(self, ctx, params): out, err = await asyncio.wait_for(process.communicate(), 5) assert process.returncode == 0, err.decode() assert json.loads(out) == {"restored": True} - assert sorted(err.decode().splitlines()) == ["fd-handler-noise", "python-handler-noise"] + assert sorted(_server_stderr(err).splitlines()) == [ + "fd-handler-noise", + "python-handler-noise", + ] @pytest.mark.parametrize("relay", [False, True]) From 0d5d2b535ab68edbf5c27d4ef9c535453b23b245 Mon Sep 17 00:00:00 2001 From: hellices Date: Sat, 24 Oct 2026 02:24:25 +0900 Subject: [PATCH 2/2] test: emit the relay watcher race in every forced-relay run The race is rare on its own, so the first fix only covered the three exact stderr checks it was seen against. Under four xdist workers on korvid-runners it hit a fourth on 3.12, twice: test_stdio_delivers_large_utf8_output_without_truncation[True] expected an empty stderr log and got "child process pid ... exit status already read: will report returncode 255". The forced-relay entrypoint now logs that exact asyncio warning at startup, so every relay=True test that reads the server's stderr has to filter it on every run instead of passing on a lucky one. With the line emitted, exactly that test failed; it now reads its stderr log through _server_stderr, which accepts text as well as bytes, and test_stdio.py passes in full. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- tests/mcp/test_stdio.py | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/tests/mcp/test_stdio.py b/tests/mcp/test_stdio.py index 8bdfab68e..9ed814023 100644 --- a/tests/mcp/test_stdio.py +++ b/tests/mcp/test_stdio.py @@ -50,6 +50,13 @@ def _parameters(state: Path, *args: str, relay: bool = False) -> StdioServerPara "stdio.cancellable_stdin = _relay_stdin\n" "from korvid.mcp import _stdio_output\n" "_stdio_output._posix_stdout = _stdio_output._relay_stdout\n" + # The child-watcher race (#472) is rare on its own; emit its line + # every time, so every relay test that reads the server's stderr + # proves it filters it rather than passing on a lucky run. + "import logging\n" + "logging.getLogger('asyncio').warning(\n" + " 'child process pid %d exit status already read: will report returncode 255', 0\n" + ")\n" "from korvid.cli import main", ) return StdioServerParameters( @@ -71,11 +78,12 @@ def _parameters(state: Path, *args: str, relay: bool = False) -> StdioServerPara ) -def _server_stderr(err: bytes) -> str: +def _server_stderr(err: bytes | str) -> str: """The stdio server's stderr, without the relay child-watcher race.""" + text = err.decode() if isinstance(err, bytes) else err return "".join( line - for line in err.decode().splitlines(keepends=True) + for line in text.splitlines(keepends=True) if not _RELAY_WATCHER_RACE.fullmatch(line.rstrip("\r\n")) ) @@ -724,7 +732,7 @@ async def test_stdio_delivers_large_utf8_output_without_truncation( assert not result.is_error assert getattr(result.content[0], "text", None) == executor.result errors.seek(0) - assert errors.read() == "" + assert _server_stderr(errors.read()) == "" @pytest.mark.skipif(sys.platform == "win32", reason="POSIX nonblocking partial writes")