Fix the llm_eval timeout: reachable MMLU mirror + no pipe deadlock (#2270)

### What does this PR do? Type of change: Bug fix `tests/examples/llm_eval/test_llm_eval.py::test_qwen3_eval_fp8` has been failing with `Failed: Timeout (>900.0s) from pytest-timeout` on unrelated branches (runs 33027056246 and the one for `ad83a428`, while the 2026-08-24 nightly passed). It is not the test being slow — it is the harness deadlocking, and the deadlock also destroys the diagnostics that would explain the underlying kill. **Mechanism.** The traceback shows `self = <Popen: returncode: -9 args: ['scripts/huggingface_example.sh', ...]>` while still blocked in `stdout.read()`. The launcher was SIGKILLed (nothing in pytest sends SIGKILL — pytest-timeout raises in the main thread, and the test's `finally` `pkill` sends SIGTERM and only runs afterwards — so an OOM kill is the likely source). But `subprocess.run(..., stdout=PIPE, stderr=STDOUT)` waits for **EOF on the pipe**, not for the process, and a surviving grandchild (the TRT-LLM serve/build worker) still holds the write end. EOF never arrives, so the test blocks until the 900 s alarm. Because the pipe is never drained, **every line of child output is discarded**, which is why the CI log says nothing about what the script was doing when it died. Reduced to a self-contained reproducer: ```python script = "sleep 300 & echo 'launcher output'; sleep 0.3; kill -9 $$" subprocess.run(["bash", "-c", script], stdout=PIPE, stderr=STDOUT, text=True, timeout=20) # -> TimeoutExpired: still blocked in communicate() after 20.0s, output lost ``` **Fix.** `_run_capturing` now starts the command in its own session, drains its output on a reader thread (so logs stream as they arrive instead of being buffered until the end), waits on the *process*, and kills the process group if descendants still hold the pipe after a 30 s grace period. A killed launcher now fails in seconds with its logs intact instead of silently burning the test's whole timeout. This does not fix whatever kills the script; it makes it diagnosable. Worth noting separately: `test_qwen3_eval_fp8` took **749.10 s against its 900 s mark** on the last green nightly, so it is fragile regardless and may want its work trimmed or its budget raised once the logs show where the time goes. ### Usage ```python # unchanged public API run_example_command(cmd_parts, example_path="llm_eval") ``` ### Testing Verified against the reproducer above and on the normal paths: | scenario | before | after | | --- | --- | --- | | launcher SIGKILLed, survivor holds the pipe | blocks indefinitely (900 s in CI) | `rc=-9` in 3.5 s, `'launcher output'` captured | | the surviving descendant | keeps running | killed with the process group (stopped ticking, 20 -> 20 bytes) | | normal exit | ok | `rc=0`, stdout and stderr interleaved in order | | non-zero exit | ok | `rc=3`, output captured | The example-test suites that use this helper run through the same code path; `tests/examples/megatron_bridge` (16 passed, 1 skipped) exercised it on nemo:26.08 in the branch this was extracted from. ### Before your PR is "*Ready for review*" - Is this change backward compatible?: ✅ — `_run_capturing` keeps its `(returncode, output)` contract; only the buffering strategy changed. - If you copied code from any other sources or added a new PIP dependency, did you follow guidance in `CONTRIBUTING.md`: N/A - Did you write any new necessary tests?: ❌ — this is test infrastructure; the scenario needs a process that outlives a SIGKILLed parent, which is awkward to assert in CI. Verified manually with the reproducer above. - Did you update [Changelog](https://github.com/NVIDIA/Model-Optimizer/blob/main/CHANGELOG.rst)?: N/A — test-infrastructure fix. - Did you get Claude approval on this PR?: ❌ 🤖 Generated with [Claude Code](https://claude.com/claude-code)  ## Summary by CodeRabbit * **Bug Fixes** * Improved command execution reliability with real-time output capture. * Ensured lingering child processes are cleaned up after commands exit or are interrupted. * Added warnings when forced cleanup may truncate output. * Prevented hangs when descendant processes keep output streams open. * **Documentation** * Updated MMLU setup instructions to use the Hugging Face dataset repository. * Improved Windows instructions by explicitly using `curl.exe`. * **Examples** * Improved MMLU downloads with retries, separate timeouts, resume support, and automatic temporary-file cleanup.  --- ### Update: the second half of the failure With the streaming fix in place, the next CI run showed the *actual* cause, which the old code had been hiding. That run blocked in `process.wait()` with `<Popen: returncode: None ...>` — child alive and working, not the previous dead-child pipe deadlock — and the now-visible output was: ``` --2026-08-27 18:09:20-- (try: 4) https://people.eecs.berkeley.edu/~hendrycks/data.tar Connecting to people.eecs.berkeley.edu ...|128.32.139.28|:443... failed: Connection timed out. Retrying. --2026-08-27 18:11:40-- (try: 5) ... ``` `huggingface_example.sh` downloads the MMLU tarball from `people.eecs.berkeley.edu`, that host stopped answering around 2026-08-25, and wget's default retry policy (20 tries, ~2 min per connect timeout) consumed the whole 900 s budget. Not runner-specific: the URL also times out from a developer workstation, and the nightlies flipped 08-24 ✅ / 08-25 ✅ / **08-26 ❌ / 08-27 ❌**, matching the outage. So this PR now carries both halves of the same failure: 1. the harness no longer deadlocks and no longer swallows the logs (`985809cc2d`), and 2. the MMLU data comes from HuggingFace's copy of the same tarball, with bounded retries (`40f1d89154`). The mirror is byte-for-byte the same dataset in the same layout the script already expects — verified by running the exact download/extract commands: ``` https://huggingface.co/datasets/cais/mmlu/resolve/main/data.tar -> HTTP 200, 166 MB data/mmlu/{dev,test,val}/ -> 57 subject CSVs each, plus auxiliary_train/ ``` `wget --timeout=20 --tries=3` plus an explicit error means the next dataset-host outage fails in about a minute with "Could not download the MMLU test data. Set MMLU_DATA_PATH to a local copy." instead of silently eating a test's timeout. The same URL is updated in `examples/llm_eval/README.md` so a manual run does not hit the dead host either. --------- Signed-off-by: Keval Morabia <28916987+kevalmorabia97@users.noreply.github.com> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-10-02 03:14:52 +08:00 · 2026-08-28 21:38:25 +05:30
parent 5500999d0b
commit 6a2ae5a25b
5 changed files with 144 additions and 9 deletions
@@ -318,9 +318,20 @@ if [[ $TASKS =~ "mmlu" ]]; then
    fi
    if [[ ! -d "$MMLU_DATA_PATH" ]] || [[ ! $(ls -A $MMLU_DATA_PATH) ]]; then
        echo "Preparing the MMLU test data"
-        wget https://people.eecs.berkeley.edu/~hendrycks/data.tar -O /tmp/mmlu.tar
+        MMLU_TAR="$(mktemp "${TMPDIR:-/tmp}/mmlu.XXXXXX")" || exit 1
+        trap 'rm -f "$MMLU_TAR"' EXIT
+        # Revision-pinned HuggingFace mirror of the Berkeley tarball, which is unreachable. Bound
+        # the retries, which otherwise outlast the callers' timeouts, and resume rather than refetch.
+        wget --connect-timeout=20 --read-timeout=60 --tries=3 -c \
+            https://huggingface.co/datasets/cais/mmlu/resolve/c30699e8356da336a370243923dbaf21066bb9fe/data.tar \
+            -O "$MMLU_TAR" || {
+            echo "[ERROR] Could not download the MMLU test data. Set MMLU_DATA_PATH to a local copy."
+            exit 1
+        }
        mkdir -p data
-        tar -xf /tmp/mmlu.tar -C data && mv data/data $MMLU_DATA_PATH
+        tar -xf "$MMLU_TAR" -C data && mv data/data $MMLU_DATA_PATH
+        rm -f "$MMLU_TAR"  # 166MB; do not hold it for the rest of the eval
+        trap - EXIT
    fi

    mmlu_flags=""
@@ -155,7 +155,8 @@ Download data

 ```bash
 mkdir -p data
-wget https://people.eecs.berkeley.edu/~hendrycks/data.tar -O data/mmlu.tar
+wget --connect-timeout=20 --read-timeout=60 --tries=3 -c \
+    https://huggingface.co/datasets/cais/mmlu/resolve/c30699e8356da336a370243923dbaf21066bb9fe/data.tar -O data/mmlu.tar
 tar -xf data/mmlu.tar -C data && mv data/data data/mmlu
 cd ..
 ```
@@ -41,7 +41,7 @@ The table below lists the setup steps to prepare your environment for evaluating
 | **Install PyTorch and Related Packages** | `pip install torch==2.7.0 torchvision==0.22.0 torchaudio==2.7.0 --index-url https://download.pytorch.org/whl/cu128` |
 | **Install ONNX Runtime Packages** | `pip install onnxruntime-directml==1.21.1` <br> `pip install onnxruntime-genai-directml==0.6.0` |
 | **Install Benchmark Requirements** | `pip install -r requirements.txt` |
-| **Download MMLU Data** | `mkdir data` <br> `curl -o .\data\mmlu.tar https://people.eecs.berkeley.edu/~hendrycks/data.tar` <br> `tar -xf .\data\mmlu.tar -C .\data` <br> `Move-Item .\data\data .\data\mmlu` |
+| **Download MMLU Data** | `mkdir data` <br> `curl.exe -L -o .\data\mmlu.tar https://huggingface.co/datasets/cais/mmlu/resolve/c30699e8356da336a370243923dbaf21066bb9fe/data.tar` <br> `tar -xf .\data\mmlu.tar -C .\data` <br> `Move-Item .\data\data .\data\mmlu` |

 ### Evaluation Methods

@@ -14,8 +14,11 @@
 # limitations under the License.
 """Utility functions for running example commands reused in multiple example tests."""

+import contextlib
 import os
+import signal
 import subprocess
+import threading
 import time
 import warnings
 from pathlib import Path
@@ -61,13 +64,76 @@ def extend_cmd_parts(cmd_parts: list[str], **kwargs):
    return cmd_parts


+# Grace period for descendants to flush and close the inherited output pipe after the command exits,
+# then a short bound on the post-SIGKILL drain (the fds close as the kernel tears the group down).
+_ORPHAN_PIPE_TIMEOUT_S = 30
+_KILLED_PIPE_TIMEOUT_S = 5
+
+
 def _run_capturing(cmd_parts: list[str], cwd: Path, env: dict[str, str]) -> tuple[int, str]:
-    """Run a command, capturing combined stdout/stderr to catch transient HF errors."""
-    result = subprocess.run(
-        cmd_parts, cwd=cwd, env=env, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True
+    """Run a command, streaming and capturing combined stdout/stderr to catch transient HF errors.
+
+    Drained by a reader thread rather than ``subprocess.run``, which waits for EOF: a descendant
+    outliving the command keeps the pipe open, hanging the read and discarding every log line.
+    """
+    chunks: list[str] = []
+    process = subprocess.Popen(
+        cmd_parts,
+        cwd=cwd,
+        env=env,
+        stdout=subprocess.PIPE,
+        stderr=subprocess.STDOUT,
+        text=True,
+        start_new_session=True,
    )
-    print(result.stdout, end="")
-    return result.returncode, result.stdout
+    # start_new_session makes the child its own group leader, so the group id is its pid (read now:
+    # os.getpgid() stops resolving it once wait() reaps the child).
+    pgid = process.pid
+
+    def _kill_process_group():
+        with contextlib.suppress(ProcessLookupError, PermissionError):
+            if os.name == "posix":
+                os.killpg(pgid, signal.SIGKILL)
+            else:  # no process groups; the command itself is the best we can reach
+                process.kill()
+
+    def _drain():
+        with contextlib.suppress(ValueError):  # the stream is closed under us on the escape path
+            for line in process.stdout:  # type: ignore[union-attr]
+                print(line, end="")
+                chunks.append(line)
+
+    reader = threading.Thread(target=_drain, daemon=True)
+    reader.start()
+    try:
+        if os.name == "posix":
+            # Wait *without* reaping: a reaped pid can be recycled, and pgid == the child's pid, so
+            # reaping before the kill below would risk signalling an unrelated group.
+            os.waitid(os.P_PID, process.pid, os.WEXITED | os.WNOWAIT)
+        else:  # no process groups, so nothing to protect the pid for
+            process.wait()
+    except BaseException:
+        # Interrupted (most likely pytest-timeout) while the command runs: its own process group is
+        # not swept up with pytest's, so take the descendants down rather than leak them.
+        _kill_process_group()
+        with contextlib.suppress(Exception):
+            process.wait(timeout=_KILLED_PIPE_TIMEOUT_S)  # reap: WNOWAIT left it waitable
+        raise
+    reader.join(_ORPHAN_PIPE_TIMEOUT_S)
+
+    if reader.is_alive():
+        warnings.warn(
+            f"{cmd_parts[0]} left descendants holding its output pipe open; killing the process "
+            "group. Output may be truncated."
+        )
+        _kill_process_group()
+        reader.join(_KILLED_PIPE_TIMEOUT_S)
+
+    returncode = process.wait()
+
+    with contextlib.suppress(Exception):
+        process.stdout.close()  # type: ignore[union-attr]
+    return returncode, "".join(chunks)


 def run_example_command(
@@ -0,0 +1,57 @@
+# SPDX-FileCopyrightText: Copyright (c) 2024 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
+# SPDX-License-Identifier: Apache-2.0
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+"""Tests for the example-command runner shared by the example tests."""
+
+import contextlib
+import os
+import signal
+import time
+
+import pytest
+from _test_utils.examples import run_command
+
+
+def test_run_capturing_does_not_block_on_a_survivor_holding_the_pipe(
+    skip_on_windows, monkeypatch, tmp_path
+):
+    """A killed command whose descendant inherited the output pipe must not hang the caller."""
+    monkeypatch.setattr(run_command, "_ORPHAN_PIPE_TIMEOUT_S", 1)
+    pid_file = tmp_path / "survivor.pid"
+
+    started = time.monotonic()
+    with pytest.warns(UserWarning, match="descendants holding its output pipe"):
+        returncode, output = run_command._run_capturing(
+            ["bash", "-c", f"sleep 60 & echo $! > {pid_file}; echo out; sleep 0.3; kill -9 $$"],
+            tmp_path,
+            os.environ.copy(),
+        )
+
+    survivor = int(pid_file.read_text())
+    try:
+        assert returncode == -9
+        assert "out" in output  # captured despite the survivor
+        assert time.monotonic() - started < 10  # the patched grace period is 1s
+
+        for _ in range(50):  # the group kill is asynchronous
+            try:
+                os.kill(survivor, 0)
+            except ProcessLookupError:
+                break
+            time.sleep(0.1)
+        else:
+            pytest.fail(f"survivor {survivor} outlived _run_capturing")
+    finally:
+        with contextlib.suppress(ProcessLookupError):
+            os.kill(survivor, signal.SIGKILL)