--- 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 (frank-primary/qwen-fp8 on dankserver, any `podman rm -f` + restart service). ## 1. Capture the true cause — the journal, not `podman logs` The serve script runs `podman rm -f ` 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 "\[" | tail -40 journalctl --no-pager --since "8 min ago" | grep -a "\[" \ | 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 |^+|~+|… 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 ''`. Grep for `Worker failed with error`. **For probe boots / runner scripts:** capture live BEFORE teardown — `podman logs -f > /home/dank/logs/.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 ` 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 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 sh -c 'find / -name "libamdhip64.so*"'`). A grep of `/opt/rocm/lib` that finds nothing is a FALSE NEGATIVE, not an absence. Then `strings | 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 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 bash -c "env | grep -E \"R4D_|CLAV_|VLLM_\" | sort"' # capacity contract as measured at boot ssh host 'podman logs --tail 3000 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 :scripts/serve-.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 - [[dankserver-qwen38-fp8-expert-offload-tuning]] — deployed shape and history - [[frank-large-benchmark]] and [[frank-small-benchmark]] — probe/ladder hygiene on live hosts