Frank
04f4e2c6d4
Enforces "one fact, one owner": technique pages keep mechanism, laws, traps and verdicts; per-endpoint shapes, digests and era measurements are cited to the endpoint page that owns them. Also repairs the four pointers the pass left empty (each verified against the cited owner before landing): - EMULATION dequant doubles host RAM (118 GiB -> ~238 GiB) -> [[frank-archon]] - 12.11 tok/s flat 304 -> 16,095 tokens -> [[Tcclaviger Fork Ops]] - bundled-head acceptance ladder 0.739/0.554/0.427/0.340 -> [[Qwen3.8 PP Deployment]] - llama.cpp PR #23897 dedup provenance -> [[qwen3.8-spec-matrix]] Replaces the retired-shape illustration in Llama Cpp Serving Sizing with the owned MiMo Q5_K_M row (6.40 GiB payload -> 20,530 MiB used), and unwraps a hard-wrapped [[Dankserver System Specs]] link that failed link integrity. Orphan census over the diff: 0 numbers lost (comma-insensitive match against the whole vault plus AGENTS.md).
209 lines
11 KiB
Markdown
209 lines
11 KiB
Markdown
---
|
||
type: reference
|
||
title: vLLM Boot Forensics and Config Interrogation
|
||
description: Capturing a vLLM container boot failure's real root cause from journald (the container log is already gone), classifying the failure, and interrogating a live endpoint's true config and client contracts.
|
||
tags: [vllm, forensics, journalctl, podman, config, contracts]
|
||
timestamp: 2026-10-05T00:00:00-07:00
|
||
---
|
||
|
||
# vLLM Boot Forensics and Config Interrogation
|
||
|
||
For serve-script vLLM endpoints (the vLLM eras of [[frank-archon]] — that page's
|
||
Eras table is which ones; any endpoint that runs `podman rm -f` + a restart
|
||
service).
|
||
|
||
## 1. Capture the true cause — the journal, not `podman logs`
|
||
|
||
The serve script runs `podman rm -f <container>` at every start, so a dead
|
||
container's log is GONE by the time you look; `no container with name or ID`
|
||
means the journal is the only source. The engine's stdout survives in
|
||
journald under the container tag:
|
||
|
||
```bash
|
||
journalctl --no-pager --since "20 min ago" | grep -a "<container>\[" | tail -40
|
||
journalctl --no-pager --since "8 min ago" | grep -a "<container>\[" \
|
||
| grep -aiE "error|exception|assert|raise|invalid|failed" | grep -av APIServer | tail -12
|
||
```
|
||
|
||
Why naive greps fail:
|
||
|
||
- Default format truncates lines at the display cut, and the fork's giant
|
||
single-line ERROR dumps are journald-SPLIT — the decisive sentence never
|
||
appears in short format.
|
||
- `-o cat` strips the `svc[pid]:` prefix, so grepping the tag against `-o
|
||
cat` returns nothing — use the default format for the tag, `-o json` for
|
||
the content.
|
||
- Time filters: relative (`--since "NN min ago"`) only — absolute timestamps
|
||
are local PDT while the engine logs UTC; never mix.
|
||
|
||
**The JSON decode procedure** (proven 2026-10-01, caught
|
||
`torch.OutOfMemoryError` exactly):
|
||
|
||
1. Bound the window: last traceback lines + the `container died` podman
|
||
event.
|
||
2. `journalctl --no-pager --since … --until … -o json | python3 -c …` on the
|
||
remote: handle `MESSAGE` possibly arriving as a **byte list**
|
||
(`bytes(int(x) for x in m).decode("utf-8","replace")`), strip ANSI
|
||
(`re.sub(r"\x1b\[[0-9;]*m", "", m)`), dedupe by first ~12 chars (one
|
||
logical traceback can arrive as 20+ entries).
|
||
3. Reassemble the worker traceback: filter skeleton lines
|
||
(`File |…| raise |^+|~+|…<N> lines|…|re-`), keep content lines. The
|
||
decisive line is usually the last content line.
|
||
4. **The diagnosis is the gap math: `ask − free = shortfall`.**
|
||
|
||
**The wrapper trap:** `RuntimeError: Engine core initialization failed. See
|
||
root cause above` is the WRAPPER — the real cause is the EngineCore traceback
|
||
above it, ending in `RuntimeError: Worker failed with error '<cause>'`. Grep
|
||
for `Worker failed with error`.
|
||
|
||
**For probe boots / runner scripts:** capture live BEFORE teardown —
|
||
`podman logs -f <ctr> > /home/dank/logs/<arm>.engine.log 2>&1 &` right after
|
||
launch. A runner's `podman rm` destroys the only copy; two 2026-10-01
|
||
failures had their root cause eaten this way, and an 8-line bootfail capture
|
||
is insufficient.
|
||
|
||
## 2. Failure classes
|
||
|
||
| signature | class |
|
||
|---|---|
|
||
| `CUDA out of memory. Tried to allocate X GiB … Y GiB free` | capacity; the gap math names the next rung ([[RDNA4 MoE Expert Offload VRAM Budget]]) |
|
||
| `Worker failed with error 'Constraints violated (L['query_start_loc'].size()[0])! … specialized it to a constant (N)'` | torch.compile/dynamo shape specialization (N = num_seqs+1-ish) — NOT memory |
|
||
| `Deactivated successfully` with no traceback | container exited CLEAN (vLLM API server exits 0 after an EngineCore fatal); container already removed — re-read the journal, check `NRestarts` |
|
||
| `no container with name or ID` | container rm'd; journal only |
|
||
|
||
Boot-order reality: the plan computes fine at impossible budgets; the
|
||
failure lands later in worker init, not at plan time. A plan line printing a
|
||
huge arena does NOT mean it will boot.
|
||
|
||
Bypasses this fork exposes for compile faults: `--enforce-eager` (skips
|
||
torch.compile AND CUDA graphs — drops graphs, a real cost),
|
||
`VLLM_DISABLE_COMPILE_CACHE=1`, `VLLM_USE_AOT_COMPILE=1`. A stale cache is
|
||
usually NOT the cause — verify before "fixing" it (`~/.cache/vllm` may hold
|
||
only `modelinfos`; each `podman run` gets a fresh container FS unless the
|
||
cache dir is mounted).
|
||
|
||
**Crash-loop signature (shape does not fit):** `Started … ~6.7 min later …
|
||
Deactivated successfully … restart`. Diagnose with `systemctl show -p
|
||
NRestarts` + per-attempt duration. `Restart=always` loops visibly;
|
||
`Restart=on-failure` stays SILENTLY DEAD (`podman wait` returned 0, systemd
|
||
saw a clean exit).
|
||
|
||
## 3. Observation hygiene during recovery
|
||
|
||
- A container being STOPPED still answers `podman logs`, so a watcher
|
||
grepping its log reports PRE-change values and looks like the fix failed.
|
||
Discriminate by container identity:
|
||
`podman ps --sort created -a --format '{{.ID}} {{.Status}} {{.CreatedAt}}'`
|
||
— require the container to post-date the arm start, then read only that ID.
|
||
- A leftover probe script whose tail does `podman rm -f <prod-container>`
|
||
fires against a freshly DEPLOYED engine. Signature: a previously-healthy
|
||
unit exits 0 (`Started → Deactivated`, code 0) — an external rm, not a
|
||
crash. Suspect an external actor before debugging the engine; `pgrep -af`
|
||
every script you launched (and kill strays of `deploy-remote.sh` by
|
||
explicit PID — killing the dev-side deploy job does NOT kill its host-side
|
||
runner).
|
||
|
||
## 4. Ops laws that bite during recovery
|
||
|
||
- `Restart=always` does NOT fire after an explicit `systemctl stop` — a
|
||
deploy's stop leaves the unit down until something starts it. Check
|
||
`systemctl is-active` yourself.
|
||
- `ExecStop=podman stop -t 120` requires `TimeoutStopSec` > 120; the 90 s
|
||
default kills the stop and logs `Failed with result 'timeout'`.
|
||
- A `D`-state worker cannot be reaped by ANY signal (SIGTERM/KILL/`podman rm
|
||
-f` all fail). Check `ps -o pid,stat,etime,comm` before declaring a GPU
|
||
wedge — measured 2026-10-01: D → R on its own within ~3 min, then the
|
||
container stopped normally.
|
||
- Never `pgrep -f`/`pkill -f` a pattern that appears in your own command
|
||
line — kill by explicit PID list.
|
||
- `git stash -u` (not bare `git stash`) for deploy windows — untracked files
|
||
still trip the deployer's dirty-tree gate.
|
||
- A production engine started by a transient/ladder unit is NOT
|
||
boot-persistent; pin the winning numbers in the repo and deploy the real
|
||
unit.
|
||
|
||
## 5. Logging audit (what more can this container say?)
|
||
|
||
Answer with evidence from the live image, not upstream docs:
|
||
|
||
1. Enumerate the fork's own env registry:
|
||
`podman exec <ctr> python -c "import vllm.envs as e; print(chr(10).join(k for k in dir(e) if k.isupper() and any(s in k for s in ('LOG','DEBUG','TRACE','STATS','PROFILER','VERBOSE'))))"` — then read defaults/clamps in `vllm/envs.py` (e.g. `VLLM_LOG_STATS_INTERVAL` defaults 10.0 s, clamped ≥ 1.0; telemetry emits only while requests are in flight).
|
||
2. **Find the REAL HIP/ROCm library paths before grepping for AMD env vars** —
|
||
containers often install ROCm into system dirs, not `/opt/rocm`
|
||
(`podman exec <ctr> sh -c 'find / -name "libamdhip64.so*"'`). A grep of
|
||
`/opt/rocm/lib` that finds nothing is a FALSE NEGATIVE, not an absence.
|
||
Then `strings <lib> | grep -E '^AMD_LOG_LEVEL$|^HSA_ENABLE_DEBUG$'`.
|
||
3. Scan vendor kernel `.so`s for switches — and separate tuning vars from
|
||
logging vars (both share a prefix).
|
||
4. **Measure the DEBUG payoff**: count `logger.debug` sites in the module of
|
||
interest. 0–10 sites ⇒ a per-module DEBUG bump buys almost nothing; global
|
||
`VLLM_LOGGING_LEVEL=DEBUG` additionally makes api_server log full
|
||
request/response bodies (incident window only).
|
||
5. Check the deployed argv for `--disable-log-stats` / `--log-configs` to
|
||
know what is already suppressed.
|
||
|
||
Report: lever / effect / cost table, split into permanent-safe (stats
|
||
interval), incident-window (`AMD_LOG_LEVEL`, DEBUG), and does-not-exist
|
||
(absent strings). Wire via env-gated `-e` pass-throughs so default-off
|
||
preserves behavior.
|
||
|
||
## 6. Interrogate a live endpoint's REAL config
|
||
|
||
Flags and env diverge from intent constantly — rollbacks drop them silently.
|
||
Read what the container is actually serving, then prove the client contract
|
||
behaviorally:
|
||
|
||
```bash
|
||
# live argv (the truth)
|
||
ssh host 'podman exec <ctr> bash -c "cat /proc/1/cmdline | tr \"\\0\" \" \"" | tr " " "\n" \
|
||
| grep -A1 -E "max-model-len|max-num-seqs|kv-cache|reasoning-parser|tool-call-parser|template-kwargs|utilization|speculative"'
|
||
# container env knobs (fork tuning that never appears in argv)
|
||
ssh host 'podman exec <ctr> bash -c "env | grep -E \"R4D_|CLAV_|VLLM_\" | sort"'
|
||
# capacity contract as measured at boot
|
||
ssh host 'podman logs --tail 3000 <ctr> 2>&1 | grep -aE "GPU KV cache size|Maximum concurrency|non-default args"'
|
||
```
|
||
|
||
`non-default args` lines print what the server overrode — the fast way to
|
||
catch a flag that never landed. `GPU KV cache size: N tokens, Maximum
|
||
concurrency for M tokens per request: X.XXx` is the capacity contract:
|
||
N ≥ requests × M or the last client gets truncated.
|
||
|
||
**Thinking contract:** a reasoning model on vLLM returns `reasoning` ONLY if
|
||
the server runs a reasoning parser; without it the thinking lands INLINE in
|
||
`content` with a dangling close-tag and a null `reasoning`. Verify with a
|
||
temp-0 completion: pass = `reasoning` non-empty AND no `<\/think>` in
|
||
`content`. Diagnose with `ReasoningParserManager.list_registered()`
|
||
(import `vllm.reasoning`).
|
||
|
||
**Tool contract:** `tool_choice: "auto"` on a server WITHOUT
|
||
`--enable-auto-tool-choice` returns HTTP 400 — reads like a model fault, is a
|
||
config gap. Probe with a real tool schema and check `tool_calls` +
|
||
`finish_reason`.
|
||
|
||
**Restoring a dropped contract from history:**
|
||
|
||
```bash
|
||
git log --all --oneline -S"reasoning-parser"
|
||
git show <commit>:scripts/serve-<svc>.sh | grep -B3 -A3 "reasoning-parser"
|
||
```
|
||
|
||
Qwen3-family values that work on the tcclaviger fork: `--reasoning-parser
|
||
qwen3`, `--enable-auto-tool-choice --tool-call-parser qwen3_xml`,
|
||
`--default-chat-template-kwargs '{"enable_thinking": true,
|
||
"preserve_thinking": true}'`. `preserve_thinking`/`enable_thinking` are
|
||
chat-template variables, NOT engine flags: they belong in
|
||
`--default-chat-template-kwargs` server-side or `chat_template_kwargs` in the
|
||
request body; a bare top-level body field of that name is ignored. Check the
|
||
payload's `tokenizer_config.json` carries the key before trusting it either
|
||
way.
|
||
|
||
`/health` 200 says the engine is up, not that the contract is on the flags
|
||
you think — any client report of odd content (inline thinking, 400 on tools,
|
||
clipping at depth) starts with sections 1–3 here before touching anything.
|
||
|
||
## Related
|
||
|
||
- [[RDNA4 MoE Expert Offload VRAM Budget]] — the plan arithmetic behind OOMs
|
||
- [[frank-archon]] — deployed shape and history
|
||
- [[frank-dragoon]] and [[frank-zealot]] — probe/ladder hygiene on live hosts
|