Skip to content

Dump the compile traceback before the runner kills the process - #1518

Merged
Jammy2211 merged 1 commit into
mainfrom
feature/jax-compile-dump-below-cap
Aug 23, 2026
Merged

Dump the compile traceback before the runner kills the process#1518
Jammy2211 merged 1 commit into
mainfrom
feature/jax-compile-dump-below-cap

Conversation

@Jammy2211

Copy link
Copy Markdown
Collaborator

Fixes a defect in #1517, found by the measurement #1517 existed to enable. Part of the jax-compile-stall epic; evidence in autolens_workspace_test#271.

The bug

The faulthandler watchdog shipped in #1517 never fired. Its CI default was a flat 300.0 seconds — and the workspace smoke cap is also 300s. The dump timer and the runner's kill timer therefore raced, and the kill won every time. A SIGKILLed process writes no traceback.

This is not theoretical. The first CI use of the watchdog was a re-timing sweep over four quarantined JAX scripts, 5 repeats × 2 Python versions across two repos. 20 of those runs stalled to the cap. All 20 produced heartbeats. None produced a stack:

21:13:50 ... JAX jit compiling vectorized (vmap) likelihood function...
21:14:20 ... JAX jit still compiling ... 30s elapsed...
   ⋮
21:18:20 ... JAX jit still compiling ... 270s elapsed...
##[error]TIMEOUT after 300s — killed the process group.

So #1517 delivered the half that proves a stalled run is alive, and silently dropped the half that says where it is stuck — which is the half phase 3 of the epic actually needs.

The fix

Derive the CI default from BUILD_SCRIPT_TIMEOUT, the per-script cap that the workspace runners and PyAutoHands both enforce, at 80% of it:

BUILD_SCRIPT_TIMEOUT Dump at
300 (smoke) 240s
1800 (release) 1440s
unset / 0 / malformed 240s flat fallback

The fallback matters: computing a fraction of an absent cap would yield 0, which disables the dump — the same silent no-op in a new disguise. An explicit PYAUTOFIT_JAX_COMPILE_DUMP_SECS still overrides everything.

Verification

Full suite 2011 passed, 34 skipped. test_jax_compile.py 19 passed, 4 new — including one that pins the invariant directly rather than testing today's numbers:

for cap in ("300", "1800", "60"):
    monkeypatch.setenv("BUILD_SCRIPT_TIMEOUT", cap)
    assert jax_compile.dump_traceback_seconds() < float(cap)

End-to-end, a simulated stall with a 10s cap — the dump now lands at 8s, before the kill at 12s:

21:31:37 ... JAX jit still compiling ... 3s elapsed...
21:31:40 ... JAX jit still compiling ... 6s elapsed...
Timeout (0:00:08)!
  File ".../autofit/non_linear/jax_compile.py", line 254 in wrapper
[exit 137 — SIGKILL]

Same scenario before this change wrote no traceback at all.

Note on the original review

Nothing in #1517's tests could have caught this. They monkeypatched faulthandler and asserted the timer was armed and cancelled — which it was, correctly. The failure lives in the relationship between two independently-correct timeouts owned by different repos, and only a real run under a real cap exposes it. Hence the new test asserting the relationship rather than the value.


Generated by Claude Code

The watchdog shipped in #1517 never actually dumped. Its CI default was a
flat 300s and the workspace smoke cap is also 300s, so the dump timer and the
runner's kill timer raced and the kill won -- a SIGKILLed process writes no
traceback. Measured: 20 stalled runs across four CI legs produced heartbeats
from every one of them and not a single stack
(autolens_workspace_test#271).

Derive the CI default from BUILD_SCRIPT_TIMEOUT -- the per-script cap the
workspace runners and PyAutoHands both enforce -- at 80% of it, so the
traceback has time to reach stderr before the kill lands. 300s cap dumps at
240s; 1800s cap dumps at 1440s. With no usable cap advertised, fall back to a
flat 240s rather than computing a fraction of zero, which would silently
disable the dump. An explicit PYAUTOFIT_JAX_COMPILE_DUMP_SECS still wins.

Four new tests, one of them pinning the invariant directly: the threshold is
strictly below the cap for every cap.

Verified end-to-end: with a 10s cap the dump fires at 8s and the traceback is
captured, where before nothing was written at all.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015qk7hoavMnFyPtW4toYn8K
@Jammy2211
Jammy2211 merged commit d3625a8 into main Aug 23, 2026
4 checks passed
@Jammy2211
Jammy2211 deleted the feature/jax-compile-dump-below-cap branch August 25, 2026 18:13
Jammy2211 pushed a commit to trexfr-ops/PyAutoFit that referenced this pull request Aug 27, 2026
The first call to a jax.jit/vmap/grad wrapper contains two waits --
trace/lower/compile, then jax.block_until_ready execution -- and the
instrumentation could not tell a stalled run which one it was in.

Two defects, both of which made a stall report the wrong diagnosis:

1. The heartbeat hardcoded "still compiling". A stalled CI run therefore
   logged `JAX jit still compiling ... 1770s elapsed` while its captured
   faulthandler stack sat in jax.block_until_ready. That is positive
   evidence for the wrong cause, and five quarantine markers across the
   two test workspaces were written against it, all calling this an
   "intermittent XLA compile stall". It is not one: compilation completes,
   in ~16s, and execution never returns.

2. The compile/execute split line was emitted only after BOTH halves
   finished. A stalled run never finishes the second, so it reported
   neither number and the split characterised only the healthy case --
   twenty stalled runs could not say that compilation had in fact
   completed.

Now: the compile half is logged the instant func() returns, the heartbeat
moves to naming the materialize half and repeats the compile time on every
beat, and the materialize half is logged on its own when it lands. A run
SIGKILLed at any point after tracing has already said on stderr which half
it was in and how long the other took.

Also extracts _block_until_ready() so the execution half is substitutable
in tests without JAX installed, and so the broad `except Exception` guards
only the optional jax import rather than the wait itself.

No call site changes: all four (Fitness._vmap/_jit/_grad, analysis/latent)
inherit this through log_on_first_compile.

For PyAutoFit#1528 (jax-compile-stall phase 3); follows PyAutoLabs#1517/PyAutoLabs#1518.

Co-Authored-By: Claude <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant