Diagnose a hung parallel job: per-rank watchdog and a roll-call report - #630
Conversation
A collective entered by only some ranks leaves N-1 ranks stopped in the same
frame and one somewhere else. That signature exists only ACROSS the set, so no
rank can see it, and the job sits there until the queue kills it with nothing
in the output to say which rank went the other way.
Two pieces. `uw.mpi.watch` arms a per-rank watchdog: nothing collective, since
by the time anything is stuck the ranks have already split and a probe needing
all of them can only make it worse. Every rank times itself and dumps alone.
`uw.mpi.ranks_agree` is the positive audit, comparing a label so it also
catches ranks that arrive together but by different routes, and naming them.
`underworld3.utilities.hang_report` does the comparison afterwards, which is
the part that turns four stack traces into an answer:
UW_HANG_WATCHDOG=120 mpirun -n 4 python myrun.py
python -m underworld3.utilities.hang_report uw-hang-dumps
ranks [0, 2, 3] stopped at model.py:13 in reduce_the_count
rank [1] stopped at model.py:20 in <module>
=> 3 of 4 ranks are waiting together at model.py:13, and ranks [1] are
somewhere else. That frame is where the collective is; ranks [1] are
where the bug is.
Arming comes from the environment rather than a call in the script, so it is
in force during import and mesh construction -- a rank that diverges before
reaching a `watch()` call reports nothing.
Three measurements shaped this. A Python `threading.Timer` does NOT run while
the main thread is inside MPI: at np=4 against a 4 s block in `comm.allreduce`,
a re-arming 0.5 s timer fired zero times on the blocked ranks while
faulthandler produced all 7 dumps, so reporting has to be in C and the
destination has to be a file descriptor, not a buffer. The main thread is
identified by its outermost frame, not its depth, after a telemetry thread
twelve frames into `requests` was reported as a rank's position. And a rank is
placed by the modal position over its recent dumps, not its last one, which
had put one of four waiting ranks in a group of its own.
Tested by subprocess rather than in-process. faulthandler's `dump_traceback_
later` is a single global slot that pytest's own plugin already owns, and a
rank inside a test framework is one process looking at itself -- the one thing
this analysis cannot be done from. The end-to-end test runs a real four-rank
job that really hangs, lets mpirun kill it, and checks the verdict.
Underworld development team with AI support from Claude Code
Adversarial reviewThe weakest claim is coverage, and it is weak by construction. The watchdog It needs the hang to actually happen, at a rank count that exposes it. np=2 The label is missing exactly where the reader most wants it. It is printed
Grouping is by one frame. Two ranks stopped at the same line via different The environment variable is process-wide and silent when malformed in one What we did not build. No Controls. Both directions throughout: the watchdog is asserted to fire when |
…ot start A CI runner has two cores, so OpenMPI declines to launch four ranks and the job produced no dumps at all -- surfacing as a FileNotFoundError on the dump directory rather than as the reason. The ranks are blocked or asleep for the whole test, so the cores are not the constraint. Underworld development team with AI support from Claude Code
CI runs MPICH, which oversubscribes by default and rejects --oversubscribe outright, taking the whole mpirun invocation down with it -- so the job never started and wrote no dumps. --timeout is OpenMPI-only for the same reason. The MPI family is now detected for the oversubscribe flag, and the time limit is enforced from Python, killing the process group so no rank is orphaned holding a dump file open. The job under test is meant never to finish, so that timeout is its normal exit path rather than an error. Underworld development team with AI support from Claude Code
…634) * Blame the right rank, rather than require every rank to have dumped test_0054's end-to-end check asserted the waiting group was exactly [0, 2, 3]. On an oversubscribed CI runner a rank can be scheduled too little to dump inside the window, and the group came back as [0] -- a true report of a slower machine, not a defect. It went red on development after #630 merged. What the tool has to get right is which rank is BLAMED, so that is what is asserted now: the majority group sits at the collective, rank 1 is not in it, the group contains only ranks that entered it, and rank 1 is named as the odd one out. Requiring a particular number of witnesses tested the scheduler. Underworld development team with AI support from Claude Code * Give the watchdog room past import before judging where the ranks are At a 1.0 s watchdog and a 25 s window the end-to-end check passed here and failed on CI with the majority located in `importlib._bootstrap`: four oversubscribed ranks take longer to `import underworld3` than the watchdog allowed, so the dump file filled with import frames and the job was killed before the collective produced enough dumps to outvote them. The timings were tuned to a workstation. 5 s watchdog, 75 s window. The assertion also now names the frame the ranks were actually found in -- "not at the collective" without saying where cost a CI round trip to diagnose. Underworld development team with AI support from Claude Code
What this is for
A collective entered by only some ranks leaves N-1 ranks stopped in the same
frame and one somewhere else. The signature exists only across the set, so no
rank can see it, and the job sits there until the queue kills it with nothing in
the output naming the rank that went the other way.
#628 catches the cases a static scan can see. It cannot see a collective reached
three frames down through a helper, which is most of them. This catches those,
because it does not reason about the call graph at all --- it observes the
symptom.
Using it
The last line is the point. The majority position is the crime scene, not the
crime: those ranks did nothing wrong, they arrived at a collective and waited.
The rank that is not with them is the one that took the branch.
Arming comes from the environment rather than a call in the script, so it is in
force during import and mesh construction. A rank that diverges or dies before
reaching a
watch()call reports nothing, and "before the script got going"covers a lot of ground.
Pieces
uw.mpi.watch/unwatch/watching/checkpoint--- the per-rankwatchdog. Nothing collective: by the time anything is stuck the ranks have
split, and a probe needing all of them either blocks alongside the others or
becomes one more collective for the divergent rank to miss.
uw.mpi.ranks_agree--- the positive audit. Compares a label, so it alsocatches ranks that arrive together by different routes, and prints which ranks
took which path. Useful for bisection, because ranks hang at the first
collective after the branch that split them, which is routinely unrelated
code.
underworld3.utilities.hang_report--- the roll call.@collective_operationnow re-arms the watchdog and labels the report, so the14 declared collectives check in without anything being placed by hand.
checkpointis a local timer reset: no communication, one test when disarmed,safe to leave in production code.
Three measurements that shaped it
A Python thread cannot report a rank blocked in MPI. At np=4 against a 4 s
block in
comm.allreduce, a re-arming 0.5 sthreading.Timerfired zerotimes on the blocked ranks;
faulthandler.dump_traceback_laterproduced allseven dumps. The interpreter lock is held for the duration, so the ranks that
most need to report are exactly the ones that cannot. Reporting has to be in C,
and the consequence is that the destination must be a file descriptor --- an
earlier draft used a
StringIO, passed every serial test, and would havereported nothing in the real case.
watch()now refuses a buffer, and the testasserting that refusal is what keeps the door shut.
The main thread is identified by its outermost frame, not its depth. A rank
blocked two frames into
allreduce, with a telemetry thread twelve frames deepinside
requests, was reported as being in the HTTP call.A rank is placed by the modal position over its recent dumps, not its last
one. A stuck rank shows the same position every period; the final sample can
catch it mid-transition. That had put one of four waiting ranks in a group of its
own, so the report named two culprits instead of one.
Testing
By subprocess, not in-process.
dump_traceback_lateris a single global slotthat pytest's own plugin already owns, and a rank inside a test framework is one
process looking at itself --- the one thing this analysis cannot be done from.
test_0053--- watchdog behaviour, 11 tests, real files throughout.test_0054--- the parser and roll call on synthetic dumps, plus anend-to-end run: a real four-rank job with a real rank-local guard, which
really hangs, is killed by
mpirun, and whose dumps must name rank 1. Anearlier version had the divergent rank join late so the job exited cleanly ---
that tested a situation nobody is ever in, and made termination the flaky part.
23 passed locally alongside
test_0052from #628.Limits
prevent one, and it needs a rank count that exposes the divergence.
absent on ranks blocked inside MPI --- those give the stack only. The stack is
the localisation; the label is a convenience.
ranks_agreeis itself collective and can hang if a rank never arrives. Thatcase belongs to the watchdog; the two are meant to run together.
comm.allreduceshows the Python line that made the call.Underworld development team with AI support from Claude Code