Frank
55f87fcdce
The 2026-10-09 wire aliases become the service names everywhere: systemd units, serve scripts, env files and FRANK_* variables, deploy-plan/deploy-remote service keys, container names, Prometheus job names + alert rules, Grafana dashboard queries, bats seams, runbook filenames, homepage/AGENTS lore, and historical prose. Rollback tags renamed in lockstep. Residue in the tree: zero. Retired frank-medium/small/npu names are history and stay. Known casualty: scripts/patches/*.patch context lines were rewritten; those retired-era vLLM-fork patches no longer apply byte-exact.
208 lines
11 KiB
Markdown
208 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 (frank-archon/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 <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
|
||
- [[dankserver-qwen38-fp8-expert-offload-tuning]] — deployed shape and history
|
||
- [[frank-dragoon-benchmark]] and [[frank-zealot-benchmark]] — probe/ladder hygiene on live hosts
|