fix(eval): drain with read1 so progress surfaces before the child exits

The live proof run showed the driver's own lines streaming correctly and
every one of the sweep's 24 cell lines sharing one timestamp
(12:05:29.96) four hours after the sweep began — the exact symptom
echo_stdout was added to remove, still present for the phase that
actually takes the fifteen hours.

`_drain` read with `pipe.read(8192)`. On a BufferedReader that blocks
until it has all 8192 bytes or the pipe closes; it does not return short
reads. A sweep emits a couple of short lines per ~45-minute cell and
never fills 8 KB, so everything sat in the buffer until the process
exited. The tail and the capture were unaffected — they only need the
bytes eventually — which is why nothing caught it before.

The existing echo test could not have: its child wrote one line and
exited immediately, so EOF made `read` return. The new test makes the
child refuse to exit until the echoed line has been observed, so an
implementation that only flushes at EOF deadlocks and fails on the
timeout instead of passing on a technicality. Verified it fails with
`read` and passes with `read1`.
This commit is contained in:
Gergo Magyar 2026-08-02 12:12:08 +00:00
parent a5251d6b08
commit f484e2cf34
2 changed files with 48 additions and 1 deletions

View file

@ -9,6 +9,7 @@ import sys
import time
from concurrent.futures import ThreadPoolExecutor
from pathlib import Path
from types import SimpleNamespace
import pytest
@ -141,6 +142,48 @@ def test_echo_stdout_streams_child_progress_and_stays_off_by_default(capfd) -> N
assert "starting" in echoed.stdout_tail
def test_echo_reaches_the_log_while_the_child_is_still_running(tmp_path: Path, monkeypatch) -> None:
"""Streaming has to be prompt, not merely eventual.
A sweep emits one line every ~45 minutes. Draining with `read(8192)` still
delivers every byte, so the tail and the capture look correct but nothing
surfaces until the pipe closes, which turns a 15-hour job into a silent one
and is the whole reason this passthrough exists.
The child here refuses to exit until the echoed line has been observed, so
an implementation that only flushes at EOF deadlocks and fails on the
timeout rather than passing on a technicality.
"""
released = tmp_path / "echo-observed"
class Sink:
def write(self, data: bytes) -> int:
if b"first-line" in data:
released.write_text("go")
return len(data)
def flush(self) -> None:
pass
monkeypatch.setattr(process_control.sys, "stderr", SimpleNamespace(buffer=Sink()))
script = """
import pathlib, sys, time
sys.stdout.write('first-line\\n')
sys.stdout.flush()
target = pathlib.Path(%r)
for _ in range(400):
if target.exists():
break
time.sleep(0.05)
""" % str(released)
result = run_managed([PYTHON, "-c", script], timeout=15, echo_stdout=True)
assert released.exists(), "the line never reached the echo sink while the child ran"
assert result.ok
assert "first-line" in result.stdout_tail
def test_incomplete_stdin_delivery_cannot_report_success() -> None:
result = run_managed(
[PYTHON, "-c", "import os,time; os.close(0); time.sleep(0.05)"],

View file

@ -128,7 +128,11 @@ def _drain(
echo: BinaryIO | None = None,
) -> None:
try:
while chunk := pipe.read(8192):
# read1, not read: on a BufferedReader, read(n) blocks until it has all
# n bytes or the pipe closes. A child that emits a line every 45 minutes
# never fills 8 KB, so its output would surface only when it exits —
# which is precisely what echo_stdout exists to avoid.
while chunk := pipe.read1(8192):
tail.append(chunk)
if capture is not None:
capture.append(chunk)