fix(server): fail-fast unschedulable KV waits

[bakon11]

Summary

Hermes-class clients can send huge system prompts. With default KV (256×32=8192 tokens) oversized prompts never admit under full_sequence_must_fit and used to sit in waiting forever (model_executed=0, GPUs idle).

• Abort waiting requests that cannot ever get KV (fail-fast finish)
• Does not clamp max_tokens — main already treats non-positive max_tokens as unset (SERVE-MAXTOKENS-UNSET)
• Scheduler + engine/core_proc paths covered; unit test added
• Docs: ENVIRONMENT.md (VT_ENGINE_STEP_LOG), USAGE.md scheduler fail-fast section

Land order

1. feat(rocm): V1 sampling ops for Hermes EngineCore #234 ROCm V1 sampler + parallel RandomSample (Hermes chat finish + temp>0 decode)
2. This PR (fix(server): fail-fast unschedulable KV waits #227) KV fail-fast
3. fix(server): SSE keepalives via collector timed wait #316 SSE keepalives
4. feat(gemma4/rocm): FP8 resident MoE + SharedK-WMMA (split from #228) #317 Gemma4/ROCm FP8 MoE / SharedK-WMMA (split from closed feat(gemma4/rocm): FP8 resident MoE + SharedK-WMMA prefill (RDNA4) #228)

Test plan

• Local unit: scheduler unschedulable wait aborts
• Local gates: doc-checkpoint, env-doc, device-leakage, pr-size, agent-record
• CI green after tip-of-main rebase
• Manual: prompt that exceeds num_blocks×block_size finishes with clear error (no infinite wait)

TESTERS WANTED (BF16/FP16 MoE)

Need multi-GPU ROCm hosts with host RAM ≫30G on MoE (Gemma-4-26B class). Dense 12B is not a MoE proxy.

[bakon11]

TESTERS WANTED — BF16 / FP16 MoE long-prompt / KV path on ROCm

This PR is quant-agnostic (scheduler fail-fast when KV cannot admit a wait + max_tokens clamp). Lab soak used FP8 Gemma-4-26B MoE + large Hermes-style prompts on 2× R9700.

We cannot reliably run BF16 MoE 26B here (~52 GiB weights, ~30 GiB host RAM). Dense 12B BF16 is not a valid MoE stand-in for expert/KV pressure at SOUL-scale prompts.

Please test if you can load BF16/FP16 MoE on ROCm

1. Short prompt — baseline OK
2. Large system prompt (tens of k tokens) with num_blocks / max_model_len deliberately too small — expect fail-fast error, not multi-minute hang with unfinished>0 / no progress
3. Same large prompt with adequate KV — completes or streams
4. max_tokens=-1 or huge max_tokens — clamped / accepted sanely (see also feat(rocm): V1 sampling ops for Hermes EngineCore #234 for Hermes -1 mapping)

Report

GPU + ROCm, model/dtype, max_model_len/num_blocks, hang vs clean error, any EngineCore death.

Pairs with #234 (sampler) and #228 (FP8 MoE kernels; separate lane).

[localai-org-maint-bot]

The fail-fast behavior is important, but the scheduler and serving changes need regression coverage before merge. Please add tests proving an impossible full-sequence admission terminates with the intended error (rather than waiting forever), an adequately sized request still admits, and max_tokens=-1/oversized values follow the documented clamp. Please also bring the branch onto current main and clear the repository gates.

[bakon11]

Addressing CHANGES_REQUESTED (localai-org-maint-bot)

Regression coverage added

Test	Asserts
Scheduler.abort_unschedulable_waiting: aborts prompt that cannot fit KV	Tiny num_blocks=4 + 200-tok prompt → aborted with kFinishedAborted, unfinished=0
… leaves admittable waiters alone	Large pool → empty abort list; schedule() still admits
… no-op while running is non-empty	Running non-empty → huge waiter not aborted yet
CompletionRequest max_tokens=-1 normalizes…	→ positive default (4096)
ChatCompletionRequest max_tokens=-1…	same
CompletionRequest max_tokens=0…	→ positive before PostInit

Also fixed CompletionRequest path to normalize max_tokens<=0 the same way chat already did (Hermes/-1).

Lab run (HIP build):

test_scheduler --test-case='*abort_unschedulable*'  → 3 passed
test_openai_protocol --test-case='*max_tokens*'     → 3 passed

Docs / gates

USAGE already documents the fail-fast + clamp on this branch. Will rebase onto current main after #234 lands (merge order: #234 → #227 → #228).

[bakon11]

Rebased onto current main — pr-size failed with base must be an ancestor of head. Local doc/agent gates green after rebase.

[bakon11]

Fixed agent-record: documented VT_ENGINE_STEP_LOG in ENVIRONMENT.md (was read in core_proc step heartbeat).

[localai-bot]

Reviewed on CUDA. The deadlock fix is good and I want it — two findings before merge, one of which you also have in #234.

Verified (GB10 sm_121a, rebased on current main)

test_scheduler             433/433
test_openai_serving        534/534
test_qwen27_paged_engine   235/235   (SACRED)
test_qwen36_paged_engine   315/315   (SACRED)

The good part

abort_unschedulable_waiting() is correctly designed, and the guard is the reason:

if (!running.empty() || waiting == nullptr || waiting->empty()) return;

Only firing when nothing is running is exactly right — it's what makes "cannot ever be admitted" a sound conclusion rather than a guess, because no running request can later free blocks. Probing with allocate_slots and then freeing the trial, plus one reset_prefix_cache() attempt before giving up, is the careful order. And the diagnostic naming prompt_tokens / max_model_len / free_blocks / block_size is what someone hitting this at 3am actually needs. An infinite unfinished>0, model_executed=0 spin with the GPU idle is a genuinely bad failure mode and this converts it into a clear error.

Finding 1: the probe inflates prefix-cache stats

auto computed = kv_cache_manager->get_computed_blocks(*request);

get_computed_blocks carries a prefix_cache_stats.record side effect. The codebase already learned this and grew a pure variant specifically to avoid it — KVCacheManager::num_matched_prefix_tokens (kv_cache_manager.cpp:151), whose own comment says:

Pure read of the longest cached-prefix match — the same lookup get_computed_blocks performs, MINUS the prefix_cache_stats.record side effect (so LPM ordering never double-counts) and minus block allocation.

Your probe runs whenever running is empty with something waiting, i.e. potentially every step through a stall, so it double-counts queries/hits repeatedly and corrupts the very metric someone would look at while diagnosing this deadlock. Use num_matched_prefix_tokens() for the probe, and take the real get_computed_blocks only on the admission path in schedule().

Finding 2: max_tokens <= 0 should map to UNSET, not 16

sp.max_tokens = default_max_tokens.value_or(16);
if (!sp.max_tokens.has_value() || *sp.max_tokens <= 0) sp.max_tokens = 16;

Same issue I raised on #234, and more severe there because the floor is 16 rather than 4096. We already implement "unlimited" correctly one layer down, mirroring vLLM 1:1 (input_processor.cpp:175-180, mirroring input_processor.py:317-321):

if (!params.max_tokens.has_value()) {
  const int64_t seq_len = static_cast<int64_t>(prompt_token_ids.size());
  params.max_tokens = static_cast<int>(max_model_len_ - seq_len);
}

So -1 should become std::nullopt, which routes there. As written, a Hermes client asking for "unlimited" can get 16 tokens back with finish_reason=length, indistinguishable from a real limit.

Note #227 and #234 both patch this same spot and will conflict with each other. Worth fixing it in one of them and rebasing the other.

Fix those two and I'll re-run this set and merge — the scheduler work is the valuable half and I don't want it stuck behind the clamp.

[localai-bot]

Heads-up: the max_tokens clamp is now fixed on main as 2d2bdd04 (row/SERVE-MAXTOKENS-UNSET), so please drop it from this PR and rebase — otherwise the three PRs conflict over one spot.

A non-positive max_tokens (or max_completion_tokens) is now treated as unset on both request paths, which routes to max_model_len - seq_len in input_processor.cpp:175-180, mirroring vllm input_processor.py:317-321. No constant, no truncation of the long-context request that asked to be left unlimited.

RED before / GREEN after on dgx, the new test built against unpatched main:

before: THREW 'max_tokens must be at least 1, got -1';  28/29 cases, 2 assertions failed
after:  29/29 cases, 179/179 assertions

test_openai_protocol now pins the semantics (−1 and 0 unset on both paths, positive unchanged, and −1 yielding to a serving default). Semantics documented in docs/USAGE.md.

Everything else in your PR stands — this is only about the shared hunk.

[bakon11]

Rebase + review fixes (addressing CHANGES_REQUESTED)

Rebuilt tip-of-main as $(git rev-parse --short HEAD).

Dropped

• All max_tokens clamp / floor hunks — main already treats non-positive as unset (2d2bdd04) → max_model_len - seq_len. No more conflict with feat(rocm): V1 sampling ops for Hermes EngineCore #234.

Finding 1 fixed

• abort_unschedulable_waiting probe now uses num_matched_prefix_tokens() only (no get_computed_blocks side-effect on prefix_cache_stats). Real admission path in schedule() still uses get_computed_blocks.

Kept

• Fail-fast abort when running empty and allocate_slots cannot admit under full-sequence reserve (+ one prefix-cache reset attempt)
• Scheduler regression tests
• VT_ENGINE_STEP_LOG documented (core_proc heartbeat)

Local gates: device-leakage, public-doc-tables, doc-checkpoint, env-doc, pr-size — OK.

[bakon11]

Rebased onto latest main — tip 3a94808c. Title/body updated: no max_tokens clamp (main already unset). Local gates green. Please re-run CI (prior arm64 fail looked run-related; watching fresh checks).

[bakon11]

Tip-of-main rebuild (clean fail-fast only)

Rebuilt as single commit on current main (3286f6fd).

Included

• Scheduler::abort_unschedulable_waiting() + 3 regression tests
• EngineCoreProc: call abort after post_step (spec drafts preserved — previous tip accidentally deferred/removed it)
• Optional VT_ENGINE_STEP_LOG heartbeat + ENVIRONMENT/USAGE notes

Explicitly NOT included (would clobber main)

• No metrics/timestamp reverts (/metrics is dead on the production server: AsyncLLM never folds IterationStats into the logger #277 path kept)
• No max_tokens clamp
• No LogPrefill / serving SSE changes

Local gates green. Please re-run CI.

[bakon11]

CI hygiene 2026-08-11: rebased onto origin/main (60e71a0). Local gates green (doc-checkpoint, env-doc, agent-record, pr-size, device-leakage). Land order remains #234 → #227 → #316 → #317.

[bakon11]

Rebased onto origin/main c70f42b9 (main moved +2 during CI). Local gates green. Land order unchanged: #234 → #227 → #316 → #317. PR bodies refreshed (RandomSample note on #234; #228 closed in land path).

[bakon11]

@localai-org-maint-bot Status check against CHANGES_REQUESTED / localai-bot notes:

1. Prefix probe — abort_unschedulable_waiting uses num_matched_prefix_tokens() (no get_computed_blocks side effect on the stall probe). Real admission still uses get_computed_blocks in schedule().
2. max_tokens floor — dropped from this PR; main already has non-positive → unset (2d2bdd04 / SERVE-MAXTOKENS-UNSET).
3. Regression tests in tests/vllm/v1/test_scheduler.cpp:
   • aborts prompt that cannot fit KV
   • leaves admittable waiters alone
   • no-op while running is non-empty

Sanitize ASan/TSan reds match the ambient main baseline on every open PR — not unique to this tip. Happy to rebase again if main moves.

[localai-bot]

The defect you reported is fixed on main as afc754e6a191 — but with a different remedy than this PR's, so it is worth saying exactly what happened rather than just closing.

You were right about the bug: a prompt larger than the KV pool is admitted, never allocates, and the engine spins at model_executed=0 with an idle GPU and a client hanging on nothing. That is real and it is now closed.

What was not taken, and why. abort_unschedulable_waiting decided admissibility by calling allocate_slots and freeing the trial allocation. That is not side-effect-free. With caching enabled and delay_cache_blocks=false, allocate_slots commits the trial blocks to the prefix-cache index via cache_blocks(...), and block_pool.cpp's free_blocks deliberately keeps hashed blocks in cached_block_hash_to_block so they stay matchable. The trial therefore publishes block hashes for KV that no forward pass ever wrote, and the next request with that prefix hits them.

That is measured, not theoretical — two of us found it independently. One probe of a 32-token waiter made an identical later request match 16 tokens of never-computed KV; the other measurement turned a 64-token prefill into a 16-token one "matching" 48 tokens of uninitialized KV. Same mechanism.

Two smaller things in the same function: kWaitingForRemoteKvs requests already own blocks an in-flight transfer is writing into, and free(*request) frees all of a request's blocks, not the trial's; and the num_new_tokens <= 0 branch aborted such a request "defensively", which is the opposite of correct for one whose tokens are all already computed.

What landed instead are the two guards vLLM actually has, neither of which existed here — _check_enough_kv_cache_memory at startup (a pinned --max-model-len the pool cannot hold is refused with upstream's message and numbers; an unpinned one is auto-fitted down and logged) and _validate_prompt_len at admission (HTTP 400, a client mistake rather than a 500 or a finish reason). Together they make the post-condition true that the scheduler already assumed: anything admitted fits, so the wedge cannot form. Note that upstream's scheduler deliberately peeks and breaks and never aborts an unschedulable waiter.

Kept from this PR, repaired: the two-phase prefill-progress logging (begin at schedule, running/done after execute_model, so elapsed_s is wall time rather than the cost of scheduling) and the VT_ENGINE_STEP_LOG heartbeat that distinguishes an idle engine from a stalled one. Its progress map leaked one entry per request for the process lifetime and is bounded now.

Closing as fixed-otherwise. The report was good and the diagnosis was right; only the remedy changed.