fix(runner): stop the timeout watchdog pinning the caller's output

CHANGELOG.md

@@ -11,6 +11,7 @@
 - Performance: per-test cleanup no longer reads the whole of `BASHUNIT_TEMP_DIR`. That directory is shared and survives between runs, so leftovers from an interrupted run taxed every test of every later run — a 100-test file took 978ms against 5000 leftovers and 542ms after, and runtime no longer grows with the directory. A file a test writes there by hand, rather than via `temp_file`/`temp_dir`, is no longer removed for it (#1269)
 
 ### Fixed
+- A run using `--test-timeout` no longer leaves its timeout watchdog holding the caller's captured output. The watchdog was detached from stdin/stdout/stderr but still inherited the two descriptors the runner dups from stdout, so one that outlived its parent — after a kill, or when the signal that ends it missed — pinned whoever was reading that run for the whole timeout budget; a nested run under `--suite` did it to the run that spawned it. Such a watchdog now also stops itself once there is nothing left to police, rather than sleeping out the budget and then firing a process-group kill at a pid that may by then name something else (#1137)
 - A test that both fails an assertion and hits a shell error no longer reports the failure text with the diagnostic glued onto the end; the error message is the diagnostic alone (#1267)
 - `--list` under `--parallel` no longer prints `No tests found` in the middle of the ids: a listing dispatches no worker, so there is nothing to aggregate (#1007)
 

src/runner/exec.sh

@@ -347,13 +347,40 @@ function bashunit::runner::run_with_timeout() {
   # Both jobs run in their own process group (set -m) so each can be killed as a
   # whole tree. The body MUST run in an explicit ( ) subshell: a backgrounded { }
   # group does not run its EXIT trap on normal completion, which would drop the
-  # encoded assertion context. The watchdog's fds are detached from the caller so
-  # a lingering `sleep` can never hold a captured stdout pipe open.
+  # encoded assertion context.
   set -m
   (bashunit::runner::execute_test_body "$test_file" "$fn_name" "$@") >"$out_file" 2>&1 &
   local test_pid=$!
   (
-    sleep "$secs"
+    # The watchdog is the one process here that can outlive its parent: the
+    # group kill below intermittently misses it, and a SIGKILLed run never
+    # reaches that kill at all. Detaching 0/1/2 is not enough, because both
+    # descriptors bashunit keeps open are dups of a stdout it does not own --
+    # FD 3 for the test body, FD 5 for the EXIT trap -- and a nested run
+    # inherits the OUTER run's pair on top of its own. An orphaned `sleep` held
+    # those, so the caller reading the run's output waited out the whole timeout
+    # budget for an EOF that no visible writer was delaying (#1137).
+    #
+    # `exec` closes for good; a per-command `3>&- 5>&-` would not, because bash
+    # implements it by dup'ing each descriptor to a fd >= 10 to restore it
+    # after, and that copy is not close-on-exec, so the child inherits the very
+    # pipe the close was meant to withhold (`ls -l /dev/fd` inside `cmd 5>&-`
+    # lists fd 11).
+    exec 3>&- 5>&-
+    # Wait in steps rather than one `sleep $secs`, giving up as soon as there is
+    # nothing left to police. A watchdog can outlive its parent -- the group kill
+    # below "intermittently misses", per the note there, and a killed run never
+    # reaches that kill at all -- and one that stays armed sleeps out the budget
+    # and then signals a process GROUP by a pid the kernel is free to have handed
+    # to something else by then. `$$` is the runner's pid even in here, so the
+    # two checks read as "is my run still going, and is the test still running?".
+    waited=0
+    while [ "$waited" -lt "$secs" ]; do
+      kill -0 "$$" 2>/dev/null || exit 0
+      kill -0 "$test_pid" 2>/dev/null || exit 0
+      sleep 1
+      waited=$((waited + 1))
+    done
     # Only a still-running test can have timed out. Without this guard a watchdog
     # that outlived a missed teardown (see below) would mark an already-finished
     # fast test as timed out.
@@ -409,6 +436,12 @@ function bashunit::runner::run_test() {
   # (FD = File Descriptor)
   # Duplicate the current std-output (FD 1) and assigns it to FD 3.
   # This means that FD 3 now points to wherever the std-output was pointing.
+  #
+  # Nothing in src/ reads it, but a test body can: `exec 2>&3 2>log` is how a
+  # test detaches its stderr from the runner's 2>&1 merge, and
+  # tests/unit/project/redirect_error_test.sh pins that. It is therefore part of
+  # what a test is handed, and every process the test forks inherits it -- see
+  # the watchdog in run_with_timeout, which must close it (#1137).
   exec 3>&1
 
   local test_execution_result

tests/acceptance/bashunit_timeout_test.sh

@@ -41,3 +41,54 @@ function test_bashunit_does_not_time_out_a_fast_test() {
   assert_successful_code \
     "$(./bashunit --no-parallel --env "$TEST_ENV_FILE" --test-timeout 5 "$fast_only")"
 }
+
+# A caller capturing a run's output waits for EOF on the pipe, which arrives
+# only once every process holding the write end has gone. The watchdog is
+# detached from stdout, so killing the run must end the capture at once -- and
+# it did not, because a descriptor the runner had left open leaked into the
+# watchdog's `sleep`, pinning the caller for the whole timeout budget (#1137).
+function test_a_killed_run_releases_its_captured_output_at_once() {
+  local workdir
+  workdir=$(bashunit::temp_dir killed_run)
+  local probe="$workdir/body-started"
+  # The body announces itself rather than the caller guessing a delay: the
+  # watchdog exists only while a test body does, and on a slow runner a fixed
+  # sleep killed the run before it had started one -- or printed anything.
+  cat >"$workdir/killed_test.sh" <<TEST
+function test_body_in_flight_when_the_run_is_killed() {
+  : >"$probe"
+  sleep 3
+  assert_same "never" "reached"
+}
+TEST
+
+  local start=0
+  local end=0
+  local output=""
+
+  start=$(date +%s)
+  output=$(
+    # Stand-ins for the two dups of stdout the runner hands a test body, which a
+    # nested run inherits for real. Pointing them at this capture is what makes
+    # a leak observable: what the killed run must not leave behind is a process
+    # holding this pipe, on FD 1 or on any descriptor it was handed.
+    exec 3>&1 5>&1
+    ./bashunit --no-parallel --env "$TEST_ENV_FILE" --test-timeout 15 "$workdir" &
+    run_pid=$!
+    waited=0
+    while [ ! -f "$probe" ] && [ "$waited" -lt 300 ]; do
+      sleep 0.1
+      waited=$((waited + 1))
+    done
+    kill -9 "$run_pid" 2>/dev/null
+    wait "$run_pid" 2>/dev/null
+  ) || true
+  end=$(date +%s)
+
+  # The floor is the body's own sleep, which legitimately keeps the run's
+  # stdout: a still-running test body is indistinguishable from one about to
+  # print. The ceiling only has to sit below the timeout budget, which is what a
+  # leaked descriptor makes the caller wait out in full.
+  assert_contains "Running" "$output"
+  assert_less_than 10 "$((end - start))"
+}