fix: idle work must not starve real requests — the stuck context probe

[REPPL]

Fix: idle work must not starve real requests — the context probe on a non-chat model

Resolves iss-2609211334563318, iss-2609211334570516, iss-2609211334576018 (moved to resolved/ in this change). Pre-emption — itd-2609211335097114 — stays a draft and is not implemented or approximated here.

The incident, from the live box's logs (v0.9.1, 2026-09-21)

Every chat request was refused 503 for six hours. The context probe queued mlx-community/GLM-OCR-bf16 (pipeline image-to-text, chat: false) at 09:36 and loaded it 32 times, every eleven minutes, until 15:38. The child's log is one traceback: mlx_lm server raised ValueError: Model type glm_ocr not supported (chained from ModuleNotFoundError: No module named 'mlx_lm.models.glm_ocr') in its generate thread on the pool's own readiness completion, while its httpd kept answering, so the pool's one readiness request blocked for the whole ten-minute ReadyTimeout — did not become ready within 10m0s, model failed to load, unloaded reason=load_failed — and the probe read the resulting 503 as "no room", kept its bounds and re-queued the model for the next idle tick. Only the maintainer's Unload at 15:49 ended it.

Why a loading 2.2 GB model was charged 82.46 GB: not a property of loading. The pool charges a model from the moment its entry exists (startLocked: charge: need), and the charge is LoadCostOf(weights, KV per token × served window × concurrency). With no served_context set, the default served window is derived to fill the budget (App.servedWindowAt: (budget − weights and headroom) / (KV per token × sequences), capped at the declared window). GLM-OCR declares a window large enough that the derived one filled the budget, so its charge ≈ the whole budget while loading and would have been the same once loaded. Left as it is, per the brief.

The three fixes (one commit each, test-first)

1. The probe considers only models the server offers to chat (52dcef7a). probeSources.Candidates() and App.MeasureNow read registry.Model.CanChat with the rule in force — the one home the archtest holds; nothing copied. Measure now on a chat: false model is refused 400 with the reason.
   • red: TestTheProbeConsidersOnlyChatModels — candidates = [org/chat org/ocr], want only the chat model / Measure now queued a model the server does not offer to chat
   • green: ok internal/app 0.243s
2. A load that cannot succeed fails in seconds, and a failed model is not retried by idle work (d3478a9f, 190d7172, 5ce44e45, eec93f2d).
   • The pool watches the per-model child log (runtime.LoadLogger, which the real launcher's execProcess satisfies via LogPath()) every 500 ms while its readiness request is out, reading a bounded 64 KiB tail; a traceback whose terminal line is ValueError|ModuleNotFoundError|ImportError cancels the wait (context.WithCancelCause) and the NotReadyError carries that line, bounded to 300 bytes with every path-shaped token blanked. BrokenPipeError and friends are deliberately not in the set — the child survives those.
     • red: TestAFatalLineInTheChildLogEndsTheLoadWaitAtOnce — the reason does not carry the child's own line: "org/ocr did not become ready within 30s" (30.3 s)
     • green: ok internal/runtime 0.745s
   • A load that never became ready is recorded on the model — registry.LoadFailure (reason + provenance: runtime, budget, concurrency, served window). While it stands: Candidates() skips it, selfTestServer.Ready() skips it, Probe.Due drops it from the queue, and modelSource.Resolve refuses it with a NotReadyError carrying the reason and the way out (so a client is refused at once, classed not-ready, text to entitled clients only). Lifted by a moved provenance (RefreshStaleness, at start and after every save), by a re-download, and by hand: Load and Measure now. The pool now tells the observer whether a failure was the model's own or interrupted (the entry taken out of the pool by another path — a client that hung up, an unload, an eviction); only the former is recorded. The card shows a did not load pill and the reason.
     • red (registry): build failed — undefined: LoadFailure, SetLoadFailure, LoadFailed; green: ok internal/registry 2.896s
     • red (app): build failed — a.recordLoadFailure undefined, a.ForgetLoadFailure undefined; green: ok internal/app 0.391s (TestALoadFailureIsRecordedWithItsProvenanceAndAnInterruptedLoadIsNot, TestAFailedModelIsSkippedByIdleWorkAndRefusedWithItsReason)
     • red (pool, interrupted): TestTheObserverIsToldWhetherALoadFailedOnItsOwnOrWasInterrupted — a load abandoned by its only waiter was reported as {… interrupted:false …}, want an interrupted failure; green: ok internal/runtime 1.036s
     • red (probe queue): TestAQueuedModelThatIsNoLongerACandidateIsDropped — the queue still holds [org/m]; green: ok internal/contextprobe 4.422s
     • red (card): TestTheCardSaysWhyAModelDidNotLoadAndHowToRetryIt failed on the line's text; green: ok internal/ui
   • The probe's ten-minute step floor is deliberately left (the one item of the brief not done). defaultStepTimeout is the gateway's own prefillBudget (which has the same ten-minute base) plus a minute: the probe's timer must not undercut the gateway's deadline or a step the gateway would have allowed is filed as prefill_deadline, and a step's request includes the cold load the pool allows ReadyTimeout (ten minutes) for — the probe unloads before every step. Lowering the floor to the body-derived figure (~2 min at the calibration size) would fail every large model's cold load as a deadline. With the fail-fast above, the floor no longer holds the server for anyone: a hung load ends in seconds.
3. The refusal names the holder (c9f75c6b, eec93f2d). selftest.Status gains Since; the gateway is handed Options.IdleJobs (wired in main.go to a.SelfTest.Status); a NoRoomError 503 to an entitled client — loopback, or key-admitted, the same predicate (g.entitled) the models list's residency fields use — gains: ; the memory is held by <model>, loading, which the context probe has been at for 4m12s — the server's own idle work, not the size of the model asked for. It is released when the run ends, or at once with Unload on that model's card — and Unload now does that even while the job's request is in flight (see the reviews). Only when the job's model is in pool.Resident(). The pool's own NoRoomError.Error() is unchanged and still names no model; an unentitled client still gets cannot serve this model right now; the message for a genuinely full budget is byte-for-byte what it was. The card's residency pill now says loading / loading for the context probe / held by the self-test instead of loaded for every resident model.
   • red: TestARefusalNamesTheModelAnIdleJobIsHolding — body = {"error":{"code":503,"message":"not enough memory to load another model, and no model in memory can be freed (limit 41.0 GB)",…}} (three subtests)
   • green: ok internal/gateway 1.196s
   • red (pill): TestTheResidencyPillNamesTheJobHoldingTheModel, TestTheCardIsBuiltFromTheResidencyLabel failed (function absent); green: ok internal/ui 8.920s

Hand check (scratch root, port 11999, loopback; branch build dessau-fix; the live server on 11535 never contacted)

Two copies of the small model were planted beside it: Fake-OCR-bf16 (registry entry with pipeline_tag: image-to-text, its config.json model_type set to glm_ocr so the real mlx_lm child raises the incident's own ValueError) and Fake-Chat-4bit (adopted, chat by template). Settings: context_probe: true, idle_threshold_sec: 60, upstream_header_timeout_sec: 1 (the gateway's own deadline override, to force a step timeout without a burner), decode_concurrency: 8, max_resident_bytes: 30 GB (one model's charge is 16.45 GB, so two do not fit).

• /v1/models: Fake-OCR-bf16 chat=False, the others chat=True.
• A client request for Fake-OCR: 503 in 1.005 s — mlx-community/Fake-OCR-bf16 could not load: ValueError: Model type glm_ocr not supported. — log model failed to load at once; no path in the body. The child's log holds the same traceback the live box's did.
• The second request: 503 in 0.6 ms, … did not load the last time it was tried (could not load: ValueError: Model type glm_ocr not supported); it is not tried again on its own until … press Load or Measure now …; /api/state carries load_failure with reason and provenance.
• POST /api/models/measure for Fake-OCR: 400 is not offered to chat, and the probe measures through chat completions.
• A restart with a changed budget and concurrency re-judged the mark and lifted it (measurements re-judged … Fake-OCR-bf16); POST /api/models/load lifted a fresh one (load_failure: null, model loading), the retried load failed fast again and re-marked it.
• With the probe on: at the first idle minute idle_jobs = {job: context-probe, model: Fake-Chat-4bit, step: calibrating at 1024 tokens, since: …} — never Fake-OCR (probe_queue empty throughout; no probe line for it in the log).
• While the probe held Fake-Chat (resident: [(Fake-Chat-4bit, loading, 16.45 GB)]), a client request for Qwen was refused in 1 ms with: not enough memory to load another model, and no model in memory can be freed (limit 30.0 GB); the memory is held by mlx-community/Fake-Chat-4bit, which the context probe has been loading for 0s — the server's own idle work, not the size of the model asked for. It is released when the run ends, or at once with Unload on that model's card. The probe then yielded (context probe paused … a request arrived), and the abandoned load left no mark on Fake-Chat (interrupted, not the model's failure).
• The probe resumed at the next idle minute; with the 1 s deadline three steps came back 504, and it ended context probe measured model=Fake-Chat-4bit window=8880 bound=prefill_deadline with resident: [], resident_bytes: 0 — the step timeout released the budget.
• After the review fixes, a second run from the rebuilt branch: with the probe holding Qwen with its request in flight (loading, in_flight 1, calibrating at 1024 tokens), POST /api/models/unload answered 200 in 52 ms (context probe paused … a request arrived; resident: []) — where the live box answered 409 twice.
• Stopped by pid each time; pgrep -f dessau-fix and pgrep -f mlx_lm both 0. Config, registry and models directory restored to their start state.

Reviews

Both ran on the diff before the PR; every finding applied or explicitly rejected, and the fixes landed in eec93f2d with their own tests.

Security review (security-reviewer): FIX_FIRST → applied.

1. MEDIUM — the traceback reader never reset inTraceback and read an unterminated final segment, so a stray ValueError: line after a survived traceback, or a line still being written, became a persistent verdict; and the timeout/signal verdicts are transient conditions made into a standing, restart-surviving refusal. Applied: the reader takes a terminal line only straight after a traceback's frames (indented lines), resets on any other line, and reads whole lines only (TestOnlyAFatalTracebackLineIsReadAsALoadFailure gained five cases); the timeout and signal-exit classes are recorded as transient — they stand for this process and are dropped at the next start (TestATransientLoadFailureDoesNotOutliveTheProcess); the child's own traceback and a non-signal exit status stand as before.
2. LOW — a local process can POST a fake traceback to the child's loopback port during the readiness window and the reader would take it. Accepted, no change: same trust class that can already plant registry.json or drive the child directly; no new privilege. Recorded in the decision line.
3. LOW — the reader's os.Open followed links and could block on a FIFO. Applied: O_RDONLY|O_NONBLOCK|O_NOFOLLOW, fstat kept.
4. LOW — the sanitiser leaked words of a path with spaces and passed control characters. Applied: control characters dropped; everything from the first path-shaped token to the last blanked as one <path>.
5. INFO — observer callbacks are unordered, so a late failure could re-mark a model a hand retry had lifted. Applied: recordLoadFailure skips a failure for a model the pool currently holds an entry for (the retry's own report decides).
6. INFO — provenance read at record time, not load start. Accepted, no change: a budget change during a ten-minute load records the mark under the provenance in force at its end; the next save re-judges it.

Ruthless review (ruthless-reviewer): FIX_FIRST → applied.

1. MEDIUM — the refusal, two doc pages and the changelog promised that Unload releases a held model, and the pool refused that Unload as busy while the job's request was in flight (the maintainer's two 409s on the live box). Applied (the honest option): Runner.Interrupt(model) ends the run as a yield; handleUnload asks for it first and waits, bounded, for the model to go. TestUnloadFromThePanelTakesTheModelBackFromTheProbe on the real gateway+pool+probe stack — red: Unload on the probe's model got 409: … org/m is serving 1 request(s); try again in a moment: model is busy; green: ok internal/gateway 0.351s. Plus TestInterruptEndsTheRunOnThatModelAsAYield.
2. MEDIUM — a one-off readiness timeout became a standing, restart-surviving refusal. Applied: the transient class above; recorded in the decision ledger.
3. LOW — Due could prune a Measure now queued between its candidate snapshot and its lock. Applied: a queue generation counter; pruning only against the queue the snapshot was read for.
4. LOW — a stale failure written after a person lifted it. Applied: the residency gate above.
5. LOW — "has been loading for 4m12s" was the run's age. Applied: the sentence now reads "held by , loading, which the context probe has been at for 4m12s".
   Checked clean by the reviewer: the cancellation path (WithCancelCause, watcher lifetime, cause read after Do), the waitReady reorder, the Interrupted distinction (including Close), RefreshStaleness' identity lift, Due vs rescan, the "/" guard, idleHolder's lock cost, the wiring in main.go, and that no test is tautological.

Definition of done

go test -race ./... green, gofmt -l . empty, go vet ./... clean, abcd docs lint 0 findings, abcd identity 0 adrift. Docs: docs/context-probe.md (which models, how long a step, what happens to a model that does not load, the holder on the card), docs/self-test.md, docs/models-list.md (the refusal rule). Changelog under [Unreleased], impact: fix. One decision line in .abcd/work/DECISIONS.md.