Untrusted execution timeout wedges the replica: a stale SystemExit kills the shared asyncio executor thread

[JadenFiotto-Kaufman]

Summary

When an untrusted request hits the execution timeout, the replica never becomes usable again. Every later request to that replica hangs with no response and no error, indefinitely. The trusted path recovers cleanly from the same blocks in well under a second.

ndif kill on the wedged request reports success and returns the queue counters to Executing: 0, Queued: 0, but this frees only the queue's bookkeeping — the replica still does not serve requests afterwards. There is currently no known operator remedy short of restarting the replica.

Found while testing execution-timeout recovery on the Test stack ahead of the prod release.

Reproduction

Test stack, NDIF_DEFAULT_EXECUTION_TIMEOUT_SECONDS=20 on the Ray head, openai-community/gpt2 pinned as replica fab50 (SandboxModelActor), sandbox pool size 2.

Run a block that outlives the timeout, then immediately send a normal trace to the same replica:

# times out
with m.trace("hello", remote=True):
    import time as _t
    _t.sleep(60)
    m.transformer.h[0].output[0].save()

# recovery probe
with m.trace("The Eiffel Tower is in the city of", remote=True):
    lg = m.lm_head.output.save()

Observed

path       block     first request              recovery
---------  --------  -------------------------  --------------------------
trusted    sleep      21.5s  "exceeded ... 20.0s"   0.8s  OK
trusted    pyloop     20.3s  "exceeded ... 20.0s"   0.5s  OK
untrusted  sleep      20.3s  "exceeded ... 20.0s"   HUNG (>18 min)

After the untrusted case, ndif queue showed the timed-out request still executing long past its own timeout:

⚙ [fab50] executing b40ba757… (for 0:18:50)

with the recovery request queued behind it.

ndif kill b40ba757… returned ✓ Request b40ba757… cancelled while executing. and the queue went to Executing: 0, Queued: 0. However, a plain gpt2 trace submitted afterwards also hung indefinitely (>6 min, no RUNNING→COMPLETED, no error). So the kill restores the queue's view but not the replica.

Evidence gathered

• Loki: the request trail ends at "Your job has started running." — no timeout line, no error line, nothing after.
• ray.util.state.list_tasks: one SandboxModelActor.run in RUNNING, the rest FINISHED — a run() coroutine that never returned.
• No runner subprocess alive on the GPU worker, so Sandbox.stop() did its job.
• ReplicaState.dispatch() has finally: self.current_request = None, so it had not returned either.
• py-spy on the actor: no ndif/nnsight frames on any thread. Consistent with a coroutine suspended at an await (py-spy cannot see those) rather than a thread spinning.

Notes on the mechanism (not confirmed)

run() has only two await points, and nothing after the timeout branch awaits:

• await asyncio.to_thread(self.model._remoteable_set_env, request.env) — base.py:350
• await asyncio.wait({job, kill}, timeout=self.execution_timeout, ...) — base.py:357

Cancelling job at base.py:362-363 does not stop the underlying thread — asyncio.to_thread wraps a real thread, and cancelling the task only abandons it. That thread is inside SandboxDriver.pump(connection), and for the untrusted path the host's model forward is parked mid-forward in a greenlet belonging to that thread.

cleanup() then runs on the event loop thread and calls self.model.interleaver.cancel() (base.py:656), which throws GreenletExit into parked workers — greenlets owned by the abandoned execution thread, not this one. It also calls torch.cuda.synchronize() on the event loop thread.

Candidates worth checking, in order:

1. The abandoned execute thread is never joined, and the next request's await asyncio.to_thread(...) (or something that thread still holds — the greenlet-parked forward, the interleaver, a pool slot) blocks on it.
2. interleaver.cancel() reaching cross-thread into greenlets it does not own.
3. torch.cuda.synchronize() on the event loop thread while an abandoned thread still has work in flight.

Ruled out as the blocking point:

• Sandbox.stop() — bounded: terminate(), wait(timeout=5), kill(), wait() (host.py:134-143).
• Pool.acquire() — bounded at 30 s, spawns if drained (host.py:278).
• Interleaver.cancel() raising on worker=None for ndif's MediatorProxy — it catches BaseException and downgrades to a warning, so it cannot propagate or hang there.

Still to establish

Whether the wedge also happens for an untrusted block that stays in Python bytecode (a while loop) or one issuing repeated small CUDA ops, versus only one blocked in a C call like time.sleep. Both attempts at the bytecode-loop case were themselves swallowed by the still-wedged replica from the sleep case, so this is untested rather than negative.

Why this matters for the release

Untrusted is the path real users take. One user submitting a block that runs long takes the replica out until someone notices and restarts it, and the queue's own counters say everything is fine.

[JadenFiotto-Kaufman]

Root cause found

interrupt() injects SystemExit into the execution thread with PyThreadState_SetAsyncExc (util.py:69-88). That thread is a shared asyncio default-executor worker, because execute() is dispatched with asyncio.to_thread (base.py:354). An async exception fires only at a bytecode boundary, so when the target is parked in a native call it lands arbitrarily later — in whatever that pooled worker is doing by then.

On the untrusted path the target is always parked in a native call: recvn → sock.recv(), waiting on the runner. Sequence:

1. Request A times out. run() calls interrupt(), which stops the runner and schedules SystemExit for A's worker thread.
2. The thread is inside sock.recv(), so the exception cannot land.
3. Stopping the runner closes the socket, recvn raises ConnectionError, work_item.run() captures it into A's future, and the worker finishes A's item, goes idle, and releases _idle_semaphore. A's run() responds ERROR and returns correctly — which is why the client always sees the right message at the right time.
4. Request B arrives. run() reaches await asyncio.to_thread(self.model._remoteable_set_env, request.env) (base.py:350). The same worker dequeues B's work item.
5. The SystemExit from step 1 now lands, in _worker outside work_item.run()'s try. The thread dies holding B's work item.
6. B's future is never completed. B's run() is suspended at its first await, forever.

Because B never reaches asyncio.wait, its own execution timeout never arms — which is why a 0.5 s trace sits "executing" for 24 minutes under a 20 s timeout, and why nothing appears in the log after "Your job has started running.".

Evidence from the wedged actor

Introspected in-process via __ray_call__ while B was hung:

Executor ThreadPoolExecutor-4 max_workers=8 threads=1 alive=0 qsize=0 shutdown=False
    ThreadPoolExecutor-4_0 alive=False daemon=False
live threads: ['AsyncIO Thread: default', 'MainThread', 'PythonGCThread',
               'Thread-1 (_monitor)', 'ThreadPoolExecutor-0_0',
               'ThreadPoolExecutor-1_0', 'tqdm_monitor']

pending asyncio Tasks: 1
--- Task-8 ---
No stack for <Task pending coro=<run_async_func_or_coro_in_event_loop.<locals>.async_func()>
  wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel(), Task.task_wakeup()]>

execution_ident=None
execution_sandbox=None
execution_timeout=20.0

ThreadPoolExecutor-4 is asyncio's default executor — the one to_thread uses. Its only worker is dead, qsize=0 (B's item was dequeued and lost with it), and the executor was never shut down. The single pending task is B's run(), waiting on a future chained from a concurrent.futures.Future that no longer has a thread behind it.

py-spy --native on the same process shows the event loop healthy and idle in epoll_pwait inside uv_run, so nothing is blocking the loop:

Thread 1525 (idle): "AsyncIO Thread: default"
    epoll_pwait (libc.so.6)
    uv__io_poll (linux.c:1432)
    uv_run (core.c:452)
    run_forever (loop.c:31528)

Clean serial reproduction

On a freshly restarted replica, with no operator commands involved:

12:56:35  15b2b63c  Your job has started running.
12:56:55  15b2b63c  Your job exceeded the execution timeout of 20.0s.   <- correct
12:56:55  5f8a0395  Your job has started running.
          (nothing, ever)

5f8a0395 is with m.trace(...): m.lm_head.output.save() — a 0.5 s trace. Ray reports its SandboxModelActor.run as RUNNING indefinitely.

Why trusted recovers

Same kill_thread call, but the trusted target is executing Python bytecode inside work_item.run(), so SystemExit lands within the try that captures it into the future. The worker survives and the pool stays intact.

Second, separate bug: the timed-out block keeps running

interrupt() and cleanup() both stop self.execution_sandbox (model.py:200-205, model.py:181-185), but that attribute is a single slot on the actor while run() is a coroutine that Ray executes concurrently. When requests overlap, a later request overwrites execution_sandbox, and the earlier one's interrupt() then stops the wrong runner or None.

Caught in the act — a runner still executing a user block 25 minutes after its request had already errored:

815: python3.12 -m ndif.services.ray.sandbox.runner /tmp/sbx-9e4c71dce14e.sock ...
Thread 815 (active+gil): "MainThread"
    __setitem__ (nnsight/tracing/util.py:84)
    python_loop_block (timeout_test.py:29)
    _run (nnsight/intervention/interleaver.py:245)

That is while i < 10**12: i += 1, pinning a core, invisible to the queue and to telemetry, with its request long since failed. For prod this means the execution timeout does not actually bound CPU: a user can leave work running indefinitely after being told their job was killed. execution_ident is a single slot too, so kill_thread can likewise be aimed at an unrelated request's thread.

Suggested fixes

1. Do not inject into the untrusted path at all. SandboxModelActor.interrupt() already calls execution_sandbox.stop(), which reliably ends the block; the socket then EOFs and pump unwinds on its own. Dropping the super().interrupt() call there removes the stray-exception window entirely. Smallest change, fixes the wedge.
2. Give execute() a dedicated thread rather than the shared asyncio default executor, so a late async exception can only ever kill that request's own thread.
3. Make the sandbox/ident per-request instead of an attribute on the actor — pass them through, or key them by request id — so concurrent run() coroutines cannot clobber each other.
4. Arm the timeout before the first await. Wrapping the whole body in asyncio.timeout(...) would have turned this permanent wedge into a 20 s error, which is worth having regardless of the fixes above.

Operator remedy

ndif kill <id> on the stuck request frees the queue, and the replica then serves requests normally (verified: PROBE OK in 1.7s immediately after). ndif restart gpt2 also works and additionally reaps orphaned runners via their die-with-parent watchdog.

I retract the claim in the original report that the kill leaves the replica unusable. What actually happened is that each of my test runs left a new stuck request behind, so killing the one I knew about still left another holding the slot.