Skip to content

serve engine deadlocks in SleepConditionVariableSRW during a long streaming reply; stall watchdog never fires #481

Closed as not planned

Description

@gu-feng

Environment

  • Engine: 0.1.34 ready-made release build (BUILD.json: version 0.1.34, source "release", portable, cuda 13.0, archs 75/86/89/120), engine\strata.exe timestamp 2026-10-02 00:55 UTC. Observed twice live on this exact build. The 0.1.35 changelog doesn't list anything matching this, so I assume it is still present (not yet re-tested on 0.1.35).
  • Hardware: NVIDIA RTX 5060 Ti 16 GB (sm_120) — the only CUDA device; Intel i5-14600K (6 P-cores + 8 E-cores, no AVX-512); 64 GB RAM; Windows 11 Pro build 26200.
  • Serve: serve/server.py, OpenAI-compatible endpoint on 127.0.0.1:8080.
  • Engine args (one line for easy re-use):
--pack <packs\iq3_xxs> --native <shard1> --ple-gguf <shard2> --expert-profile <custom profile> --expert-cache auto --prefill auto --spec 4 --mtp <mtp\rt> --max-context 205824 --kv int8 --kv-resident 32768 --vision --vram-reserve-mib 700 --pcie-frac 0.35 --spec-min-p 0.70 --pool-workers 9 --pool-affinity auto

(--pool-affinity auto was added between the two live observations; the first deadlock predates it, so affinity is not implicated.)

  • Client: an agentic coding client over OpenAI-compatible SSE: tool-call loops, 34K–85K-token prompts with heavy prefix reuse, reasoning_effort: high → multi-minute <think> streams, occasional client-side cancels.

What happens

Mid-generation, the engine deadlocks: output stops, the GPU drops to 0% while VRAM stays allocated (15.1 GB held), the engine process's total CPU time freezes (every thread blocked), and the request never completes nor errors. The client hangs until the whole service is restarted. The engine log's last line is always a normally-completed earlier request — nothing is written at the moment of the hang, on stderr or stdout.

Happened 4+ times over two days, only with this agentic client; browser chat and short requests never trigger it. Both live-observed cases froze ~74 s into a <think> stream (once at thinking token 2459, once at 9717+).

Evidence (second occurrence, captured live)

  1. Engine process 12+ minutes into the freeze: all 30 threads in Wait (2× EventPairLow, rest Unknown/UserRequest), total CPU time identical across samples.
  2. Full memory dump taken (comsvcs MiniDump /full), parsed without symbols. Main thread:
ntdll.dll!NtWaitForAlertByThreadId+0x14            <- RIP
ntdll.dll!RtlSleepConditionVariableSRW+0x1de
KERNELBASE.dll!SleepConditionVariableSRW+0x38
strata.exe+0x35f118                                <- caller of SleepConditionVariableSRW

The dump was deleted after analysis (64 GB), but I can reproduce, re-dump and pull all 30 thread stacks with a working minidump parser if that helps identify the lock partner.
3. The stall watchdog never fires. After 12+ minutes of a fully frozen process there was no no progress for ... s ... (issue #29) line and no strata-stall-<pid>.dmp. Whatever the main thread waits on, the watchdog's progress accounting does not cover it.
4. serve/server.py wedges with the engine. After I force-killed the deadlocked engine process, the server did not respawn it on the next request (the request handler stays stuck); only restarting the whole server recovers.

Ruled out

  • RAM/VRAM exhaustion: memtest86 clean; the wedge reproduced with ~24 GB RAM free; engine VRAM was at its planned steady state (520 MiB free, no LOW warning) — and the deadlock is a permanent wait, not a slowdown.
  • GPU driver TDR: no Event 4101 / LiveKernelEvent at the freeze times.
  • The client's cancels as the direct trigger of the freeze — a cancel was in flight around the first incident, but the second freeze happened with no cancel; cancelled requests complete cleanly otherwise (v0.1.34's fast cancel works).

Frequency / repro shape

Every occurrence: long agentic session (tool calls + big reused prefixes) with reasoning_effort: high → a thinking stream several minutes long → engine freezes mid-stream. Never in ~50 short chat/browser requests. I cannot reproduce it on demand yet, but it recurs within a day of agentic use.

Asks

  1. Resolve strata.exe+0x35f118 in the 0.1.34 release build (a .pdb/map for release builds — or a hint which std::condition_variable::wait in the serve path sits there — would let me self-resolve and give you the function).
  2. Why the stall watchdog (STRATA_WATCHDOG_S) doesn't cover this wait; ideally a stuck engine should still self-report and dump.
  3. serve/server.py: detect a dead (or force-killed) engine mid-request and respawn, instead of wedging the handler.

Workaround I run meanwhile

An external scheduled task tails the server's stdout (Tee-Object to a file) and restarts the whole service when a [strata] thinking: progress line goes stale for >90 s. Turns the hang into a ~2 min hiccup.

Happy to attach: per-thread stack dump of all 30 threads on the next occurrence, STRATA_TRACE=1 log through a freeze, or the engine + server logs around either incident.

Activity

  1. wxaef commented on Oct 2, 2026

    @wxaef

    me too

  2. Niko1221 commented on Oct 2, 2026

    @Niko1221
    Owner

    Thanks for the stack. We resolved +0x35f118 against our copy of the 0.1.34 release: it is the static STL's _Cnd_wait, an untimed condition-variable wait on the engine's main thread. The best fit is the engine waiting for its next command between requests while the server waits for that request's end, so the two have lost step. The stall watchdog only counts while a request is running, which is why it never fired. The next release makes the server notice it: no engine output for a while during a request, or a stop that is never acknowledged, now restarts the engine instead of waiting forever.

    To find how they lose step, could you, on the next freeze:

    1. post the next 2-3 return addresses above +0x35f118 (we resolve them against the same build);
    2. run with "STRATA_TRACE": "1" in the config's env and post the end of strata-<model>.log plus the server window's last lines;
    3. say whether the request was cancelled or hit a thinking budget just before.

    Keeping this open.

  3. Niko1221 commented on Oct 2, 2026

    @Niko1221
    Owner

    0.1.37 adds the server-side safety net: a request whose engine stays silent (default 300 s, longer while a long prompt is read; "engine_silence_s" in the config) or never acknowledges a stop now ends with an error, and the next request restarts the engine. We still want to find how the two lose step: the trace asked for above would help a lot.

  4. gu-feng commented on Oct 3, 2026

    @gu-feng
    Author

    @Niko1221 Deployed v0.1.38 here (release build) — engine_silence_s at its default, and "STRATA_TRACE": "1" is set in the config's env, so the next freeze comes with the trace tail. No freeze has recurred since 0.1.38 went in.

    Answers to (3), for the two freezes we captured on engine 0.1.34:

    Freeze 2 (2026-10-02 ~07:30 UTC, captured live): the client was still waiting — no cancel was in flight. Thinking was at 2459 of a 131072 budget, nowhere near it. No DONE/ERR was ever logged for that request.
    Freeze 1 (2026-10-02 ~16:28 UTC): the client logged stream.failed, status=cancelled about 2 minutes after the freeze began, so the cancel looks like a consequence rather than the trigger. The thinking budget was not hit either.
    One more data point that may or may not be related: both freezes happened ~74 s into long streams with reasoning_effort: high.

    On the next freeze you will get, as asked:

    the ordered strata.exe return addresses above +0x35f118 (my first dump was parsed with a stack walker that collapsed same-module frames, which is why only four frames were posted — the parser now emits every frame in order, and all 30 threads' RIPs with them);
    the end of strata-iq3_xxs.log with the trace lines, plus the server console's last lines.
    Also noted while testing, in case it is related: terminating a healthy running engine process (45 GiB of the arena locked at 4 KiB pages) has hung in an uninterruptible state for 15+ minutes — TerminateProcess sent, CPU frozen, the locked memory and VRAM held until reboot. May be driver-side and unrelated to the desync; mentioning it since both end in the same "everything waits forever" symptom.

  5. Yoshimit commented on Oct 8, 2026

    @Yoshimit

    Seems like the env STRATA_ENGINE_READY_S=0 only affects the engine's start.
    On my potato gamer, the env allows the engine to start after some time, but a request that needs to read the entire conversation to compact gives me the message:

    [...]
    [strata] reading the prompt: 14,223 of 49,581 tokens, 854 s so far
    [strata] the engine said nothing for 1871 s during the request; the server ended the engine. The engine and the server lost step (issue #481; a very slow PC can raise "engine_silence_s" in the config, 0 = wait forever). If it happens again, please add the end of the engine log to github.com//issues/481. The next request starts the engine again. Its log: D:\Downloads\models\Strata-main\strata-coder-iq1_m.log
    [strata] done: 0 tokens in 2738 s (0.0 tok/s) (error, cancel=False)

    Yes, the engine takes an awful amount of time to start and the prompt reading is very poor here.
    But the decoding is 'light years away' from any other options I have. So, I prefer this.

    So, the env should avoid the server ending the engine on any request. I set it up asking for that.

    Thank you for your project @Niko1221 !

  6. rebuilt commented on Oct 11, 2026

    @rebuilt

    Adding matching evidence from the HIP / gfx1201 path (Radeon AI PRO R9700, IQ3_S, engine 0.1.39) for the payload the issue asks for.

    The server line:

    [strata] the engine said nothing for 300 s during the request; the server ended the engine. ...
      (issue #481; a very slow PC can raise "engine_silence_s" in the config, 0 = wait forever)
    

    The engine log at that moment: it had stopped making progress during a long prefill, and the watchdog's stall report shows the host parked on a GPU operation — not on disk, not on the expert pool:

    strata serve: no progress for 300 s during a request (reading the prompt (batched):
      waiting for the GPU (attention, router) at layer 37 of the prompt chunk from token 5101)
      - stopping the engine so the server starts it again (issue #29)
    strata serve: stall report (engine 0.1.39): stage "reading the prompt (batched): waiting for the GPU
      (attention, router) at layer 37 of the prompt chunk from token 5101" for 300 s;
      0 layers served since the last finished step (0 = stopped, more = slow)
      expert pool: epoch 0, batch epoch 0: 0 of 0 jobs claimed, 0 done; 11 of 11 workers parked, 11 sleeping; mode 0
      verify window (last window, not the current stage): 0 tokens at position 0, host at layer step 1;
        the GPU rang 0; flags: served 0, plan (A) 0, copies (B) 0
      threads waiting on the disk (state D): 0 of 67
      memory: 29297 MiB resident, 13 MiB in swap, 28000 MiB RAM available; 266165 major page faults so far
      2 s later:
      expert pool: 0 of 0 jobs claimed, 0 done; 11 of 11 workers parked, 11 sleeping; mode 0
      verify window: 0 tokens ... the GPU rang 0 ... host idle for 510650 ms
    

    Notes that may help narrow it: every expert worker parked and asleep, verify window "GPU rang 0", 0 threads in D-state, and low swap. That reads as the host blocked in a GPU sync (cudaStreamSynchronize in the prefill path) rather than a scheduler/pool problem. Config: engine 0.1.39, gfx1201, 131072 ctx, --kv int8 --kv-resident 32768, --vram-reserve-mib 3072. It happened once at 3072 MiB reserve (many more at lower reserve; 700 MiB also drove a ~7x driver-paging slowdown). Happy to attach the full engine-log tail if useful.

  7. Niko1221 commented on Oct 13, 2026

    @Niko1221
    Owner

    Thanks for the report. To keep the tracker current we are closing issues older than three days: 0.1.44 is out with a long list of fixes, and many older reports are covered by it or by 0.1.43.1.

    If this still happens on 0.1.44, please leave a comment here with your engine log (and the version line it prints), and we will reopen it. A new issue that links this one works too.

  8. jem-os commented on Oct 21, 2026

    @jem-os

    Still happens on 0.1.45, with a twist: the engine finished the request at full speed, but the server's request thread stopped consuming its output, and the silence watchdog did not fire. From the code (below), this looks like a stalled write to the client rather than the engine and server losing step.

    Environment

    • Engine: 0.1.45 (strata generate: session is up (engine 0.1.45)), Linux, in Docker.
    • Hardware: RTX 3090 24 GB (sm_86), PCIe 4.0 x16 (probe 25.8 GB/s), Ryzen 9 5950X (no AVX-512), 128 GB RAM, swap off. Driver 595.91.07, CUDA 13.2.
    • Engine args (paths masked):
    --serve --pack <pack> --native <model.gguf> --ple-gguf <model.gguf> --expert-profile <profile> --expert-cache auto --prefill auto --spec 4 --spec-min-p 0.5 --mtp <mtp> --max-context 262144 --kv int8 --kv-resident 32768
    
    • Config: "reasoning_close_retry": true, "tool_call_recovery": true; engine_silence_s at its default. STRATA_TRACE was not set.
    • Client: Claude Code (claude -p) over /v1/messages, streaming, 6 tools, thinking: adaptive, effort high, max_tokens 32000 (thinking capped at 24000). Agentic loop with heavy prefix reuse. Claude Code's own output went to a file, so it was not blocked on its stdout.

    What happened (2026-10-21, UTC)

    Server log: the request streamed normally, then stopped at 4,837 thinking tokens and stayed silent for 15 min 41 s until the client gave up:

    09:09:47.545 [strata] thinking limited to 24000 of max_tokens 32000 so the answer has room ("answer_room": false in the config turns this off)
    09:09:52.815 [strata] reading the prompt: 56,830 of 56,835 tokens, 5 s so far
    09:09:53.828 [strata] thinking: 77 of budget 24000 (max 32000) tokens, 107.3 tok/s, 6 s
    ...
    09:10:39.394 [strata] thinking: 4717 of budget 24000 (max 32000) tokens, 101.9 tok/s, 52 s
    09:10:40.398 [strata] thinking: 4837 of budget 24000 (max 32000) tokens, 102.3 tok/s, 53 s
    09:26:21.450 [strata] done: 4894 tokens in 994 s (5.0 tok/s) (disconnect, cancel=True), expert cache 94.8% hit (+0.6% of the routed experts over PCIe)
    09:26:24.612 [strata] thinking limited to 24000 of max_tokens 32000 so the answer has room ("answer_room": false in the config turns this off)
    09:26:38.718 [strata] tool call complete: 1415 of max 32000 tokens, 100.9 tok/s, 14 s
    09:26:39.403 [strata] done: 1497 tokens in 15 s (101.8 tok/s) (stop, cancel=False), ...
    

    Engine log for the same request: it completed at full speed, with 6,521 tokens generated in 64.5 s, so it was done by about 09:10:52:

    strata serve: prompt 56835 tokens = 45641 reused + 11194 read in 5540 ms (2020.5 tok/s), 6521 generated in 64485 ms (101.1 tok/s), drafts accepted 3589 of 5378, 6 checkpoints
    strata serve: decode expert cache hit rate: 94.8% (3609211 hits / 3807985 lookups); 22468 more read by the GPU over PCIe or from another GPU (0.6% of all 3830453 routed)
    strata serve: route tail skip: 41874967 missed experts skipped (43598005 entries) since the start
    strata serve: KV streaming: 99.73% of 374427816 block reads hit VRAM, 4102.2 MiB read from RAM
    strata serve: suffix drafts: 53 windows, 84 of 140 drafts accepted
    strata serve: prompt 56835 tokens = 56830 reused + 5 read in 60 ms (84.0 tok/s), 1497 generated in 14720 ms (101.7 tok/s), drafts accepted 817 of 1206, 6 checkpoints
    

    The second prompt 56835 line is the client's retry at 09:26:24, which matches the server's done: 1497 tokens in 15 s.

    Answers to the three questions

    1. Return addresses: not captured (Linux; no dump taken).
    2. Engine log end and server lines: above. The engine log has no line between the two requests. Nothing indicates an error.
    3. Cancel or thinking budget: neither before the stall. The client's cancel came 15 minutes later, as a timeout. Thinking was at 4,837 of 24,000 when the server's progress lines stopped.

    Likely cause, from the code

    I read serve/server.py at 0.1.46.3 (9de04cd), not 0.1.45, so the line numbers may differ for 0.1.45.

    One handler thread runs the whole request as a chain of pull-based generators:

    1. StrataEngine.generate() (around line 2157) takes engine lines from self.lines, the queue the pump thread fills. The silence watchdog runs inside this loop.
    2. Service._run() pulls tokens from it and prints the thinking: N of budget progress lines.
    3. anthropic_events() turns the tokens into SSE events.
    4. _anthropic() (around line 6987) writes each event with self.wfile.write() and flush(), with no write timeout on the socket.

    If that write blocks, because the client stops reading or the path between the two stops moving bytes, nothing pulls the next token. The progress lines stop, and the watchdog never runs, because it lives in the generator that is no longer pulled. The pump thread keeps reading engine stdout into the unbounded queue, so the engine finishes at full speed. _watch_client() cannot help: it detects a closed socket (EOF), not a client that has stopped reading.

    This fits each observation:

    • The engine finished by about 09:10:52 and needed no restart.
    • The progress lines stopped at 09:10:40, and 57 more tokens were counted after it, while the socket buffers filled.
    • There was no "the engine said nothing" line in 15 minutes.
    • The done … (disconnect, cancel=True) line came at the moment the client gave up. The blocked write then fails, the except OSError path sets cancel, and the drain after STOP finds the engine's DONE already in the queue.

    While the thread is blocked, the request also holds the request FIFO, so any other request would wait behind it.

    What stopped the bytes is not visible in the code or the logs. During a stall, ss -tnoi on both ends would tell a client that stopped reading (large Recv-Q on the client) from a stalled path (large Send-Q on the server, empty Recv-Q on the client). py-spy dump of the server would show whether the handler thread is in a socket write. The server ran in Docker, so Docker's port publishing is in the path.

    Possible fixes: a write deadline on the SSE socket, so a stalled client raises an error instead of blocking; and a watchdog that does not depend on the consumer pulling tokens.

    Observations

    • The engine generated about 1,700 tokens after the server's last progress line. If the analysis above is right, those lines and the engine's DONE reached the server's queue, but the request thread did not read them until the client disconnected.
    • The server's engine_silence_s safety net did not fire in 15 minutes. There is no "the engine said nothing" line.
    • No engine restart was needed: the next request ran at normal speed 3 s later.
    • Earlier on 0.1.45, at 128K context with swap on, we had four stalls of the other kind, where the safety net did fire ("the engine said nothing for 329/454/569/698 s"). We did not keep the engine logs for those.
    • The engine also warns of 323–459 MiB of free VRAM at request start (Engine hangs at layer 48 during decode when VRAM headroom drops below ~500 MiB #2065 warning, suggesting --vram-reserve-mib 896). Decode stayed at 101 tok/s through this request, so it does not look related.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions