Skip to content

record(SERVER-STALL-1737): the zero-byte hang reproduces off-GPU, and its proposed fix is a divergence (#1737) - #1771

Draft
localai-bot wants to merge 3 commits into
mainfrom
row/FIX-SERVER-STALL-1737-ORACLE
Draft

record(SERVER-STALL-1737): the zero-byte hang reproduces off-GPU, and its proposed fix is a divergence (#1737)#1771
localai-bot wants to merge 3 commits into
mainfrom
row/FIX-SERVER-STALL-1737-ORACLE

Conversation

@localai-bot

@localai-bot localai-bot commented Aug 23, 2026

Copy link
Copy Markdown
Collaborator

The 2026-08-22 comment on #931 reported a single /v1/completions request that never returns on dgx:gpu0 — zero bytes, no status line, GPU idle. #931 itself is closed and its cause (the SSE keepalive, #971) is on main, and the failing request is non-streaming, so it never reaches that frame. This branch carries the record of the second defect behind that signature, filed as #1737, together with a correction to it.

The correction, which is the reason this is not an implementation task

The first commit records the off-by-one as ours and proposes correcting ResolveMaxModelLen to (num_blocks - 1). Read at the exact parity pin 5559679229bc, upstream carries the same arithmetic end to end:

  • kv_cache_utils.py:2144-2158 reconstructs available_memory = override * bytes_per_block from the full block count whenever num_gpu_blocks_override is set. That is byte-for-byte what model_loader.cpp:1505-1507 does.
  • kv_cache_coordinator.py:90-95 then builds BlockPool(num_gpu_blocks=kv_cache_config.num_blocks, ...) with no + 1.
  • block_pool.py:188-191 pops block 0 out of the free queue as the null block, exactly as block_pool.cpp:53-57 does.

So upstream's allocatable capacity is num_blocks - 1 against an advertised max_model_len that assumes num_blocks — the same one-block overhang the record attributes to us. The self-preemption half matches too: sched/scheduler.py:607-609 preempts the sole request, breaks, and leaves it waiting, which is the :934-938 shape the record already identified as shared.

Both halves are mirrored behaviour. Subtracting the null block is a decision about diverging from the reference, not an in-flow bug fix, and the next reader must not pick it up as one. The original ## Owed entry is left in place rather than rewritten, because the shape of the error — reading our own code against a hang and concluding the arithmetic was ours without reading the oracle's — is the lesson.

The hang reproduces independently, off-GPU

Fresh CPU build (-DVLLM_CPP_CUDA=OFF, RelWithDebInfo, x86_64) on facebook/opt-125m, one binary, three legs:

leg flags result
control --num-blocks 64 --block-size 16, max_tokens 16 HTTP 200, 13.2 s, finish_reason="length"
wedge --num-blocks 4 --block-size 16, max_tokens 56 curl: (28) ... 0 bytes received, http_status=000 size=0

/health answers 200 throughout the wedge and the server logs only its startup lines plus INFO auto-fit max_model_len: reduced from 2048 to 64 to fit the KV cache (4 blocks x 16 tokens). That confirms the first commit's finding on a second machine and a second build.

One hypothesis, falsified by measurement rather than dropped

Upstream's serving layer hard clamps max_tokens to max_model_len - input_length: get_max_tokens (entrypoints/serve/utils/api_utils.py:170-206) returns the min over model headroom, request value and operator ceiling, and completion/serving.py:163-181 feeds it to to_sampling_params, which at completion/protocol.py:358 assigns it unconditionally rather than as a fallback. We never do: serving_completion.cpp:241 and serving_chat.cpp:767 call to_sampling_params() with no argument, and InputProcessor fills max_tokens only when unset (input_processor.cpp:268-271, :304, :340).

The predicted consequence was that an over-long max_tokens would wedge the same way. It does not. Measured at --num-blocks 8 --block-size 16 --max-model-len 64 with max_tokens 5000: HTTP 200 in 62.8 s with finish_reason="length" and 58 generated tokens. Our engine stops at max_model_len by another route, so the mechanism differs from upstream while the client-visible result matches. There is no defect there, and the adjacent operator-ceiling arm of the same upstream function stays open as #544.

The wedge also survives SIGTERM

Seen only because the reproduction's processes had to be reaped. After the
client's 90 s timeout the harness sent SIGTERM to the wedged server; it logged
server: shutting down on signal 15 and did not exit — still alive 53
minutes later, State: S, 23 threads, ~5.2% average CPU, cleared only by
SIGKILL. Both healthy legs of the same harness exited on the identical signal.

That is a one-variable contrast with n=1 on each arm, not a controlled
experiment, and the shutdown path was not traced; what is established is that
the signal was received and acknowledged and the process still never
terminated. It raises the operational cost of the wedge above a hung client: a
supervisor that restarts on SIGTERM hangs with it.

What this does not do

No product code changes. The wedge is not fixed, because fixing either half diverges from the pinned reference and that is a decision rather than a patch. The measurement guard #931 owed — require_complete_request_set, which refuses to derive a rate from a record with failed != 0 — already landed with #971 and is unchanged here.

FOLLOWING_AGENTS_PROTOCOL

Following-Agents-Protocol: true
AI-Assisted: true
Assisted-by: AGENT:claude-opus-5 [Claude Code]

mudler added 3 commits August 23, 2026 08:26
…d the advertised context is one block too large (#1737)

The 2026-08-22 comment on #931 reported a single `/v1/completions` request that
never returns on `dgx:gpu0` -- zero bytes, no status line, GPU idle -- and could
not pursue it, because that box is bounded by #1647. #931 itself is closed and
its cause (the SSE keepalive, #971) is on main, and the failing request is
non-streaming, so it never reaches that frame. This is a second defect with the
same client-visible signature, and it does not need the box.

It reproduces on a CPU build of `vllm-server` against `facebook/opt-125m` in two
flags. With `--num-blocks 4 --block-size 16`, one non-streaming request of 6
prompt plus 56 output tokens returns `curl: (28) ... with 0 bytes received`
after 150 s while `/health` answers 200. Scraped during the stall, `/metrics`
reads `num_requests_waiting 1`, `num_requests_running 0`,
`kv_cache_usage_perc 0.0` and `num_preemptions_total 1`: the KV cache is empty
and the request is still refused. `VT_SERVER_VERBOSE=1` emits 48,285 consecutive
`core-step end model_executed=0` heartbeats, which is the CPU equivalent of the
`0 %, 11.43 W` reading in that comment.

The mechanism was measured with a scratch scheduler trace, since reverted
byte-for-byte. `ResolveMaxModelLen` reconstructs `available` as
`num_blocks * bytes_per_block` and advertises
`max_model_len = num_blocks * block_size`, while only
`(num_blocks - 1) * block_size` is allocatable, because block 0 is the reserved
null block. A request inside the advertised context is therefore admitted,
decodes until the pool is exhausted, preempts itself as the only request in
flight, and is refused re-admission on every step thereafter. The boundary is
exact: at `--num-blocks 2` a 17-token request returns 200 and an 18-token one
hangs.

Nothing is fixed here, and the reason is the in-flow rule's own criterion. The
silent-wedge half is shared with vLLM, whose v1 scheduler breaks out of the same
loop and leaves the request waiting, so removing it is a divergence that needs a
decision rather than a patch. The off-by-one half is ours, but correcting it
tightens an assertion `test_loaded_engine_dense.cpp` currently pins, so it needs
its own row, spec and fresh review.

It is not established that this arithmetic is what the #931 comment hit, and the
records say so: that request was 22 tokens against a 27B checkpoint, nowhere
near any advertised context. What transfers is the shape, and a discriminator
that needs no new code -- read the `VT_SERVER_VERBOSE=1` heartbeat during the
stall, because `model_executed=0` against a non-zero `unfinished` count puts the
search on the KV pool rather than on `AsyncLLM`.

FOLLOWING_AGENTS_PROTOCOL

Following-Agents-Protocol: true
AI-Assisted: true
Assisted-by: AGENT:claude-opus-5 [Claude Code]
…roposed fix is a divergence (#1737)

The record this commit corrects calls the advertised-context overhang "ours" and
proposes correcting `ResolveMaxModelLen` to `(num_blocks - 1)`. Read at the exact
parity pin `5559679229bc`, upstream carries the same arithmetic end to end:
`kv_cache_utils.py:2144-2158` reconstructs `available_memory` from the FULL block
count under `num_gpu_blocks_override`, `kv_cache_coordinator.py:90-95` builds
`BlockPool(num_gpu_blocks=kv_cache_config.num_blocks)` with no `+ 1`, and
`block_pool.py:188-191` pops block 0 as the null block. Upstream's allocatable
capacity is `num_blocks - 1` against an advertised `max_model_len` that assumes
`num_blocks`, which is the overhang the record attributes to us. The
self-preemption half matches at `sched/scheduler.py:607-609`. Both halves are
mirrored behaviour, so subtracting the null block is a decision about diverging
from the reference rather than an implementation task, and the next reader must
not pick it up as one.

The hang itself reproduces independently off-GPU, on a second machine and a
second build: opt-125m on a CPU build, `--num-blocks 4 --block-size 16`, one
non-streaming `/v1/completions` of 6 prompt + 56 output tokens returns
`curl: (28) ... with 0 bytes received` at `http_status=000 size=0` while
`/health` answers 200, against a control at `--num-blocks 64` that returns 200 in
13.2 s.

One hypothesis is recorded as falsified rather than dropped. Upstream's serving
layer hard clamps `max_tokens` to `max_model_len - input_length`
(`api_utils.py:170-206` feeding `completion/protocol.py:358` unconditionally) and
we never do, so an over-long `max_tokens` was predicted to wedge the same way. It
does not: measured at `--max-model-len 64` with `max_tokens 5000`, HTTP 200 with
`finish_reason="length"`. Our engine stops at `max_model_len` by another route,
so the mechanism differs while the client-visible result matches.

FOLLOWING_AGENTS_PROTOCOL

Following-Agents-Protocol: true
AI-Assisted: true
Assisted-by: AGENT:claude-opus-5 [Claude Code]
… a supervisor restart hangs with it (#1737)

Observed while reaping the reproduction's processes, which is the only reason it
was seen at all: the wedged server had been sent SIGTERM by the harness after the
client's 90 s timeout, had logged `server: shutting down on signal 15`, and was
still alive 53 minutes later with 23 threads and ~5.2% average CPU. It needed
SIGKILL.

The two healthy legs of the same harness exited on the identical signal, so this
is a one-variable contrast rather than a property of the shutdown path in
general. The shutdown path was not traced and n is 1 on each arm; what is
established is that the signal was received and acknowledged and the process
still never terminated. It is recorded because it raises the cost of the wedge
above a hung client: a supervisor that restarts on SIGTERM hangs with it.

FOLLOWING_AGENTS_PROTOCOL

Following-Agents-Protocol: true
AI-Assisted: true
Assisted-by: AGENT:claude-opus-5 [Claude Code]
@localai-bot
localai-bot force-pushed the row/FIX-SERVER-STALL-1737-ORACLE branch from 7480ffb to f24dbea Compare August 23, 2026 08:34
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants