From 5764d22f23ef8b5025d2ba8de571e3b915e24c2b Mon Sep 17 00:00:00 2001 From: Matthew Taylor Date: Tue, 18 Aug 2026 16:48:29 -0400 Subject: [PATCH 1/4] Dump thread stacks before killing a hung test A test that crashes reported a traceback, because PYTHONFAULTHANDLER=1 installs faulthandler for SIGSEGV and friends. A test that hung reported nothing: the runner detects the hang and kills the process group with SIGKILL, which cannot be caught, so no handler ever ran. The report carried system tables and the last -v test name, and nothing that points at the hung code. The runner now asks the process where it is stuck before killing it. tools/hang_dump.py registers SIGUSR1 with faulthandler.register, and capture_test_output_with_timeout signals the process and drains the dump into pre_kill_diag, which already flows into the startup_hang, timeout, and shutdown_hang reports. The dump is taken twice: identical stacks seconds apart are what tell a wedged process from a slow one. SIGTERM and SIGABRT cannot be used for this. AppLauncher binds both to a handler that calls SimulationApp.close(), which is itself what a shutdown hang is stuck inside, so either would re-enter the hang. A Python-level signal handler would not run regardless, since those execute between bytecodes and a thread wedged in a native Kit, CUDA, or renderer call never returns to the interpreter loop. faulthandler.register installs a C-level handler that walks every thread from inside the signal handler, so it reports a process whose GIL will never be released. --- conftest.py | 5 +- .../changelog.d/mataylor-hang-stack-dump.skip | 0 .../test_test_orchestrator_result_handling.py | 104 ++++++++++- tools/conftest.py | 165 +++++++++++++++--- tools/hang_dump.py | 64 +++++++ 5 files changed, 314 insertions(+), 24 deletions(-) create mode 100644 source/isaaclab/changelog.d/mataylor-hang-stack-dump.skip create mode 100644 tools/hang_dump.py diff --git a/conftest.py b/conftest.py index 393c36bff568..f499a0e64c11 100644 --- a/conftest.py +++ b/conftest.py @@ -19,7 +19,8 @@ e.g. ``pytest -m unit source/isaaclab/test`` or ``pytest -m "not unit" source/isaaclab/test``. Also loads ``tools/ovrtx_log.py``, which replays the OVRTX renderer log per test, so every suite that -builds a renderer reports what it logged the same way. +builds a renderer reports what it logged the same way, and ``tools/hang_dump.py``, which lets the CI +runner ask this process for a stack dump before it kills it for hanging. """ from __future__ import annotations @@ -27,7 +28,7 @@ import json import os -pytest_plugins = ["tools.ovrtx_log"] +pytest_plugins = ["tools.ovrtx_log", "tools.hang_dump"] JOURNAL_ENV_VAR = "ISAACLAB_TEST_JOURNAL" """Environment variable naming the crash-journal file. Unset (the default) disables journaling.""" diff --git a/source/isaaclab/changelog.d/mataylor-hang-stack-dump.skip b/source/isaaclab/changelog.d/mataylor-hang-stack-dump.skip new file mode 100644 index 000000000000..e69de29bb2d1 diff --git a/source/isaaclab/test/cli/test_test_orchestrator_result_handling.py b/source/isaaclab/test/cli/test_test_orchestrator_result_handling.py index 0fc66832cd6f..b8eb25b76335 100644 --- a/source/isaaclab/test/cli/test_test_orchestrator_result_handling.py +++ b/source/isaaclab/test/cli/test_test_orchestrator_result_handling.py @@ -9,6 +9,8 @@ import importlib.util import json +import os +import signal import sys import xml.etree.ElementTree as ElementTree from pathlib import Path @@ -16,10 +18,22 @@ import pytest +TOOLS_DIR = Path(__file__).resolve().parents[4] / "tools" +"""Repo ``tools/`` directory, holding the orchestrator and the stack-dump plugin it signals.""" + +posix_only = pytest.mark.skipif( + not hasattr(signal, "SIGUSR1"), + reason="the orchestrator's process handling and the stack-dump signal are both POSIX-only", +) +"""Skip on platforms where ``capture_test_output_with_timeout`` cannot run. + +It needs ``select`` on pipes, ``os.killpg``, and ``start_new_session``, and the dump needs ``SIGUSR1``. +""" + def _load_orchestrator_module() -> ModuleType: """Load ``tools/conftest.py`` without registering it as a pytest plugin.""" - module_path = Path(__file__).resolve().parents[4] / "tools" / "conftest.py" + module_path = TOOLS_DIR / "conftest.py" module_name = "isaaclab_test_orchestrator" tools_dir = str(module_path.parent) if tools_dir not in sys.path: @@ -483,3 +497,91 @@ def test_result_summary_includes_fast_failure_after_thirty_slower_files(): assert "Slowest 30 Test Files" not in summary assert "fast_failure.py" in summary assert all(test_path in summary for test_path in test_files) + + +def _write_hanging_script(tmp_path: Path) -> Path: + """Write a script that registers the dump handler and then blocks forever.""" + script = tmp_path / "hangs.py" + script.write_text( + "import sys, threading\n" + f"sys.path.insert(0, {str(TOOLS_DIR)!r})\n" + "import hang_dump\n" + "hang_dump.register()\n" + "print('collected 1 item', flush=True)\n" + "def wedged_call():\n" + " threading.Event().wait()\n" + "wedged_call()\n", + encoding="utf-8", + ) + return script + + +@posix_only +def test_hung_process_report_names_where_it_is_stuck(monkeypatch, tmp_path: Path) -> None: + """A hang must report the stack it is stuck in, not just that it stopped. + + Without a dump the runner escalates straight to ``SIGKILL``, which cannot be caught, and the report + carries only system tables -- nothing that points at the hung code. + """ + orchestrator = _load_orchestrator_module() + # The system tables are captured separately and are slow; this test is about the stack. + monkeypatch.setattr(orchestrator, "_capture_system_diagnostics", lambda: "") + # raising=False so a build without the dump still reaches the assertion below, and fails on the + # missing stack rather than on the missing constant. + monkeypatch.setattr(orchestrator, "HANG_DUMP_GRACE", 1, raising=False) + + _returncode, _stdout, _stderr, kill_reason, _wall_time, pre_kill_diag = ( + orchestrator.capture_test_output_with_timeout( + [sys.executable, str(_write_hanging_script(tmp_path))], timeout=2, env=os.environ.copy() + ) + ) + + assert kill_reason == "timeout" + assert "HANG STACK DUMP" in pre_kill_diag + assert "wedged_call" in pre_kill_diag + + +@posix_only +def test_hung_process_is_dumped_more_than_once(monkeypatch, tmp_path: Path) -> None: + """Repeated dumps are what tell a wedged process apart from a slow one.""" + orchestrator = _load_orchestrator_module() + monkeypatch.setattr(orchestrator, "_capture_system_diagnostics", lambda: "") + # raising=False so a build without the dump still reaches the assertion below, and fails on the + # missing stack rather than on the missing constant. + monkeypatch.setattr(orchestrator, "HANG_DUMP_GRACE", 1, raising=False) + + *_, pre_kill_diag = orchestrator.capture_test_output_with_timeout( + [sys.executable, str(_write_hanging_script(tmp_path))], timeout=2, env=os.environ.copy() + ) + + assert pre_kill_diag.count("----- dump ") > 1 + + +@posix_only +def test_hang_dump_precedes_system_diagnostics(monkeypatch, tmp_path: Path) -> None: + """The stack must sit ahead of the system tables, which ``_get_diagnostics`` truncates off the end.""" + orchestrator = _load_orchestrator_module() + monkeypatch.setattr(orchestrator, "_capture_system_diagnostics", lambda: "=== SYSTEM DIAGNOSTICS BODY ===") + # raising=False so a build without the dump still reaches the assertion below, and fails on the + # missing stack rather than on the missing constant. + monkeypatch.setattr(orchestrator, "HANG_DUMP_GRACE", 1, raising=False) + + *_, pre_kill_diag = orchestrator.capture_test_output_with_timeout( + [sys.executable, str(_write_hanging_script(tmp_path))], timeout=2, env=os.environ.copy() + ) + + assert "HANG STACK DUMP" in pre_kill_diag + assert pre_kill_diag.index("HANG STACK DUMP") < pre_kill_diag.index("SYSTEM DIAGNOSTICS BODY") + + +def test_hang_dump_plugin_is_inert_without_signal_support(monkeypatch) -> None: + """The plugin loads on every platform, so it must no-op where the signal does not exist.""" + if str(TOOLS_DIR) not in sys.path: + sys.path.insert(0, str(TOOLS_DIR)) + import hang_dump + + monkeypatch.setattr(hang_dump, "DUMP_SIGNAL", None) + + assert hang_dump.is_supported() is False + assert hang_dump.register() is False + hang_dump.pytest_configure(config=None) # must not raise diff --git a/tools/conftest.py b/tools/conftest.py index 5873bb5f1f58..47826a5e7201 100644 --- a/tools/conftest.py +++ b/tools/conftest.py @@ -21,6 +21,7 @@ from isaaclab.test.utils import resolve_test_sim_device # Local imports +import hang_dump # isort: skip import ovrtx_log # isort: skip import test_settings as test_settings # isort: skip from crash_journal import JOURNAL_ENV_VAR, create_crash_report # isort: skip @@ -80,6 +81,129 @@ def pytest_ignore_collect(collection_path, config): from the kill. """ +HANG_DUMP_PASSES = 2 +"""Number of stack dumps requested from a hung process before it is killed. + +One dump says where the process is; two taken seconds apart say whether it is +moving. Identical stacks are what distinguishes a wedged process from a slow +one, which the runner cannot tell from wall clock alone. +""" + +HANG_DUMP_GRACE = 3 +"""Seconds spent collecting each dump. + +``faulthandler`` writes its dump from inside the signal handler, so this only +has to cover signal delivery and the write itself. It is spent solely on runs +that are already failing. +""" + +HANG_DUMP_LIMIT_BYTES = 64 * 1024 +"""Maximum bytes of stack dump carried into the report. + +The dump lands in the job log and in the JUnit XML, and a Kit process has +enough threads to make an unbounded dump a problem in both. +""" + + +def _drain_ready_output(process, stdout_fd, stderr_fd, timeout=0.1): + """Read whatever is readable on the child's pipes, echoing it as it arrives. + + Args: + process: The child being read from. + stdout_fd: Read end of the child's stdout, already non-blocking. + stderr_fd: Read end of the child's stderr, already non-blocking. + timeout: Seconds to wait for either pipe to become readable. + + Returns: + Tuple of ``(stdout_bytes, stderr_bytes)`` read in this pass. Both are + echoed to this process's own streams before being returned, so output + reaches the job log while the test is still running. + """ + stdout_chunk = b"" + stderr_chunk = b"" + try: + ready_fds, _, _ = select.select([stdout_fd, stderr_fd], [], [], timeout) + + for fd in ready_fds: + with contextlib.suppress(OSError): + if fd == stdout_fd: + chunk = process.stdout.read(1024) + if chunk: + stdout_chunk += chunk + sys.stdout.buffer.write(chunk) + sys.stdout.buffer.flush() + elif fd == stderr_fd: + chunk = process.stderr.read(1024) + if chunk: + stderr_chunk += chunk + sys.stderr.buffer.write(chunk) + sys.stderr.buffer.flush() + except OSError: + time.sleep(timeout) + return stdout_chunk, stderr_chunk + + +def _dump_hung_process_stacks(process, stdout_fd, stderr_fd): + """Ask a hung process for a stack of every thread, and collect what it writes. + + Sends :data:`hang_dump.DUMP_SIGNAL`, which ``tools/hang_dump.py`` registers with ``faulthandler`` in the + test process. See that module for why the dump cannot be triggered with ``SIGTERM``, ``SIGABRT``, or a + Python-level :mod:`signal` handler. + + The signal goes to the test process itself rather than its group. The handler is registered there, and + a standalone script the test launched as a grandchild has no handler -- ``SIGUSR1`` would simply kill it, + losing it from the process tree the caller has already recorded. + + Args: + process: The hung child. + stdout_fd: Read end of the child's stdout, already non-blocking. + stderr_fd: Read end of the child's stderr, already non-blocking. + + Returns: + Tuple of ``(dump_section, stdout_bytes, stderr_bytes)``. *dump_section* is a report section, or + ``""`` when the process wrote nothing -- the case when it is wedged somewhere the signal cannot be + delivered, or died before it could answer. The byte strings are whatever the child wrote while being + dumped, and belong in the captured streams either way. + """ + stdout_data = b"" + stderr_data = b"" + dumps = [] + + if hang_dump.DUMP_SIGNAL is None: + return "", stdout_data, stderr_data + + for _ in range(HANG_DUMP_PASSES): + try: + os.kill(process.pid, hang_dump.DUMP_SIGNAL) + except OSError: + break + + # faulthandler writes the dump to the child's stderr, so that is the stream it arrives on. + dumped = b"" + deadline = time.time() + HANG_DUMP_GRACE + while time.time() < deadline: + stdout_chunk, stderr_chunk = _drain_ready_output(process, stdout_fd, stderr_fd) + stdout_data += stdout_chunk + stderr_data += stderr_chunk + dumped += stderr_chunk + if dumped: + dumps.append(dumped) + # exit early if the process died + if process.poll() is not None: + break + + if not dumps: + return "", stdout_data, stderr_data + + body = "\n".join( + f"----- dump {index} of {len(dumps)} -----\n{dump.decode('utf-8', errors='replace')}" + for index, dump in enumerate(dumps, start=1) + ) + section = f"=== HANG STACK DUMP (all threads) ===\n{body}" + if len(section) > HANG_DUMP_LIMIT_BYTES: + section = section[:HANG_DUMP_LIMIT_BYTES] + "\n... (truncated)" + return section, stdout_data, stderr_data + def capture_test_output_with_timeout(cmd, timeout, env, startup_deadline=0, report_file=""): """Run a command with timeout and capture all output while streaming in real-time. @@ -155,8 +279,18 @@ def capture_test_output_with_timeout(cmd, timeout, env, startup_deadline=0, repo kill_reason = "timeout" if kill_reason: + # Diagnostics first: they record the process tree while the hung process is still in it. pre_kill_diag = _capture_system_diagnostics() + # Ask the process where it is stuck before killing it -- SIGKILL below cannot be caught, + # so this is the only chance to get a stack out of it. + hang_stacks, dump_stdout, dump_stderr = _dump_hung_process_stacks(process, stdout_fd, stderr_fd) + stdout_data += dump_stdout + stderr_data += dump_stderr + if hang_stacks: + # Ahead of the system tables, which _get_diagnostics truncates off the end. + pre_kill_diag = f"{hang_stacks}\n\n{pre_kill_diag}" + # Kill the entire process group (test + any Kit children). try: os.killpg(pgid, signal.SIGKILL) @@ -171,26 +305,9 @@ def capture_test_output_with_timeout(cmd, timeout, env, startup_deadline=0, repo wall_time = time.time() - start_time return -1, stdout_data, stderr_data, kill_reason, wall_time, pre_kill_diag - try: - ready_fds, _, _ = select.select([stdout_fd, stderr_fd], [], [], 0.1) - - for fd in ready_fds: - with contextlib.suppress(OSError): - if fd == stdout_fd: - chunk = process.stdout.read(1024) - if chunk: - stdout_data += chunk - sys.stdout.buffer.write(chunk) - sys.stdout.buffer.flush() - elif fd == stderr_fd: - chunk = process.stderr.read(1024) - if chunk: - stderr_data += chunk - sys.stderr.buffer.write(chunk) - sys.stderr.buffer.flush() - except OSError: - time.sleep(0.1) - continue + stdout_chunk, stderr_chunk = _drain_ready_output(process, stdout_fd, stderr_fd) + stdout_data += stdout_chunk + stderr_data += stderr_chunk # Drain any output the process wrote before or just after exiting. try: @@ -312,12 +429,16 @@ def _make_missing_report_result( stdout_data, stderr_data, wall_time, + pre_kill_diag="", ): """Build the ``CRASHED`` pass result for a run that exited without writing a JUnit report. Shared by the initial invocation and the fresh-process retries: a retry that dies before ``pytest_sessionfinish`` has no report of its own, and reusing the previous attempt's results would report the run as merely failed and lose the test that took the process down. + + ``pre_kill_diag`` carries the hang stack dump when the process was killed rather than crashed, + which is the case for a fresh-process retry that hung instead of dying. """ if kill_reason: reason = f"Process killed ({kill_reason}) before it produced a report" @@ -325,7 +446,7 @@ def _make_missing_report_result( reason = _signal_description(-returncode) else: reason = f"Process exited with code {returncode} but produced no report" - diag = _get_diagnostics() + diag = _get_diagnostics(pre_kill_diag) logger.warning(f"⚠️ {log_label}: {reason}") logger.info(diag) @@ -912,6 +1033,7 @@ def _run_one_pass( stdout_data=stdout_data, stderr_data=stderr_data, wall_time=wall_time, + pre_kill_diag=pre_kill_diag, ) # -- Report file exists: parse actual test results ----------------- @@ -1008,6 +1130,7 @@ def _run_one_pass( stdout_data=stdout_data, stderr_data=stderr_data, wall_time=wall_time, + pre_kill_diag=pre_kill_diag, ) shutdown_hanged = kill_reason in ("shutdown_hang", "timeout") and not has_test_failures diff --git a/tools/hang_dump.py b/tools/hang_dump.py new file mode 100644 index 000000000000..ec111a76c4f2 --- /dev/null +++ b/tools/hang_dump.py @@ -0,0 +1,64 @@ +# Copyright (c) 2022-2026, The Isaac Lab Project Developers (https://github.com/isaac-sim/IsaacLab/blob/main/CONTRIBUTORS.md). +# All rights reserved. +# +# SPDX-License-Identifier: BSD-3-Clause + +"""On-demand stack dump for a test process the CI runner believes is hung. + +A test that crashes reports a traceback, because ``PYTHONFAULTHANDLER=1`` (set per test file in +``tools/conftest.py``) installs ``faulthandler`` for ``SIGSEGV`` and friends. A test that *hangs* reported +nothing: the runner detects the hang and kills the process group with ``SIGKILL``, which cannot be caught, so +no handler ever ran. This module closes that gap by giving the runner a signal to ask for a stack first. + +Two constraints decide which signal that can be: + +* ``SIGTERM`` and ``SIGABRT`` are unusable. :class:`~isaaclab.app.AppLauncher` binds both to a handler that + calls ``SimulationApp.close()``, which is itself what a shutdown hang is stuck inside, so sending either + re-enters the hang rather than reporting it. Binding ``SIGABRT`` also displaces ``faulthandler``'s own + handler for it. +* A Python-level :mod:`signal` handler would not run anyway. Those execute between bytecodes, and a thread + wedged in a native Kit, CUDA, or renderer call never returns to the interpreter loop -- the same reason + ``isaaclab.cli.multigpu`` escalates to ``SIGKILL`` when reaping stragglers. + +:data:`DUMP_SIGNAL` is therefore ``SIGUSR1``, which nothing else in the repo uses, and it is registered +through :func:`faulthandler.register` rather than :mod:`signal`. That installs a C-level handler which walks +every thread and writes to a file descriptor from inside the handler, so it reports a process whose GIL is +held by a native call that will never release it. +""" + +import faulthandler +import signal +import sys + +DUMP_SIGNAL = getattr(signal, "SIGUSR1", None) +"""Signal the CI runner sends to ask a hung test process for a stack dump. + +``None`` off POSIX. ``tools/conftest.py`` reads this so the sender and the receiver cannot disagree. +""" + + +def is_supported(): + """Return whether this process can register the dump handler. + + :func:`faulthandler.register` and ``SIGUSR1`` are both POSIX-only, and ``sys.__stderr__`` is ``None`` + when the interpreter starts without a real stderr. + """ + return DUMP_SIGNAL is not None and hasattr(faulthandler, "register") and sys.__stderr__ is not None + + +def register(): + """Install the dump handler, and return whether it was installed. + + The dump is written to ``sys.__stderr__`` rather than :data:`sys.stderr` so it survives pytest's capture + and lands on the pipe the runner is already draining -- the same reason ``AppLauncher`` prints its startup + marker there. + """ + if not is_supported(): + return False + faulthandler.register(DUMP_SIGNAL, file=sys.__stderr__, all_threads=True, chain=False) + return True + + +def pytest_configure(config): + """Register the handler before any test imports Kit, so a startup hang is reportable too.""" + register() From e1980d651c773b64aca7d3da7e034b031b1e7048 Mon Sep 17 00:00:00 2001 From: Matthew Taylor Date: Wed, 19 Aug 2026 12:26:44 -0400 Subject: [PATCH 2/4] Write hang stack dumps to a file instead of stderr The dump never reached CI. pytest captures at the file-descriptor level, so it has already pointed fd 2 at a temporary file of its own by the time the plugin loads; faulthandler.register(file=sys.__stderr__) stored fd 2 and wrote there. That buffer is discarded when the process is SIGKILLed, which is the only case the dump is ever written in, so a hung test still reported nothing but system tables. The dump now goes to a file named by ISAACLAB_HANG_DUMP, which the runner sets per test file and clears per attempt, mirroring the crash journal's ISAACLAB_TEST_JOURNAL. pytest does not redirect it, and the runner reads it after the process is gone. This is the same reason tools/ovrtx_log.py keeps the renderer log in a file. The regression tests missed this because they hung a bare `python script.py` child, which has no capture, so the dump reached stderr and they passed. They now hang a real `python -m pytest` child, reproducing the CI failure: against the previous implementation all three fail on `assert 'HANG STACK DUMP' in ''`. Found by the CI probe in the follow-up branch, which wedged a rendering correctness test and produced a timeout report with no stack. --- .../test_test_orchestrator_result_handling.py | 45 +++++------ tools/conftest.py | 44 ++++++----- tools/hang_dump.py | 79 ++++++++++++++++--- 3 files changed, 116 insertions(+), 52 deletions(-) diff --git a/source/isaaclab/test/cli/test_test_orchestrator_result_handling.py b/source/isaaclab/test/cli/test_test_orchestrator_result_handling.py index b8eb25b76335..c5f3966161d4 100644 --- a/source/isaaclab/test/cli/test_test_orchestrator_result_handling.py +++ b/source/isaaclab/test/cli/test_test_orchestrator_result_handling.py @@ -499,21 +499,25 @@ def test_result_summary_includes_fast_failure_after_thirty_slower_files(): assert all(test_path in summary for test_path in test_files) -def _write_hanging_script(tmp_path: Path) -> Path: - """Write a script that registers the dump handler and then blocks forever.""" - script = tmp_path / "hangs.py" - script.write_text( - "import sys, threading\n" - f"sys.path.insert(0, {str(TOOLS_DIR)!r})\n" - "import hang_dump\n" - "hang_dump.register()\n" - "print('collected 1 item', flush=True)\n" - "def wedged_call():\n" - " threading.Event().wait()\n" - "wedged_call()\n", +def _hanging_pytest_run(tmp_path: Path) -> tuple[list[str], dict[str, str]]: + """Return the command and environment for a hung *pytest* process. + + The child has to be pytest, not a bare script. pytest captures at the file-descriptor level, so it has + already redirected fd 2 by the time a test runs; a dump written there is discarded when the process is + killed. A bare script has no such capture and would pass whether or not the dump reaches a file. + """ + test_file = tmp_path / "test_wedges.py" + test_file.write_text( + "import threading\n\n\ndef test_wedges():\n wedged_call()\n\n\ndef wedged_call():\n" + " threading.Event().wait()\n", encoding="utf-8", ) - return script + env = os.environ.copy() + # `-p hang_dump` needs tools/ importable; the orchestrator gets this from the repo-root conftest. + env["PYTHONPATH"] = str(TOOLS_DIR) + os.pathsep + env.get("PYTHONPATH", "") + env["ISAACLAB_HANG_DUMP"] = str(tmp_path / "hangdump.log") + cmd = [sys.executable, "-m", "pytest", "-p", "hang_dump", "-p", "no:cacheprovider", str(test_file)] + return cmd, env @posix_only @@ -530,10 +534,9 @@ def test_hung_process_report_names_where_it_is_stuck(monkeypatch, tmp_path: Path # missing stack rather than on the missing constant. monkeypatch.setattr(orchestrator, "HANG_DUMP_GRACE", 1, raising=False) + cmd, env = _hanging_pytest_run(tmp_path) _returncode, _stdout, _stderr, kill_reason, _wall_time, pre_kill_diag = ( - orchestrator.capture_test_output_with_timeout( - [sys.executable, str(_write_hanging_script(tmp_path))], timeout=2, env=os.environ.copy() - ) + orchestrator.capture_test_output_with_timeout(cmd, timeout=15, env=env) ) assert kill_reason == "timeout" @@ -550,9 +553,8 @@ def test_hung_process_is_dumped_more_than_once(monkeypatch, tmp_path: Path) -> N # missing stack rather than on the missing constant. monkeypatch.setattr(orchestrator, "HANG_DUMP_GRACE", 1, raising=False) - *_, pre_kill_diag = orchestrator.capture_test_output_with_timeout( - [sys.executable, str(_write_hanging_script(tmp_path))], timeout=2, env=os.environ.copy() - ) + cmd, env = _hanging_pytest_run(tmp_path) + *_, pre_kill_diag = orchestrator.capture_test_output_with_timeout(cmd, timeout=15, env=env) assert pre_kill_diag.count("----- dump ") > 1 @@ -566,9 +568,8 @@ def test_hang_dump_precedes_system_diagnostics(monkeypatch, tmp_path: Path) -> N # missing stack rather than on the missing constant. monkeypatch.setattr(orchestrator, "HANG_DUMP_GRACE", 1, raising=False) - *_, pre_kill_diag = orchestrator.capture_test_output_with_timeout( - [sys.executable, str(_write_hanging_script(tmp_path))], timeout=2, env=os.environ.copy() - ) + cmd, env = _hanging_pytest_run(tmp_path) + *_, pre_kill_diag = orchestrator.capture_test_output_with_timeout(cmd, timeout=15, env=env) assert "HANG STACK DUMP" in pre_kill_diag assert pre_kill_diag.index("HANG STACK DUMP") < pre_kill_diag.index("SYSTEM DIAGNOSTICS BODY") diff --git a/tools/conftest.py b/tools/conftest.py index 47826a5e7201..3acff389174f 100644 --- a/tools/conftest.py +++ b/tools/conftest.py @@ -143,12 +143,12 @@ def _drain_ready_output(process, stdout_fd, stderr_fd, timeout=0.1): return stdout_chunk, stderr_chunk -def _dump_hung_process_stacks(process, stdout_fd, stderr_fd): +def _dump_hung_process_stacks(process, stdout_fd, stderr_fd, env): """Ask a hung process for a stack of every thread, and collect what it writes. Sends :data:`hang_dump.DUMP_SIGNAL`, which ``tools/hang_dump.py`` registers with ``faulthandler`` in the test process. See that module for why the dump cannot be triggered with ``SIGTERM``, ``SIGABRT``, or a - Python-level :mod:`signal` handler. + Python-level :mod:`signal` handler, and why it lands in a file rather than on the process's stderr. The signal goes to the test process itself rather than its group. The handler is registered there, and a standalone script the test launched as a grandchild has no handler -- ``SIGUSR1`` would simply kill it, @@ -158,35 +158,38 @@ def _dump_hung_process_stacks(process, stdout_fd, stderr_fd): process: The hung child. stdout_fd: Read end of the child's stdout, already non-blocking. stderr_fd: Read end of the child's stderr, already non-blocking. + env: Environment the child was started with, read for the dump file it was told to write. Returns: Tuple of ``(dump_section, stdout_bytes, stderr_bytes)``. *dump_section* is a report section, or ``""`` when the process wrote nothing -- the case when it is wedged somewhere the signal cannot be - delivered, or died before it could answer. The byte strings are whatever the child wrote while being - dumped, and belong in the captured streams either way. + delivered, or died before it could answer. The byte strings are whatever the child wrote to its own + streams while being dumped, and belong in the captured output either way. """ stdout_data = b"" stderr_data = b"" dumps = [] - if hang_dump.DUMP_SIGNAL is None: + dump_file = env.get(hang_dump.DUMP_PATH_ENV_VAR, "") + if hang_dump.DUMP_SIGNAL is None or not dump_file: return "", stdout_data, stderr_data for _ in range(HANG_DUMP_PASSES): + # Only this pass's share of the file is the dump it asked for. + start = hang_dump.size(dump_file) try: os.kill(process.pid, hang_dump.DUMP_SIGNAL) except OSError: break - # faulthandler writes the dump to the child's stderr, so that is the stream it arrives on. - dumped = b"" + # Keep draining while the handler runs, so a full pipe cannot be what stops it answering. deadline = time.time() + HANG_DUMP_GRACE while time.time() < deadline: stdout_chunk, stderr_chunk = _drain_ready_output(process, stdout_fd, stderr_fd) stdout_data += stdout_chunk stderr_data += stderr_chunk - dumped += stderr_chunk - if dumped: + + if dumped := hang_dump.read_since(dump_file, start): dumps.append(dumped) # exit early if the process died if process.poll() is not None: @@ -195,10 +198,7 @@ def _dump_hung_process_stacks(process, stdout_fd, stderr_fd): if not dumps: return "", stdout_data, stderr_data - body = "\n".join( - f"----- dump {index} of {len(dumps)} -----\n{dump.decode('utf-8', errors='replace')}" - for index, dump in enumerate(dumps, start=1) - ) + body = "\n".join(f"----- dump {index} of {len(dumps)} -----\n{dump}" for index, dump in enumerate(dumps, start=1)) section = f"=== HANG STACK DUMP (all threads) ===\n{body}" if len(section) > HANG_DUMP_LIMIT_BYTES: section = section[:HANG_DUMP_LIMIT_BYTES] + "\n... (truncated)" @@ -284,7 +284,7 @@ def capture_test_output_with_timeout(cmd, timeout, env, startup_deadline=0, repo # Ask the process where it is stuck before killing it -- SIGKILL below cannot be caught, # so this is the only chance to get a stack out of it. - hang_stacks, dump_stdout, dump_stderr = _dump_hung_process_stacks(process, stdout_fd, stderr_fd) + hang_stacks, dump_stdout, dump_stderr = _dump_hung_process_stacks(process, stdout_fd, stderr_fd, env) stdout_data += dump_stdout stderr_data += dump_stderr if hang_stacks: @@ -692,9 +692,11 @@ def _retry_failed_test_in_fresh_process( f"⚠️ {test_file}: failed in subprocess" f" (attempt {process_failure_attempts}/{max_process_failure_retries + 1}), retrying in fresh process..." ) - # The renderer log goes too: a retry that dies has its log quoted in the rebuilt report, and a - # leftover from the previous attempt would be attributed to this one. - for stale_file in (report_file, journal_file, ovrtx_log.LOG_PATH): + # The renderer log and hang dump go too: a retry that dies has both quoted in the rebuilt report, + # and a leftover from the previous attempt would be attributed to this one. + for stale_file in (report_file, journal_file, env.get(hang_dump.DUMP_PATH_ENV_VAR, ""), ovrtx_log.LOG_PATH): + if not stale_file: + continue with contextlib.suppress(FileNotFoundError): os.remove(stale_file) @@ -884,7 +886,11 @@ def _run_one_pass( # pytest creates the report directory in ``pytest_sessionfinish``, which a crashed run never # reaches; without this the journal's first write fails and ``_journal_write`` swallows it. os.makedirs(os.path.dirname(journal_file), exist_ok=True) - pass_env = {**ctx.env, JOURNAL_ENV_VAR: journal_file} + # Absolute for the same reason, and a file rather than the process's stderr because pytest captures + # at the fd level: a dump written to fd 2 is discarded with the rest of the captured output when the + # process is killed, which is the only case it is ever written in. + hang_dump_file = os.path.abspath(f"tests/test-hangdump-{report_slug}{suffix}.log") + pass_env = {**ctx.env, JOURNAL_ENV_VAR: journal_file, hang_dump.DUMP_PATH_ENV_VAR: hang_dump_file} cmd = [ sys.executable, @@ -916,7 +922,7 @@ def _run_one_pass( while True: # Clear the renderer log too: read after the subprocess dies, it is the only renderer output a # crash, hang, or timeout reports, and a leftover would be attributed to the wrong run. - for stale_file in (report_file, journal_file, ovrtx_log.LOG_PATH): + for stale_file in (report_file, journal_file, hang_dump_file, ovrtx_log.LOG_PATH): with contextlib.suppress(FileNotFoundError): os.remove(stale_file) diff --git a/tools/hang_dump.py b/tools/hang_dump.py index ec111a76c4f2..ad519be57c59 100644 --- a/tools/hang_dump.py +++ b/tools/hang_dump.py @@ -24,9 +24,17 @@ through :func:`faulthandler.register` rather than :mod:`signal`. That installs a C-level handler which walks every thread and writes to a file descriptor from inside the handler, so it reports a process whose GIL is held by a native call that will never release it. + +The dump goes to a *file*, not to stderr, for the same reason ``tools/ovrtx_log.py`` keeps the renderer log +in one: pytest captures at the file-descriptor level, so it has already pointed fd 2 at a temporary file of +its own by the time this plugin loads. A dump written there is discarded with the rest of the captured output +when the process is ``SIGKILL``ed, which is exactly the case this module exists to report. Writing to a file +this module owns puts the dump somewhere pytest does not redirect and the runner can read after the process +is gone. """ import faulthandler +import os import signal import sys @@ -36,29 +44,78 @@ ``None`` off POSIX. ``tools/conftest.py`` reads this so the sender and the receiver cannot disagree. """ +DUMP_PATH_ENV_VAR = "ISAACLAB_HANG_DUMP" +"""Environment variable naming the file stacks are dumped to. Unset (the default) disables dumping. + +The runner sets it per test file, mirroring the crash journal's ``ISAACLAB_TEST_JOURNAL``. Leaving it unset +outside CI keeps a local ``pytest`` run from registering a handler nothing will ever signal. +""" + +_dump_file = None +"""Open handle for the dump file, held for the process lifetime. + +``faulthandler`` keeps the file *descriptor*, not the object, so dropping this reference would close the fd +out from under the handler and the dump would go nowhere. +""" + def is_supported(): """Return whether this process can register the dump handler. - :func:`faulthandler.register` and ``SIGUSR1`` are both POSIX-only, and ``sys.__stderr__`` is ``None`` - when the interpreter starts without a real stderr. + :func:`faulthandler.register` and ``SIGUSR1`` are both POSIX-only. """ - return DUMP_SIGNAL is not None and hasattr(faulthandler, "register") and sys.__stderr__ is not None + return DUMP_SIGNAL is not None and hasattr(faulthandler, "register") -def register(): - """Install the dump handler, and return whether it was installed. +def dump_path(): + """Return the configured dump file, or ``""`` when dumping is disabled.""" + return os.environ.get(DUMP_PATH_ENV_VAR, "") + - The dump is written to ``sys.__stderr__`` rather than :data:`sys.stderr` so it survives pytest's capture - and lands on the pipe the runner is already draining -- the same reason ``AppLauncher`` prints its startup - marker there. +def size(path): + """Return the size of ``path`` in bytes, or 0 when it does not exist yet.""" + try: + return os.path.getsize(path) + except OSError: + return 0 + + +def read_since(path, start): + """Return the text appended to ``path`` after ``start`` bytes. + + Args: + path: Dump file to read. + start: Offset the read begins at. A file shorter than this was rewritten, so the offset no longer + describes its contents and the whole file is read instead. + + Returns: + The appended text, or ``""`` when there is none -- the case when the process never answered. """ - if not is_supported(): + if size(path) < start: + start = 0 + try: + with open(path, "rb") as handle: + handle.seek(start) + return handle.read().decode("utf-8", errors="replace") + except OSError: + return "" + + +def register(): + """Install the dump handler, and return whether it was installed.""" + global _dump_file + path = dump_path() + if not path or not is_supported(): + return False + try: + _dump_file = open(path, "w") # noqa: SIM115 (held open for the process lifetime, see above) + except OSError: return False - faulthandler.register(DUMP_SIGNAL, file=sys.__stderr__, all_threads=True, chain=False) + faulthandler.register(DUMP_SIGNAL, file=_dump_file, all_threads=True, chain=False) return True def pytest_configure(config): """Register the handler before any test imports Kit, so a startup hang is reportable too.""" - register() + if not register() and dump_path(): + print(f"[ISAACLAB] hang stack dumps unavailable on {sys.platform}", file=sys.__stderr__, flush=True) From 4891cd1b9b03121a6135d6bf25b3f991fde2d8d7 Mon Sep 17 00:00:00 2001 From: Matthew Taylor Date: Tue, 18 Aug 2026 16:54:20 -0400 Subject: [PATCH 3/4] Add temporary CI probe wedging a rendering correctness test Blocks test_rendering_cartpole.py forever after its first case has really rendered, so CI exercises the hang stack dump against a live Isaac Sim process rather than the toy subprocess the unit tests use. Kit is fully up and all of its threads are running when SIGUSR1 arrives, which is the part the unit tests cannot cover. Expect the file to be killed for "timeout" and its report to carry a HANG STACK DUMP section naming _probe_wedge. Not for merge. --- .../test/core/test_rendering_cartpole.py | 38 +++++++++++++++++++ 1 file changed, 38 insertions(+) diff --git a/source/isaaclab_tasks/test/core/test_rendering_cartpole.py b/source/isaaclab_tasks/test/core/test_rendering_cartpole.py index ce8075cd09fa..75f418f8a10b 100644 --- a/source/isaaclab_tasks/test/core/test_rendering_cartpole.py +++ b/source/isaaclab_tasks/test/core/test_rendering_cartpole.py @@ -31,7 +31,45 @@ _attach_comparison_properties_fixture = make_attach_comparison_properties_fixture(_COMPARISON_SCORES) +# ---------------------------------------------------------------------------------------------------- +# TEMPORARY CI PROBE -- DO NOT MERGE +# +# Wedges this file partway through the run so CI exercises the hang stack dump against a real Isaac Sim +# process: Kit is fully up, has rendered actual frames, and all of its own threads are running when +# SIGUSR1 arrives. The unit tests only prove the mechanism against a toy subprocess; this proves it +# reports a live Kit process, whose main thread is parked in a native call. +# +# Expect: this file is killed for "timeout", and its job log and JUnit report carry a +# "=== HANG STACK DUMP (all threads) ===" section naming _probe_wedge, twice. +# +# Revert by deleting this block and the _probe_wedge() call in test_rendering_cartpole. +# ---------------------------------------------------------------------------------------------------- +import sys # noqa: E402 +import threading # noqa: E402 + +_PROBE_CASES_BEFORE_WEDGE = 1 +"""Cases allowed to render normally before the process is wedged.""" + +_probe_cases_done = 0 + + +def _probe_wedge(): + """Block forever, once enough cases have actually rendered.""" + global _probe_cases_done + _probe_cases_done += 1 + if _probe_cases_done <= _PROBE_CASES_BEFORE_WEDGE: + return + print( + f"[CI PROBE] wedging after {_PROBE_CASES_BEFORE_WEDGE} rendered case(s);" + " expect a hang stack dump naming _probe_wedge", + file=sys.__stderr__, + flush=True, + ) + threading.Event().wait() + + @pytest.mark.parametrize("physics_backend,renderer,data_type", PHYSICS_RENDERER_AOV_COMBINATIONS) def test_rendering_cartpole(physics_backend, renderer, data_type): """Test cartpole environment rendering correctness.""" rendering_test_cartpole(physics_backend, renderer, data_type, _COMPARISON_SCORES, compare_golden=True) + _probe_wedge() # TEMPORARY CI PROBE -- DO NOT MERGE From 774826be0da6867f36ecb4bc62a10263133086f2 Mon Sep 17 00:00:00 2001 From: Matthew Taylor Date: Wed, 19 Aug 2026 12:27:22 -0400 Subject: [PATCH 4/4] Add changelog fragment for the probe's isaaclab_tasks change --- .../changelog.d/mataylor-hang-stack-dump-ci-probe.skip | 0 1 file changed, 0 insertions(+), 0 deletions(-) create mode 100644 source/isaaclab_tasks/changelog.d/mataylor-hang-stack-dump-ci-probe.skip diff --git a/source/isaaclab_tasks/changelog.d/mataylor-hang-stack-dump-ci-probe.skip b/source/isaaclab_tasks/changelog.d/mataylor-hang-stack-dump-ci-probe.skip new file mode 100644 index 000000000000..e69de29bb2d1