#18505·ollama

[BUG] MLX nvfp4: admitted request stalls in prefill at processed=total-1 with zero tokens for minutes under sustained single-slot load; only runner SIGTERM recovers

Author: Etoile04Created Sep 17, 2026Updated Sep 17, 2026

Summary

Under sustained back-to-back load through a single slot (OLLAMA_NUM_PARALLEL=1), an admitted request on an MLX nvfp4 model intermittently stops making any progress — no further prompt-processing progress marks, no generated tokens — for minutes, while the mlx runner subprocess keeps spinning at 71–79% CPU. Client timeouts eventually cancel the request. The stall is runner-state-dependent, not content-dependent: the same 7,213-token request froze twice and then completed in 12.6 s on the third attempt (full log trace below).

A sharp fingerprint: in the two stalled attempts, prefill progress stopped at processed = total − 1 tokens (5434/5435, then 3/4) and never transitioned to generation.

Environment

  • ollama 0.34.0 (macOS app)
  • MLX engine initialized "MLX version"=0.32.2-27-g37c26e5 device=gpu (mlx_metal_v4, xgrammar v0.2.5)
  • macOS 26.6.2 (25G83), Apple M4 Max, 128 GiB RAM
  • Model: qwen3.5:4b-nvfp4 (Qwen3_5ForConditionalGeneration, 923 tensors)
  • Server env (relevant): OLLAMA_NUM_PARALLEL=1, OLLAMA_MAX_QUEUE=512, OLLAMA_CONTEXT_LENGTH=262144, OLLAMA_KEEP_ALIVE=5m0s, OLLAMA_DEBUG=INFO
  • A second model (nomic-embed-text served via llama-server) runs on the same ollama server for embeddings — it stayed fully healthy through every stall (see below)

Symptom

Workload: a document-extraction pipeline drives the single slot continuously for ~60–100 min windows with 2–9K-token prompts (~4 concurrent client tasks queueing into the one slot). During these windows, intermittently (at least once per window in our observations):

  1. A request is admitted (prefix-cache hit logged).
  2. Prefill progress marks appear normally for the first ~1.5 s, then stop at processed = total − 1.
  3. No further progress marks and no tokens for minutes, until the client deadline cancels.
  4. The runner subprocess stays at 71–79% CPU throughout (observed via ps during stalls).
  5. Requests admitted after the stall also hang; only SIGTERM of the runner subprocess recovers (see Recovery).

Healthy request latencies escalate in the minutes before each stall: 45 s → 1m08 → 1m15 → 1m26 → 1m42.

Key evidence — same prompt, three attempts (2026-09-17, log timestamps +08:00 local)

Attempt 1 — stalls in prefill at 5434/5435, then silent for 4m55s:

11:31:38.298  prefix_cache.go:125  msg="cache hit" total=7213 matched=1781 cached=1778 left=5435
11:31:39.644  pipeline.go:223       msg="Prompt processing progress" processed=2048 total=5435
11:31:40.996  pipeline.go:223       msg="Prompt processing progress" processed=4096 total=5435
11:31:41.892  pipeline.go:223       msg="Prompt processing progress" processed=5434 total=5435
              <4 min 55 s of silence — no further marks, no tokens; runner at 71-79% CPU>
[GIN] 11:36:36 | 500 | 5m0s | POST "/api/chat"
11:36:36.645  server.go:235  ServeHTTP POST /v1/completions took=5m0.0236905s status="200 OK"
11:36:36.663  runner.go:276   msg="Request terminated" error="context canceled"

Attempt 2 — same prompt, prefix cache now full (left=4); stalls at 3/4, silent ~5m:

11:36:38.699  prefix_cache.go:125  msg="cache hit" total=7213 matched=7213 cached=7209 left=4
11:36:38.761  pipeline.go:223       msg="Prompt processing progress" processed=3 total=4
              <silence>
[GIN] 11:41:38 | 500 | 5m0s | POST "/api/chat"
11:41:38.763  server.go:235  ServeHTTP POST /v1/completions took=5m0.081243709s status="200 OK"
11:41:38.797  runner.go:276   msg="Request terminated" error="context canceled"

Attempt 3 — same prompt again, left=1; completes normally in 12.6 s:

11:41:42.814  prefix_cache.go:125  msg="cache hit" total=7213 matched=7213 cached=7212 left=1
11:41:55.378  server.go:235  ServeHTTP POST /v1/completions took=12.571921833s status="200 OK"
11:41:55.384  pipeline.go:105  msg="peak memory" size="9.50 GiB"

A second stall three minutes later — four parallel client tasks all hit their 240 s deadline in the same millisecond:

11:44:50.861  server.go:235  ServeHTTP POST /v1/completions took=43.036792ms status="200 OK"   <- last healthy completion
              <silence>
11:48:51.021  server.go:235  ServeHTTP POST /v1/completions took=3m59.944809417s status="200 OK"
11:48:51.021  server.go:235  ServeHTTP POST /v1/completions took=3m59.893538917s status="200 OK"
11:48:51.021  server.go:235  ServeHTTP POST /v1/completions took=3m59.841989584s status="200 OK"
11:48:51.021  server.go:235  ServeHTTP POST /v1/completions took=3m59.790206583s status="200 OK"

Why we believe this is a runner defect, not load/OOM/content

  • Not OOM: sched.go "system memory" lines logged through the stalls show 36.8–51 GiB free of 128 GiB and free_swap="0 B"; no Metal allocation failures anywhere in the logs. Per-request peak memory across the whole window was 9.5–14.8 GiB.
  • Not a host-wide stall: the co-tenant embedding model (llama-server on the same ollama server) kept serving /v1/embeddings 200s in the same milliseconds the MLX slot was frozen, and /v1/status on the main server kept answering in <100 ms.
  • Not prompt content: the same 7,213-token prompt froze twice and completed on the third attempt, minutes apart (trace above).
  • Recurring: the same fingerprint (silence + deadline-exact took=3m59.9x/5m0.0x cancel clusters) appears in every sustained-load window we have driven since Sep 11 (Sep 11, 13, 15, 16, 17), including windows with no other tooling involved.

Recovery behavior

  • Client cancellation does not clear the stall — requests admitted afterwards hang too.
  • ollama stop qwen3.5:4b-nvfp4 returns promptly but leaves the runner PID alive and the slot frozen.
  • Only SIGTERM of the mlx runner subprocess resets it (model reloads in ~79 s).

Reproduction sketch

OLLAMA_NUM_PARALLEL=1 ollama serve
# drive the single slot continuously for 1-2 h with ~4 concurrent clients,
# each POSTing /api/chat with 2-9K-token prompts back-to-back
# -> at least one admitted request stalls as described above

We're happy to re-run with OLLAMA_DEBUG=DEBUG and capture a sample/spindump of the runner subprocess on the next occurrence (it reproduces most days) — please let us know what diagnostics would help most.

Possibly related: #16030 (nvfp4 slow under memory pressure — ours stalls with tens of GiB free), #18269 (nvfp4 MLX variant stuck in "Stopping…" state).