From b045f547bae7479fe7dcd2a58900ca0d2b13a4d5 Mon Sep 17 00:00:00 2001 From: Patrick O'Reilly Date: Thu, 17 Sep 2026 23:06:33 -0700 Subject: [PATCH] jhm: bound the test-output echo on every reap, not just timed-out ones (#570) `jhm --test` can hang forever reaping a test that has ALREADY EXITED, taking the rest of the suite with it and burning the whole CI job with no diagnostic. An aarch64 run sat in it for 110 minutes with 61 tests still queued, having printed one line past the previous progress update: TESTS: 4 running, 61 queued TEST: orly/server/import_replication.test No TIMEOUT:, no EXITCODE:, no echoed output. The per-test timeout cannot catch this. Its sweep only runs when TryWaitAll() returns nothing; the absence of a "TIMEOUT: ... still running" line proves the test exited on its own, putting jhm in the reap where the deadline no longer applies. It then blocked in Base::EchoOutput, which reads to EOF -- and EOF on a pipe needs EVERY write end closed. import_replication.test forks orlyi servers; any that outlive the test still hold its stdout. EchoOutputBounded already exists for precisely this, written for #537, and its comment names the failure exactly. It was simply scoped too narrowly: only the SIGKILLed branch used it, on the assumption that only a killed test strands children. A test that exits on its own can stand up servers and fail before reaping them just as easily. So use it on both paths. It costs nothing in the normal case -- a pipe whose writers are all gone polls readable immediately and reads zero, so the quiet period is only ever spent in the pathological case it exists for. Verified both directions with a probe that forks a "test" which spawns a grandchild holding stdout and then exits non-zero: the read-to-EOF shape hangs and has to be killed, the bounded one returns in 2s and still prints the test's output. jhm rebuilds clean via bootstrap. --- changelog.d/570-bounded-test-echo.md | 1 + jhm/jhm.cc | 31 +++++++++++++++++----------- 2 files changed, 20 insertions(+), 12 deletions(-) create mode 100644 changelog.d/570-bounded-test-echo.md diff --git a/changelog.d/570-bounded-test-echo.md b/changelog.d/570-bounded-test-echo.md new file mode 100644 index 00000000..12a90143 --- /dev/null +++ b/changelog.d/570-bounded-test-echo.md @@ -0,0 +1 @@ +- **Fixed**: `jhm --test` no longer hangs forever reaping a test that has already exited. `Base::EchoOutput` reads the child's pipe to EOF, and EOF needs every write end closed -- so a test that stands up servers and fails before reaping them leaves grandchildren holding its stdout, and the reporter waits for an EOF that can never arrive. One aarch64 run sat there for 110 minutes with 61 tests still queued, which is exactly the silent budget-eating failure #537 set out to abolish. `EchoOutputBounded` already existed for this, written for #537, but was wired only to the SIGKILLed path on the assumption that only a killed test strands children; it now runs on every reap. Free in the normal case -- a pipe with no writers left polls readable at once and reads zero (#570). diff --git a/jhm/jhm.cc b/jhm/jhm.cc index 714c25f3..107a969a 100644 --- a/jhm/jhm.cc +++ b/jhm/jhm.cc @@ -99,11 +99,22 @@ void WriteCompileCommandsJson(const TEnv &env) { out << TJson(std::move(entries)); } -/* Echo whatever output the pump has already delivered for a TIMED-OUT test, - giving up after a quiet period instead of waiting for EOF: a SIGKILLed - test can leave grandchildren holding the pipe's write side (its forked - servers, say), and then EOF never comes -- the reporter must not inherit - the wedge the timeout just cut short (#537). */ +/* Echo whatever output the pump has already delivered, giving up after a + quiet period instead of waiting for EOF: a test can leave grandchildren + holding the pipe's write side (its forked servers, say), and then EOF + never comes -- the reporter must not inherit a wedge it is trying to + report on (#537). + + Used on EVERY reap, not just timed-out ones (#570). The original scope + assumed only a SIGKILLed test strands children, but a test that exits on + its OWN can stand up servers and fail before reaping them just as easily, + and that path used to wait for an EOF that could never arrive -- one + aarch64 run sat in it for 110 minutes with 61 tests still queued, which is + precisely the silent budget-eating failure #537 set out to abolish. + + Costs nothing in the normal case: a pipe whose writers are all gone polls + readable immediately and reads zero, so the quiet period is only ever + spent in the pathological case it exists for. */ void EchoOutputBounded(TFd &&fd) { uint8_t buf[4096]; for (;;) { @@ -389,13 +400,9 @@ class TJhm : public TCmd { TESTS: line land displaced from the test's own output, making the failure read as if the test printed nothing (#520). */ cout << "TEST: " << test << endl; - if (timed_out.count(test)) { - EchoOutputBounded(subprocess->TakeStdOutFromChild()); - EchoOutputBounded(subprocess->TakeStdErrFromChild()); - } else { - EchoOutput(subprocess->TakeStdOutFromChild()); - EchoOutput(subprocess->TakeStdErrFromChild()); - } + /* Bounded on both paths -- see EchoOutputBounded (#570). */ + EchoOutputBounded(subprocess->TakeStdOutFromChild()); + EchoOutputBounded(subprocess->TakeStdErrFromChild()); } if (timed_out.count(test)) { cout << "TIMEOUT: " << test << " killed after " << timed_out.at(test)