Skip to content

A request the scheduler can never admit hangs forever with zero bytes: our advertised max_model_len is one block larger than the servable KV, and the wedge is silent at both ends #1737

Description

@localai-bot

Follow-up to the sharper reproduction posted on
#931 on 2026-08-22, which was
hit on dgx:gpu0 and could not be pursued there because the box is off limits
under #1647. #931 itself is
closed and its fix (the SSE keepalive, #971) is on main; this is a different
defect that produces the same client-visible symptom.

The symptom reproduces off-GPU, on CPU, with a 125M model, in two flags

cmake -S . -B build-cpu -G Ninja -DCMAKE_BUILD_TYPE=RelWithDebInfo \
  -DVLLM_CPP_CUDA=OFF -DVLLM_CPP_BUILD_TESTS=OFF
cmake --build build-cpu --target server -j 12

VT_SERVER_VERBOSE=1 build-cpu/examples/vllm-server \
  --model ~/models/opt-125m-bf16-st --port 8144 --served-model-name model \
  --num-blocks 4 --block-size 16 &

curl -sS -m 150 -X POST http://127.0.0.1:8144/v1/completions \
  -H 'Content-Type: application/json' \
  -d '{"model":"model","prompt":"The capital of France is","max_tokens":56,"temperature":0}'

Measured, 2026-08-22, x86_64, main at 2f2a70925:

curl: (28) Operation timed out after 150001 milliseconds with 0 bytes received
http_status=000 time_total=150.001220 size=0

Zero bytes, no status line, no error body. The server stays up and /health
answers 200 throughout. This is byte-for-byte the client-side signature the #931
comment recorded on GB10.

What the server is doing, measured rather than inferred

/metrics, scraped during the stall — the capture the #931 comment says was
never taken:

vllm:num_requests_running{...}                       0.0
vllm:num_requests_waiting{...}                       1.0
vllm:num_requests_waiting_by_reason{...,reason="capacity"} 1.0
vllm:kv_cache_usage_perc{...}                        0.0
vllm:num_preemptions_total{...}                      1.0

The KV cache is 0% used and the request is still not admitted.

VT_SERVER_VERBOSE=1 gives the engine heartbeat, and it is the discriminator
between a wedged engine and a slow one:

INFO core-step begin unfinished=1 finished_pending=0
INFO core-step end model_executed=0 n_out=0 elapsed_s=0.000

48,285 such steps in one 150 s leg, none of which executed the model (48,284 of them also carried the admission refusal traced below). That is
the CPU equivalent of the 0 %, 11.43 W GPU reading in the #931 comment: the
work never reaches the device because nothing is ever scheduled.

The mechanism

With a scratch trace in the scheduler's waiting loop (not committed), the steady
state is identical on every one of those steps:

SCHED-CALL   step=49437 waiting=1 running=0
ADMIT-CAND   id=cmpl-0-0 status=6 num_tokens=49 cached=32 new=17 budget=2048 chunked=1
ADMIT-REFUSED id=cmpl-0-0 status=6 num_tokens=49 computed=32 new=17 lookahead=0 running=0 free_blocks=3

status=6 is kPreempted. The sequence is:

  1. --num-blocks 4 --block-size 16 makes the server advertise
    max_model_len = 64: INFO auto-fit max_model_len: reduced from 2048 to 64 to fit the KV cache (4 blocks x 16 tokens).
  2. The request (6 prompt + 56 requested = 62 tokens) is accepted, because 62
    is inside the advertised 64. refuse_oversized_prompt only bounds the prompt.
  3. It prefills and decodes 43 tokens. At 49 tokens the pool is exhausted. It is
    the only request in flight, so the scheduler preempts itself
    (num_preemptions_total 1), frees every block, resets
    num_computed_tokens to 0 and prepends it to the waiting queue —
    Scheduler::preempt_request, mirroring scheduler.py:546-572.
  4. On resume it needs blocks for all 49 tokens. The prefix cache returns 32 of
    them, 17 remain, and 4 blocks are required against 3 free. Refused.
    Forever.

Only 3 blocks are ever allocatable out of the 4 configured, because block 0 is
the reserved null block
(block_pool.cpp:53-57, :453 "Subtract 1 to account for the null block"). So the servable context is
(num_blocks - 1) * block_size = 48 tokens while ResolveMaxModelLen
(model_loader.cpp:1508) computes available = num_blocks * bytes_per_block
and advertises 64. A request that lands in that last block is admitted and can
then never be re-admitted.

The boundary is exact and reproducible:

--num-blocks advertised max_model_len prompt+max_tokens result
2 32 14 200, 8 tokens
2 32 17 200, 11 tokens
2 32 18 hangs, 0 bytes
2 32 30 hangs, 0 bytes
4 64 62 hangs, 0 bytes after 43 tokens
1 16 22 hangs, 0 bytes, model_executed=0 from step 1 (zero allocatable blocks)

The --num-blocks 1 row is the one that matches the #931 comment most closely:
nothing is ever scheduled, so the device is never touched at all.

Two defects, and they should be separated

1. A permanently unschedulable request is never failed. Whatever the reason,
the client waits forever on an open connection with zero bytes, the server logs
nothing at default verbosity, and the engine burns ~1000 no-op steps a second.
vLLM's own v1 scheduler shares the break-and-leave-waiting shape
(sched/scheduler.py:934-938 at the pinned 555967922), so changing this is a
divergence and needs a decision, not a patch.
It is recorded here because it is
what turns every KV-admission problem into a silent hang.

2. The advertised context exceeds the servable context by one block. This one
is ours: ResolveMaxModelLen reconstructs an "available memory" figure from our
own resolved block count, and that reconstruction counts a block the BlockPool
will never hand out. Correcting it to (num_blocks - 1) would make the request
above stop cleanly at max_model_len with finish_reason="length" instead of
wedging.

It is not a small in-flow fix, and it is not being made here:
tests/vllm/entrypoints/test_loaded_engine_dense.cpp:635-660 currently pins the
present arithmetic (params.num_blocks = 1 asserting max_model_len == 32), so
the change tightens an existing assertion and needs its own row, spec and fresh
review. That same file's "an over-long prompt is REFUSED, not left waiting"
case shows the prompt half of this hang class was already closed once; this is
the generation half.

What this does and does not say about the GB10 report

It does not establish that defect 2 is what the #931 comment hit. That report
used a 22-token request against a 27B checkpoint, which is nowhere near any
advertised context. What it establishes is the shape: on that box the request
was never scheduled at all, which is the --num-blocks 1 row above — a pool with
no allocatable capacity — and that is exactly what
#1647 would produce.

The one command that settles it, and it needs no new code: restart that
server with VT_SERVER_VERBOSE=1 (or VT_ENGINE_STEP_LOG=1) and read the
heartbeat during the stall. model_executed=0 with a non-zero unfinished
count, step after step, means the engine is spinning on work it can never
schedule, and the search is over the KV pool rather than over AsyncLLM. If the
heartbeat instead shows model_executed=1 throughout, this issue is the wrong
lead and the fault is elsewhere.

The speculative-vs-non-speculative discriminator in the #931 comment is
consistent with a KV-sizing cause — a speculative config changes the pool
geometry — but nothing here measures it, and it is not asserted.

What was ruled out here

Evidence

Logs, /metrics scrapes, thread stacks and the per-arm probe output are under
the session scratchpad fix931-hang/; the scratch scheduler trace was reverted
byte-for-byte (md5 6b88fd41533c097eaefabc7f8f2936d4 before and after).

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