Test crash journal - #7005
Conversation
Greptile SummaryThe PR adds crash-durable pytest journaling and reconstructs JUnit reports when a test process exits before writing its normal report. The current revision preserves a culprit test’s recorded call-phase failure alongside the subsequent crash error.
Confidence Score: 5/5The PR appears safe to merge. No blocking failure remains; the previously reported loss of a culprit test’s recorded assertion failure is fixed by emitting that failure and the crash as separate JUnit cases. Important Files Changed
Flowchart%%{init: {'theme': 'neutral'}}%%
flowchart TD
A[pytest collects selected tests] --> B[Journal collected node IDs and markers]
B --> C[Journal test start]
C --> D[Journal phase outcomes]
D --> E{Process writes normal JUnit report?}
E -->|Yes| F[Use normal pytest report]
E -->|No| G[Read crash journal]
G --> H{Test remains in flight?}
H -->|Yes| I[Preserve recorded phase results and append crash error]
H -->|No| J[Add session shutdown error]
I --> K[Mark unreached tests skipped]
J --> K
K --> L[Write reconstructed JUnit report]
Reviews (3): Last reviewed commit: "Merge branch 'develop' into mataylor/fix..." | Re-trigger Greptile |
There was a problem hiding this comment.
Isaac Lab Review Bot
The crash journal and JUnit reconstruction preserve useful per-test context after subprocess crashes, but two report-fidelity issues need correction: the journal can include tests deselected from the current pass, and aggregation loses phase-specific failure semantics and diagnostics.
- Design and architecture: The producer/consumer split between root pytest hooks, the crash-report rebuilder, and the per-pass runner is coherent and keeps journaling opt-in. However, collection must be recorded after
-k/-mand device-split deselection; otherwise reconstructed reports include tests belonging to other passes as skipped entries. - API: The runner’s existing result tuple and status keys remain compatible, and reconstructed test identities and marker properties are preserved. The generated JUnit contract is not fully compatible with pytest output because setup and teardown failures are currently emitted and counted as ordinary failures rather than errors.
- Implementation: Per-record flushing, retry cleanup, fallback reporting, partial-line handling, and culprit attribution are well implemented and tested. Before merge, collection should use the final selected item set, and result aggregation should retain the phase and diagnostic representation associated with the selected outcome so non-call failures become JUnit errors with the correct text.
Minor fixes needed. Posted 2 actionable findings inline.
Automated review; human maintainers own approval decisions.
The crash journal records the phase each result came from, but _merge_result discarded it, so every failed test was rebuilt as a <failure>. pytest's own JUnit writer emits <error> for a failing setup or teardown and <failure> only for a failing call, so a crash-rebuilt report reclassified broken fixtures as ordinary test failures. Carry the phase that established the worst outcome through the aggregation and branch on it when building the case, so a rebuilt report buckets a case the same way a clean run would. The phase cannot be recovered from the failure text instead: longrepr holds only the traceback, and the "ERROR at setup of ..." header is terminal-reporter output that never reaches the journal.
Keep the culprit's recorded failure. A test that failed its call phase and then took the process down during teardown was rebuilt as a bare crash error, discarding the assertion and traceback the journal had already saved. pytest emits one <testcase> holding every phase's result, so the rebuilt case now carries the journaled failure and the crash error together. Journal the node IDs that will actually run. pytest applies -k/-m deselection from a trylast pytest_collection_modifyitems hook, so the items this file saw still included tests about to be dropped. Since tools/conftest.py splits a run into passes selected by marker and device, a rebuilt crash report emitted every other pass's tests as "not run" skips, inflating the counts and duplicating node IDs whose real verdicts came from the sibling pass. Journal from pytest_collection_finish instead, where session.items is post-deselection. Keep the failure text of the phase that set the worst outcome, so a skipped setup's reason cannot become the body of a later teardown failure.
|
@greptile review |
The end-to-end coverage only killed a process mid-call, which left the other paths the rebuild claims to handle resting on synthetic journals. Add subprocess runs that die at four more points and assert what the journal can still reconstruct: - SIGTERM mid-test, the shape a CI timeout or the OOM reaper produces. The process is torn down asynchronously, so nothing but the per-record flush can survive it. Also checks the markers come back, keeping test_type consistent with a clean run. - A crash in fixture teardown after the call phase already failed, which must report both the assertion failure and the crash. - A crash at session shutdown, which must be blamed on the session rather than on the test that happened to run last. - A kill between collection and the first test, where every collected test must come back as "not run" instead of vanishing. Each asserts pytest wrote no JUnit report first, so everything checked afterwards demonstrably came out of the journal. Verified by disabling _journal_write, which fails all five. Also fold the duplicated test-module scaffolding into helpers.
tools/test_crash_journal.py and tools/test_device_split.py were not executed by any workflow. The orchestrator jobs that pass "test-path: tools" go through tools/conftest.py, whose pytest_sessionstart only scans source/ and scripts/, so it never discovers the tests sitting beside it. Add a path-gated workflow that runs them directly. Both files need only pytest and junitparser, so the job skips the Isaac Sim install and finishes in about a minute. The pytest invocation needs two non-obvious flags, both commented in the workflow: --noconftest, or tools/conftest.py hijacks the session and runs the whole suite instead of these files, and PYTHONPATH=tools, since the tests import the modules under test directly. The files are named explicitly because test_settings.py matches test_*.py without being a test, and tools/test/ needs the full install.
Journal.finished was a set keyed only by node ID, so a node counted as
finished from the moment it finished once. The flaky plugin reruns a test
in-process and each attempt journals its own start and finish, so a crash
during a second attempt left every start matched and culprit returned
None. The run was reported as a clean session shutdown.
The test that killed the process fared worse than being unblamed. flaky
reruns with pytest's report logging suppressed, so the crashing attempt
records no outcome at all, and with no culprit to claim it the rebuild
took the "collected but never reached" branch:
<testcase name="test_retried">
<skipped message="not run: session aborted at session_shutdown"/>
Match starts against finishes one for one instead, walking back from the
most recent start, so the first start without an available finish is the
node still in flight. Also de-duplicate ordered_node_ids, since a retried
node now legitimately appears in started more than once and would
otherwise emit a second <testcase> for the same test.
The regression test drives the real flaky plugin rather than a synthetic
journal: the log-suppression behaviour above is not something to guess at.
Add flaky to the CI job's dependencies so it runs there instead of
skipping itself.
The runner exported "tests/test-journal-<slug>.jsonl" and the repo-root conftest reopens that path on every journal write, from inside the test process. A test that changes directory - monkeypatch.chdir, or a fixture doing the same - therefore sent its verdicts to a journal under the temporary cwd, and once teardown restored the cwd the finish record landed in the real one. The rebuild then saw a start with no result and reported a test that ran and passed as never reached. Also create the report directory before launching the subprocess. pytest creates it in pytest_sessionfinish, which a crashed run never reaches, so on the first pass of a fresh workspace every journal write failed on a missing directory and _journal_write swallowed the error - leaving the crash rebuild with nothing to work from.
A rebuilt report folded a node's setup, call and teardown records into a single verdict and, for the test blamed for the crash, stacked the crash error beside whatever result that fold produced. Both halves lost data. The fold dropped equally severe phases: a test that failed an assertion and then broke its own teardown kept only the assertion, because the teardown failure ranked no worse and the call text was already set. Key the records by node and phase instead. Repeats within one phase still collapse - that is the flaky plugin rerunning a test in-process - so a retried test still emits one entry rather than duplicate IDs. The stacking produced <failure> and <error> inside one <testcase>, which pytest never writes: its own writer opens a second testcase for a teardown error "in order to follow junit schema". The results uploader reads only the first <failure>/<error> child of a case, so the crash and its flag never left the XML, and counting one test with two results made the summary report tests - failures - errors as -1 passed. Emit a testcase per result, the way pytest does, and count them all. A passing phase still contributes no element, only its duration, which is charged to the node's first case. Otherwise a test that passed and then crashed in teardown would report a phantom pass beside its error.
| @@ -0,0 +1,818 @@ | |||
| # Copyright (c) 2022-2026, The Isaac Lab Project Developers (https://github.com/isaac-sim/IsaacLab/blob/main/CONTRIBUTORS.md). | |||
There was a problem hiding this comment.
These tests might be a bit excessive, there's alot that could be merged into one test, or parameterized as well.
| @@ -0,0 +1,341 @@ | |||
| # Copyright (c) 2022-2026, The Isaac Lab Project Developers (https://github.com/isaac-sim/IsaacLab/blob/main/CONTRIBUTORS.md). | |||
The leading underscore placed the module inside ruff's `extend-exclude` glob `_*`, so it was never linted or format-checked. Dropping the prefix brings it under the repo's gates, which surfaced a SIM105 in `_merge_result`: the `try`/`except`/`pass` guarding the duration accumulation is now `contextlib.suppress`.
The suite had grown to 27 test functions with several pairs asserting the
same behaviour from a synthetic journal and again from a real pytest
subprocess. Merge and parameterize them into 11 functions covering 22
cases, with no loss of coverage:
- `junit_names`, the unusable-journal cases, the culprit start/finish
matching, and the two session-crash shapes each become one
parameterized test.
- The repeat-folding and phase-separation tests merge into one journal
exercising all three outcomes across all three phases.
- The standalone markers test folds into the in-flight-culprit test,
whose journal already carried markers but never asserted them.
- The ID-parity, tag-parity, and double-failure subprocess tests merge
into a single clean-run parity test, saving two pytest subprocesses.
- The six crash shapes become a `_CrashCase` table driving one test, with
each scenario's rationale kept as a comment on its parameter.
`_tags_by_case` replaces the previous case helpers. It returns
`{case ID: [result tags per case]}`, so a single comparison checks both
case identity and JUnit bucket, and the call-failure/teardown-error split
is asserted directly instead of being collapsed the way the old helper
did.
|
|
||
| returncode, stdout_data, stderr_data, kill_reason, wall_time, pre_kill_diag = capture_test_output_with_timeout( | ||
| cmd, ctx.timeout, ctx.env, startup_deadline=ctx.startup_deadline, report_file=report_file | ||
| cmd, ctx.timeout, pass_env, startup_deadline=ctx.startup_deadline, report_file=report_file |
There was a problem hiding this comment.
Important — Fresh-process retries bypass crash journaling.
This applies pass_env only to the initial subprocess. Later, _run_one_pass() calls _retry_failed_test_in_fresh_process(..., env=ctx.env), and that helper removes the JUnit report before launching the retry. For the four files in PROCESS_FAILURE_RETRIES_BY_FILE, an initial test failure followed by a SIGKILL/segfault during the fresh-process retry therefore produces neither a retry journal nor a retry report. The helper falls back to the original parsed failure, so the run is reported as FAILED with 0 errors instead of CRASHED, and the actual crash culprit is lost.
I reproduced the two-attempt path: the journal variable was present for the initial invocation, absent for the retry, and the killed retry returned the original 1-failure/0-error status.
Please give each fresh-process retry its own reset journal and route a missing retry report through create_crash_report(). A regression test with “initial attempt fails, retry crashes before writing JUnit” would cover the gap.
There was a problem hiding this comment.
added fix for this
A retry launched by PROCESS_FAILURE_RETRIES_BY_FILE ran without ISAACLAB_TEST_JOURNAL, so a retry killed before pytest wrote its JUnit report produced neither a journal nor a report. The run fell back to the first attempt's parsed results and was reported as FAILED, losing the crash and the test that caused it. Each retry now starts from an empty journal of its own, and a retry that leaves no report is rebuilt through create_crash_report() like the initial invocation.
…thetic-test-ids # Conflicts: # conftest.py # source/isaaclab/test/cli/test_test_orchestrator_result_handling.py # tools/conftest.py
# 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.
Description
Currently when a test crashes unexpectedly all that is surfaced is
setup::copy_failedortest_executionand we lose context of what actually passed, failed and which test causes the crash
Please include a summary of the change and which issue is fixed. Please also include relevant motivation and context.
List any dependencies that are required for this change.
Fixes # (issue)
Type of change
Screenshots
Please attach before and after screenshots of the change if applicable.
Checklist
pre-commitchecks with./isaaclab.sh --formatsource/<pkg>/changelog.d/for every touched package (do not editCHANGELOG.rstor bumpextension.toml— CI handles that)CONTRIBUTORS.mdor my name already exists there