[Bug] Worker.close() intermittently fails to reap fork children within the close budget on a multi-card a5 pool

[doraemonmj]

Platform

a5 (Ascend 950 hardware)

Runtime Variant

tensormap_and_ringbuffer

Description

Worker.close() intermittently raises TimeoutError: child process(es) [<pid>] did not exit within the close budget from the st_worker fixture's teardown. The test body itself always passes — the collective completes and its golden check succeeds — so this is a host-side child-reap problem, not a collective-correctness or inter-card communication problem.

The reap budget is _ROLLBACK_GRACEFUL_TIMEOUT_S = 10.0 s (python/simpler/worker.py:224). After SHUTDOWN is broadcast to every child group, _reap_child_groups polls each pending pid with os.waitpid(WNOHANG) until that deadline, then reports every remaining pid as a survivor.

Evidence that it is a tail-latency effect in child device teardown rather than a hang or a bad card:

• The test body passes. Each failing subprocess reports 1 passed, 1 error, with the error attached to teardown. Across 4 full runs there were 0 golden mismatches and 0 AssertionErrors.
• Usually a single child survives. In 12 observed failures, 10 had exactly 1 surviving child, 1 had 2, and 1 had 3. A global deadlock or a capacity limit would strand children together, not leave one straggler.
• No case, rank count, or device is implicated. 12 failures were spread over 9 distinct cases (4 two-card, 5 four-card). Surviving children appeared on devices 1, 3, 5, 6 and 7 (0 / 2 / 4 never). TestAllreduceOnephaseP4 run alone (-k OnephaseP4) passes reliably.
• It scales with concurrency, not with card health. An 8-card --device pool runs 4 device-jobs at once, so up to 16 chip children finalize their CANN device state (reset device, HCCL comm destroy, VMM unmap) simultaneously. The 2-card-only a5 configuration that existed before 8 cards came online essentially never surfaced this.

Distinct from the reap bug fixed in 8e3bebf ("exit a forked worker child once its parent is gone"): that one reproduced on every 8-rank run against a pre-8e3bebf4 install and is gone after reinstalling. This one is intermittent on a current install.

Not yet done, and the decisive next step: capture a backtrace of a surviving pid (/proc/<pid>/stack, or gdb) to identify which CANN call it is sitting in. That is the only way to separate "slower than the 10 s budget" from "genuinely wedged". A --max-parallel 1 run would also confirm or refute the concurrency hypothesis.

Steps to Reproduce

1. On a host with >= 4 a5 NPUs, add "a5" to the platforms list of the 4-rank collective cases under tests/st/worker/collectives/ (as of 22f2d53 they list only ["a2a3sim", "a2a3", "a5sim"]).

2. Run the collectives suite against a multi-card pool so several device-jobs run concurrently:

   task-submit --timeout 2400 --max-time 2300 --device 0,1,2,3,4,5,6,7 \
     --run "source /usr/local/Ascend/cann-9.2.0/set_env.sh && source .venv/bin/activate && \
            export LD_PRELOAD=/usr/lib64/libstdc++.so.6 && \
            python -m pytest tests/st/worker/collectives --platform a5 --device 0-7 \
              -v --require-pto-isa --pto-session-timeout 600 -p no:cacheprovider"

3. Repeat several times. Observed failure counts over 4 consecutive 18-case runs: 1, 2, 5, 4. An earlier run was fully green (18/18), so a single passing run does not clear it.

Note: LD_PRELOAD is needed on this host because the venv interpreter carries a DT_RPATH of $ORIGIN/../lib pointing at an anaconda libstdc++ that lacks GLIBCXX_3.4.30; RPATH is consulted before LD_LIBRARY_PATH, so setting LD_LIBRARY_PATH does not help. Unrelated to this bug, but required to get the suite to run.

Expected Behavior

Worker.close() reclaims every fork child and returns cleanly, so teardown does not fail a test whose body passed.

Actual Behavior

tests/st/worker/collectives/allreduce/test_allreduce.py .E               [100%]

==================================== ERRORS ====================================
________ ERROR at teardown of TestAllreduceBidirectionalRingP4.test_run ________
...
        if survivors:
            errors.append(TimeoutError(f"child process(es) {survivors} did not exit within the close budget"))
        for msg in bad_exits:
            errors.append(RuntimeError(f"child teardown: {msg}"))
        if errors:
>           raise errors[0]
E           TimeoutError: child process(es) [576888] did not exit within the close budget

python/simpler/worker.py:6341: TimeoutError
---------------------------- Captured stderr setup -----------------------------
[chip_process pid=576887 dev=4] ready

Cases observed failing this way, over 4 runs (12 failures / 9 distinct cases):

Case	Ranks	Hits
TestAllreduceTwophaseP4	4	2
TestAllreduceIbingP2	2	2
TestAllreduceBidirectionalRingP4	4	2
TestBroadcastP4	4	1
TestAllToAllP4	4	1
TestAllreduceRingP4	4	1
TestAllreduceOnephaseP4	4	1
TestAllreduceOnephaseP2	2	1
TestAllgatherP2	2	1

Git Commit ID

22f2d53

CANN Version

9.2.0

Driver Version

npu-smi 25.6.rc1.b188

Host Platform

Linux (aarch64)

Additional Context

Location: python/simpler/worker.py:6341 (_reap_child_groups, raising after its bounded poll), reached via close() -> _teardown_ready_tree(). Surfaces through the st_worker fixture in conftest.py.

Impact: this reddens a multi-card a5 onboard run even though every collective is functionally correct. Verified separately that 8-rank allreduce (examples/workers/l3/allreduce/main.py -p a5 -d 0-7) matches golden on all 8 ranks, and that all 18 collective cases pass on a5 across 2- and 4-rank configurations.

[wangqin1723-max]

@wangqin1723-max

[wangqin1723-max]

related（#1209）

[ChaoWao]

Another pair of hits on the a5 pool today, both in st-onboard-a5 and both in the collectives allreduce group:

• run 30601332931 (branch aicpu-pg-a2a3-a5) — TestAllreduceIbingP2, devices [2, 3]: TimeoutError: child process(es) [138728] did not exit within the close budget
• run 30603360904 (PR Update: make whole-run FIFO admission failure-safe #1541) — TestAllreduceRingP2, devices [0, 1]: TimeoutError: child process(es) [1078148] did not exit within the close budget

Same signature, ~45 minutes apart, on branches with no code in common — the test itself passes in both and only the teardown reap times out. Recording it here rather than opening a duplicate.

The same a2a3 collectives suite (pytest tests/st/worker --platform a2a3, P2 and P4 across allreduce / broadcast / reduce_scatter) passes on the shared dev box, so this stays specific to the a5 pool.

[ChaoWao]

Two things from digging into this: a measured baseline for the reap path, and a concrete race that would produce exactly this signature and that a larger budget cannot fix.

I could not reproduce the reported configuration — the box I have is a2a3 (Ascend910_9392), so nothing in §1 is a5 evidence. Line refs are against 673aecea.

1. Measured reap latency (a2a3, not a5)

I wrapped Worker._reap_child_groups with an effectively unbounded deadline and recorded real elapsed time, so the measurement never fails a test and every passing run yields samples. One pass of tests/st/worker/collectives on a2a3 with a 6-device pool — 19 samples, one per case close:

min	median	p90	max	mean
0.198 s	1.411 s	1.603 s	1.778 s	1.325 s

would_have_timed_out: 0/19. Headroom at max against the 10 s budget: 5.6×.

Split by children per worker:

children	n	mean	max
2	9	1.328 s	1.635 s
4	9	1.290 s	1.778 s

Reap latency does not grow with children-per-worker. Children finalize in parallel, so the ~1.3 s reads as a fixed per-teardown cost rather than per-child work. Caveat: this measures children per Worker, not concurrent device-jobs across the pool — my run had at most ~3 concurrent jobs, not the 4 in the report, so the cross-job dimension is untested.

For the tail-latency hypothesis this is mildly unfavourable: reaching 10 s needs both a ~7× outlier and growth with scale, and the one scaling dimension I could measure is flat.

2. A race that loses SHUTDOWN outright

The mailbox control state word (_OFF_STATE) has three writers, and SHUTDOWN is not sticky:

writer	writes	synchronisation
C++ LocalMailboxEndpoint::run_control_command	CONTROL_REQUEST (worker_manager.cpp:1295), then IDLE (:1333/:1336)	holds mailbox_mu_
child serve loop	CONTROL_DONE (worker.py:2552; next-level child :1758)	unconditional store, no CAS
_broadcast_child_shutdown	SHUTDOWN (worker.py:8850)	plain shm store from Python — it cannot take the C++ mailbox_mu_

SHUTDOWN is terminal, but it shares one mutable word with a transient handshake, with no CAS and no monotonicity:

C++     write CONTROL_REQUEST
child   reads CONTROL_REQUEST, enters handle_control(...)   # slow
close() write SHUTDOWN                                      # not under mailbox_mu_
child   write CONTROL_DONE                                  # clobbers SHUTDOWN
child   loops; reads CONTROL_DONE != SHUTDOWN; never breaks
parent  reap polls for 10 s -> survivor

There is a second clobber point: run_control_command writes IDLE unconditionally once it observes CONTROL_DONE, so a SHUTDOWN landing in that gap is erased too.

The concurrency gap this needs is already documented in-tree, in _teardown_ready_tree (worker.py:8939):

register / unregister are not yet lease-fenced against close … so a racing register broadcast is possible; that gap is out of this PR's scope.

Against the evidence in the report:

observation	lost SHUTDOWN explains it?
test body always passes	✅ teardown-phase only
usually exactly 1 survivor	✅ narrow, per-child window
no case / rank / device correlation	✅ independent of case content
scales with concurrency	✅ host load widens the window between handle_control and the write-back
survivor does not exit	✅ the child never breaks — a real wedge, unbounded, not "slower than 10 s"

I have not proven this is the cause here. It is a mechanism that is reachable in-tree and consistent with every listed signature.

3. A one-read check that decides it — no gdb needed

_reap_child_groups reports survivors and leaks them; it never kills them, and it deliberately keeps a survivor's shm because freeing a live child's mailbox would be a use-after-free. So at the moment the TimeoutError is raised, the survivor and its mailbox are both still there. Read the state word:

survivor _OFF_STATE == 3 (SHUTDOWN)                  -> delivered, genuinely slow  => tail latency
survivor _OFF_STATE == 5 (CONTROL_DONE) or 0 (IDLE)  -> SHUTDOWN was overwritten   => this race

That is cheaper and more decisive than capturing /proc/<pid>/stack, and it can go straight into the error message so every future occurrence carries its own diagnosis.

4. Fix direction

If it is the race, a larger budget cannot fix it — once the word is overwritten the child waits forever. The structural fix is to make SHUTDOWN unclobberable:

• preferred: a separate one-way shutdown flag — written only by the terminating side, 0→1 only, checked in the child loop alongside the state word. Monotonic, terminal, no other writer, so clobbering is impossible by construction.
• alternative: make every non-shutdown transition a CAS that refuses to overwrite SHUTDOWN. Correct, but it turns the invariant into a rule every future writer has to remember.

If instead the survivor's word reads SHUTDOWN, it really is latency — and I would still argue for a no-progress budget rather than a larger fixed one: keep waiting while any child is still exiting, and give up only after a full poll round reaps nobody for X seconds. That adapts to load, distinguishes "slow" from "stuck" by construction, and needs no constant to re-tune as pools grow.

---

Repro note for anyone picking this up: the probe has to be installed via a sitecustomize.py on PYTHONPATH (env-gated), not pytest -p. scene_test runs each device job as [sys.executable, script, ...] — a plain script, not pytest — so a pytest plugin never reaches the process that actually creates and closes the Worker.

[ChaoWao]

Closing now that #1663 is on main.

What was proven

The SHUTDOWN clobber race is real. A deterministic, device-free repro using the real _run_chip_main_loop plus a blocking fake chip shows that a CONTROL_DONE store from an in-flight control command erases a SHUTDOWN published during that window, and the child never exits:

SHUTDOWN after control completes → child_exited=True,  final=3 (SHUTDOWN)
SHUTDOWN during control          → child_exited=False, final=5 (CONTROL_DONE)

This produces exactly the TimeoutError / "did not exit within the close budget" signature reported here. The fix (MAILBOX_OFF_SHUTDOWN, a one-way word that no other writer touches) is in #1663.

What was not proven

Whether any in-the-wild occurrence of this issue was caused by that race. 296 close cycles across a2a3 (6-device pool) and a5 (8-device pool, Ascend950PR_9579) produced zero close-budget timeouts, so I never caught a survivor to read its state word and settle it.

Why close anyway

With #1663 on main the clobber path is structurally impossible — the one-way flag is written by the terminating side only and no other writer ever touches it. Any future recurrence therefore rules out "SHUTDOWN never received" and isolates the remaining explanations (tail latency / genuine wedge in CANN teardown). That is strictly more information than today, where all three explanations are still in play.

I do not claim this issue is fixed. I claim that one mechanism known to produce its exact signature is gone from the tree, and that the next occurrence will carry its own diagnosis.

[ChaoWao]

Closing — #1663 fixed the SHUTDOWN clobber race that produces this exact signature. See above for the full analysis and the distinction between what was proven and what was not.