Skip to content

[DO NOT MERGE] Probe hang stack dump against a live Kit process - #7153

Closed
mataylor-nvidia wants to merge 4 commits into
isaac-sim:developfrom
mataylor-nvidia:mataylor/hang-stack-dump-ci-probe
Closed

[DO NOT MERGE] Probe hang stack dump against a live Kit process#7153
mataylor-nvidia wants to merge 4 commits into
isaac-sim:developfrom
mataylor-nvidia:mataylor/hang-stack-dump-ci-probe

Conversation

@mataylor-nvidia

Copy link
Copy Markdown
Contributor

Description

Do not merge. Throwaway CI probe for #7152, branched off it. Revert by deleting the marked block and the _probe_wedge() call.

What this proves

#7152 adds three regression tests that spawn a genuinely hung child and assert the stack dump appears. Those cover the mechanism, but the child is a toy python process with one thread.

What they cannot cover is the part that actually matters here: does a real Isaac Sim process answer SIGUSR1? Kit runs dozens of native threads, installs its own signal handling, and parks the main thread inside C++ calls that never return to the interpreter loop. If Kit blocked or claimed SIGUSR1, the feature would pass CI and still be useless on the hangs it was built for.

This probe wedges test_rendering_cartpole.py after its first case has really rendered — so Kit is fully initialized, has produced actual frames, and all its threads are live at the moment the signal arrives.

Note the injection is a hang, not a kill. Killing Kit produces a crash, and crashes already printed stacks before #7152PYTHONFAULTHANDLER=1 covers SIGSEGV/SIGABRT. The gap being closed is specifically hangs.

Expected result

The rendering-correctness job should show test_rendering_cartpole.py killed for timeout, with both the job log and the JUnit report carrying:

=== HANG STACK DUMP (all threads) ===
----- dump 1 of 2 -----
Current thread 0x... (most recent call first):
  File ".../threading.py", line 355 in wait
  File ".../test_rendering_cartpole.py", line ... in _probe_wedge
  File ".../test_rendering_cartpole.py", line ... in test_rendering_cartpole
  ...
Thread 0x... (most recent call first):
  <Kit's own threads>

Two things to check:

  1. _probe_wedge is named, and the frames below it are the real pytest/Kit call chain — the diagnostic that did not exist before.
  2. Kit's other threads appear as additional Thread 0x... blocks. That is the evidence faulthandler.register walks a live Kit process, not just the main thread.

The two dumps should be identical, which is the intended "wedged, not slow" signal.

Cost and blast radius

test_rendering_cartpole.py carries no PER_TEST_TIMEOUTS entry, so it runs on DEFAULT_TIMEOUT (1000 s) plus the 700 s cold-cache buffer it earns as the first enable_cameras=True file — roughly 28 minutes before the dump fires, against the job's 120-minute budget. Left at the defaults deliberately so the probe exercises the real configuration.

The orchestrator runs each file in its own process, so only test_rendering_cartpole.py is affected; the other six rendering files in the job run normally afterward. test-rendering-correctness is continue-on-error on pull requests, so a red result here does not block.

Before

The same hang on develop produces:

=== SYSTEM DIAGNOSTICS ===
--- nvidia-smi ---
...
--- process tree (ps auxf) ---

No stack, anywhere. That is the gap #7152 closes.

Type of change

  • This change requires a documentation update

Checklist

  • I have run the pre-commit checks with ./isaaclab.sh --format
  • I have made corresponding changes to the documentation
  • My changes generate no new warnings
  • I have added tests that prove my fix is effective or that my feature works
  • I have updated the changelog and the corresponding version in the extension's config/extension.toml file
  • I have added my name to the CONTRIBUTORS.md or my name already exists there

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.
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.
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.
@mataylor-nvidia
mataylor-nvidia force-pushed the mataylor/hang-stack-dump-ci-probe branch from 13f9fad to 774826b Compare August 19, 2026 16:28
@mataylor-nvidia

Copy link
Copy Markdown
Contributor Author

Run 1 result: the probe worked, and it found a real bug

The wedge landed exactly where intended, and the hang was detected on schedule — but no stack dump was produced:

22:41:24  collected 33 items
22:41:48  test_rendering_cartpole[physx-isaacsim_rtx-rgb] PASSED
23:05:02  test_rendering_cartpole[physx-isaacsim_rtx-albedo]      <- wedged mid-case
          Test .../test_rendering_cartpole.py timed out after 1700 seconds...
          --- nvidia-smi ---

nvidia-smi follows the timeout line directly, so pre_kill_diag was empty.

Root cause

pytest captures at the file-descriptor level. It dup2s fd 2 to a temp file, so
faulthandler.register(file=sys.__stderr__) — which stores fileno() = 2 — wrote the dump into pytest's
capture buffer, which is discarded when the process is SIGKILLed. That is the only case the dump is ever
written in.

The decisive evidence is this probe's own [CI PROBE] wedging marker: a plain print(..., file=sys.__stderr__)
with no signal involved, and it never reached the log either. So fd 2 is captured regardless of the dump path.

The regression tests in #7152 missed this because they hung a bare python script.py child, which has no
capture, so the dump reached stderr and they passed.

Fix

#7152 now writes the dump to a file named by ISAACLAB_HANG_DUMP, set per test file and cleared per attempt,
mirroring the crash journal's ISAACLAB_TEST_JOURNAL — and for the same reason tools/ovrtx_log.py keeps the
renderer log in a file. Its tests now hang a real python -m pytest child; against the previous
implementation all three fail on assert 'HANG STACK DUMP' in ''.

Also added the isaaclab_tasks changelog fragment this branch was missing.

Re-running to confirm the dump appears.

Worth noting

Two things did work on run 1: the timeout fired at exactly 1700 s (1000 DEFAULT_TIMEOUT + 700 cold-cache
buffer) as predicted, and the crash journal recovered all 33 verdicts from the killed process
(recovered 33 test result(s) from the crash journal).

kellyguo11 pushed a commit that referenced this pull request Aug 29, 2026
# Description

A test that **crashes** reports a traceback, because
`PYTHONFAULTHANDLER=1` installs `faulthandler` for `SIGSEGV` and
friends. A test that **hangs** reports nothing.

Hang *detection* already works — `tools/conftest.py` catches three
kinds:

| Kind | Trigger | Constant |
|---|---|---|
| `startup_hang` | no `AppLauncher initialization complete` / `collected
` marker | `STARTUP_DEADLINE = 120` s |
| `timeout` | wall clock exceeds the per-file budget | `DEFAULT_TIMEOUT
= 1000` s |
| `shutdown_hang` | JUnit report written, process still alive |
`SHUTDOWN_GRACE_PERIOD = 30` s |

The problem is what happens next: all three escalate straight to
`os.killpg(pgid, SIGKILL)`. `SIGKILL` cannot be caught, so nothing gets
a chance to dump. The report carries `nvidia-smi`, `ps auxf`, `dmesg`
and the last `-v` test name — nothing pointing at the hung code.

The repo already records the symptom in a skip reason: *"Native hang:
the per-file CI runner kills the suite after 1000s with no pytest
outcome"* (`source/isaaclab_tasks/test/rendering_test_utils.py`).

This complements the crash journal (#7005): that recovers **which
tests** had passed when a process died; this reports **where the process
is stuck**.

## Change

The runner asks the process where it is stuck before killing it.

- **`tools/hang_dump.py`** (new) — pytest plugin registering `SIGUSR1`
via `faulthandler.register()`, writing 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`. No-ops
where the signal does not exist.

The dump has to go to a **file**, not stderr. pytest captures at the
file-descriptor level, so it has already redirected fd 2 by the time the
plugin loads; a dump written there is discarded when the process is
`SIGKILL`ed — the only case it is ever written in. The first revision of
this PR wrote to `sys.__stderr__` and produced no dump in CI at all,
which #7153 caught. `tools/ovrtx_log.py` keeps the renderer log in a
file for the same reason.
- **`conftest.py`** — loads it via `pytest_plugins`, covering every
suite.
- **`tools/conftest.py`** — `_dump_hung_process_stacks()` signals the
process and drains its output before the existing `SIGKILL`, prepending
the result to `pre_kill_diag`. The fd-drain block was extracted into
`_drain_ready_output()` so the watchdog loop and the dump path share one
implementation. `pre_kill_diag` is now also threaded into
`_make_missing_report_result`, so a fresh-process retry that hangs
reports its stack too.

The dump is taken twice — identical stacks seconds apart are what
distinguish a wedged process from a slow one.

Report plumbing is otherwise unchanged: `pre_kill_diag` already flows
into the `startup_hang` and `timeout` reports and the retry warnings,
and the drain echoes to stdout/stderr, so the stack also streams live to
the job log. Prepending rather than appending matters —
`_get_diagnostics` truncates with `diag[:10000]`, so the stack survives
and the system tables get trimmed instead.

## Artifact

The dump reached CI only through `pre_kill_diag`, which
`_get_diagnostics` truncates to 10 000 characters — and a Kit process
has enough threads to exceed that, so the part worth reading was the
part being cut. The dumps are now written to `tests/hang-dumps/` and
collected as a `hang-dumps-<container>` artifact, alongside the existing
`comparison-images` and `ovrtx-logs` ones. The reports and the job log
still carry the (truncated) dump; the artifact is the whole thing. It is
absent unless something hung, which `if-no-files-found: ignore` already
covers.

## Why `SIGUSR1`

`SIGTERM` and `SIGABRT` are unusable here. `AppLauncher` binds both to
`_on_abort_signal`, which calls `SimulationApp.close()` — itself what a
shutdown hang is stuck inside — so either would re-enter the hang.
Binding `SIGABRT` also displaces `faulthandler`'s own handler.

A Python-level `signal` handler would not run regardless: those execute
between bytecodes, and a thread wedged in a native Kit, CUDA, or
renderer call never returns to the interpreter loop.
`isaaclab.cli.multigpu` documents the same constraint when reaping
stragglers.

`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. `SIGUSR1` is unused anywhere in `source/`,
`tools/`, `scripts/`, `.github/`.

## Sample output

Against a process blocked in `threading.Event().wait()`:

```
=== HANG STACK DUMP (all threads) ===
----- dump 1 of 2 -----
Current thread 0x000073f05cc49080 (most recent call first):
  File "/usr/lib/python3.12/threading.py", line 355 in wait
  File "<string>", line 8 in wedged_call
```

## Type of change

- Bug fix (non-breaking change which fixes an issue)

## Release backport

- [x] <!-- backport-active-release --> Backport this pull request to the
active release branch after it merges into `develop`

## Screenshots

Not applicable.

## Checklist

- [x] I have run the [`pre-commit` checks](https://pre-commit.com/) with
`./isaaclab.sh --format`
- [x] I have made corresponding changes to the documentation
- [x] My changes generate no new warnings
- [x] I have added tests that prove my fix is effective or that my
feature works
- [x] I have updated the changelog and the corresponding version in the
extension's `config/extension.toml` file
- [x] I have added my name to the `CONTRIBUTORS.md` or my name already
exists there

## Testing

One regression test added to
`test_test_orchestrator_result_handling.py`, exercising the **real**
`capture_test_output_with_timeout` against a genuinely hung child. It
asserts every property of the dump — the stack names the hung call, more
than one dump is taken, and the stack precedes the system tables —
because each is a facet of the same `pre_kill_diag` and each costs a
real timeout to reproduce separately. Confirmed it fails without the
change on the meaningful assertion (`assert 'HANG STACK DUMP' in ''`),
not on a missing constant.

It skips on Windows, where the orchestrator's process handling (`select`
on pipes, `os.killpg`, `start_new_session`) is unavailable.

### CI cost

The three hang tests each waited out a 15 s timeout, costing the Isaac
Sim suite about a minute for coverage that needs no GPU.
`test_test_orchestrator_result_handling.py` is now listed in
`TESTS_TO_SKIP`, so the whole file is out of CI; the skip entry records
the command to run it on demand when changing the orchestrator.

Note this also takes the file's pre-existing tests (crash-journal
blaming, retry semantics, renderer-log bounds, result summary) out of
CI.

The hang tests are also folded into one, so a local run is not a minute
either. The remaining test still has to sit through a real timeout, so
that timeout is sized to what the child actually needs: measured ~1.4 s
idle and ~2.6 s with eight spawned at once, against a budget of 8 s.
Whole file measured at 15 passed, 1 skipped in 2.9 s on Windows.

#7153 is a throwaway probe branched off this one, wedging a rendering
correctness test so CI exercises the dump against a live Kit process
with all its threads running.

## Scope

Deliberately excluded:

- **No native C++ frames** (no `py-spy`/`gdb`). Python stacks stop at
the C boundary, so a Kit shutdown hang reads as `_close_app` →
`SimulationApp.close()` without naming the RTX/PhysX call. Still
localizes the hang to a test and a call site.
- **No change to pass/fail classification** — `passed (shutdown hanged)`
stays a pass, so nothing goes red as a side effect.
- **Still uncovered:** `docker wait` in `run_tests.sh` has no deadline,
so a container hanging *above* pytest is caught only by the 180-minute
job timeout.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

infrastructure isaac-lab Related to Isaac Lab team

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant