--- type: reference title: LLM Performance Diagnosis description: "Probing why a served model is slow: the flat-depth probe, offload duty-cycle arithmetic, and step-shape attribution." tags: [performance, profiling, moe, pcie, prefix-cache, routing, telemetry] timestamp: 2026-10-19T00:00:00-07:00 --- # LLM Performance Diagnosis When a served endpoint is slower than wanted and someone names a suspect ("PCIe is saturated", "the gather is the bound"), throughput arithmetic cannot settle it — it is usually circular (it assumes the suspect consumes the step). Get data in this order; the profiler window alone has retired multi-day optimization plans. ## 1. Is decode context-bound at all? (the flat-depth probe) Sweep decode across context depth. **Flat** ⇒ attention over history is not the cost; the problem is per-token expert movement and KV/attention tuning is ruled out entirely. A genuinely context-bound server shows a clear downward slope. Record cold vs warm separately — a small gap means the cache is working. The canonical flat run (fp8 expert-offload shape, a few hundred to sixteen thousand tokens of context) is in 's profile. ## 2. Duty-cycle arithmetic (the "GPU not fully utilized" answer) Symptom: smooth ~25–35 % utilization with 100 % peaks on an expert-offload MoE. This is the EXPECTED signature, not a fault: ``` per decode step: compute burst ~100 ms (100 %) → expert-gather wait ~400 ms (~0 %) resident fraction = arena slots / total experts (e.g. 6574/24576 ≈ 27 %) PCIe bytes/token = miss_rate × lookups × slab_bytes (0.73 × 480 × 2.344 MiB ≈ 0.84 GB) predicted duty ≈ compute_ms / (compute_ms + wait_ms) ``` Validate the terms against the deployed engine's boot plan ([[RDNA4 MoE Expert Offload VRAM Budget]]). If predicted ≈ observed, the low average is structural. Note small-transfer reality: bulk bandwidth (91 % of ceiling at 1 GiB) overstates what 2–3 MiB slabs get (~72 % plus ~20 % per-transfer latency). Before blaming the link, measure it ([[PCIe Link and Atomics]]) and compare the engine's effective gather rate to the measured slab-size bandwidth — a 40–50 % gap is the software read path, not the wire. `rocm-smi --showuse` reads ~0 % during the whole multi-minute weight load: show VRAM (`--showmeminfo vram`) as the load-progress signal. ## 3. Kernel-time attribution (the profiler window) Run BEFORE building any replacement kernel. 1. Stop + mask production; boot the shape under test with ONLY the profiler config added. vLLM argv: `--profiler-config '{"profiler":"torch","torch_profiler_dir":"/prof","torch_profiler_with_stack":false,"torch_profiler_record_shapes":false,"torch_profiler_with_memory":false,"torch_profiler_dump_cuda_time_total":false}'` — `with_stack=false` is load-bearing (with stacks the stop hangs and the trace buffer grows ~40 GB → kernel OOM-kill of the engine core, anon-rss ~95 GB; the worker-side stop can hang 5 min on ROCm/kineto). Bind-mount `/prof`. If a shell substitutes values into that JSON, verify the escapes actually landed. 2. Window it: warm request → `POST /start_profile` → N generations of ≥128 tokens (~15 s of traffic) → `POST /stop_profile` (client may time out at 60 s; the trace still lands). `telemetry_report` has ONE caller: the gpu_worker profiler-stop path. Overhead is small enough to keep decode comparable (9.6 vs 9.9–10.0 tok/s measured). 3. **Parse ON THE SERVER** (traces are 100–150 MB gzipped, GB expanded). Rank `ph=="X"` events with `cat in {kernel, gpu_memcpy, gpu_memset}` by summed `dur` (µs): report % of device time, launch count AND µs/call (22 µs × 708k launches is a different problem than 4 ms × 4k), plus the first-to-last event span (fraction of wall the device was busy). Aggregate by FULL mangled name (template args are the tuning signal) and by stripped symbol. **Trap: `gpu_user_annotation` events masquerade as GPU time** (a naive sum reported 63 % in one `execute_context_0(...)` entry; spans overlap and can exceed the wall clock). 4. Divide by the window's token count → ms/token; if kernel time ≈ step time, the table IS the optimization plan. Worked example (GLM-5.3-Flash, 2×GPU, offload, decode 9.9 tok/s): ``` 34.8 % 708,500 launches vectorized_elementwise_kernel <- the actual bound 10.0 % 42,000 MoE W4A16 GEMM 8.9 % 83,160 router/top-k (sort-based) 6.5 % 133,920 hyper-connection pre/post kernels 1.05 % 20,664 ``` No amount of link arithmetic would have produced those two conclusions: the suspect was 1 %, and the mass was pointwise glue from an uncompiled trunk — whose own boot log names the cause (`FULL_DECODE_ONLY` override). It predicted a negative result in advance (spec decode cannot help a shape whose per-token cost scales with the token count) which matched an unexplained flat MTP measurement. ## 4. Telemetry without benchmarking (live hosts) When benching is forbidden (production serving), mine the runtime's own per-request telemetry — it measures the real workload and costs nothing. - llama.cpp (root unit, `-lv 3`): `sudo journalctl -u --since "-3h" --no-pager` → `slot print_timing` lines (prompt eval, eval, total, `graphs reused`, `draft acceptance … mean len`, `n_gen = N, tg = X t/s, tg_3s = …`). - halogen (rootless quadlet): `journalctl --user -u ` (**never sudo** — per-user storage) → `serve_api: mtp 28 tok in 0.66s = 42.45 t/s | 16 rounds, commit 1.75/round | prompt 58, prefill 0.92s | detok 24us/tok`. - Read the envelope, never one sample: short-prompt `prompt eval` is overhead-dominated (57 tok @ 168 t/s) — quote the longest available (1106 tok @ 1013 t/s); decode and acceptance are content-dependent (0.46–0.76 measured on one unchanged build); `graphs reused > 0` / `selected slot by LCP similarity` prove prefix-cache reuse. - **Attribute PCIe without touching the model:** background `nvidia-smi dmon -s t -c 16 -o T`, ONE ordinary `max_tokens=200` request, `wait` at the end (without it ssh closes and the client dies — the journal shows `W srv stop: cancel task` and NO print_timing while curl still reports plausible status). Measured: peak ~230 MB/s against a ~7,900 MB/s link = ~3 %, 0 at idle — the sampled-logits stream, not the transport, is decode traffic on that shape. - One `max_tokens=200` request is production traffic and fine; anything that pins the card is a bench → stop-and-mask first. Check WHICH instance you are reading (`systemctl status | head -12`; task ids jump across restarts). The engine's own ledger (`KV self size`, `n_slots` `n_ctx_slot`) outranks your model of it. ## 5. The fork's data path (before blaming the link) Offload engines pick between DMA copy-in and read-through UVA dereference inside the GEMM. Grep the installed package for the LRU/offload module and read the BRANCH CONDITION, not just the env names. A token-count threshold decides the path, and it interacts with spec decoding: an MTP step is k+1 tokens, so the step can silently cross the threshold onto the slow path as draft depth grows. Check the threshold's premise: a default tuned at 12.4 MiB/expert does not transfer to 2.344 MiB/expert, where copy-in can be several times faster. TunableOp ghost-skip: `CLAV_TUNABLEOP_SWEEP=1` alone does NOTHING under expert offload (`CLAV_TUNABLEOP_WITH_OFFLOAD=1` required) check for the skip line before concluding autotuning ran. Gather-geometry knobs read at import time → each arm is a full reload. ## 6. RAM-bandwidth-bound MoE ceiling (before recommending a quant) ``` routed experts/token = top_k × n_layers bytes/token = routed_params × bytes_per_param + shared_expert_bytes ceiling (tok/s) = measured_bandwidth / bytes_per_token ``` Measure the HOST's real bandwidth, never assume DIMM ratings: 4-DIMM AM5 boards downclock to DDR5-3600 regardless of 5600 sticks (two large DIMMs beat four small). Single-threaded reads under-report dual-channel ~4x — use the multi-threaded plateau of a checksumming reader (`scripts` pattern: `/tmp/bw.c`, 1/2/4/8/16 threads). Worked example (DeepSeek-V4.1-Flash): 6×40 experts × 35.4M params = 8.5B params/token; at 3 bpw + 0.53 GB shared = **3.7 GB/token** → 42 GB/s ⇒ **11.3 tok/s ceiling**. Sanity anchors: H100 NVL + CPU offload 226 GB ⇒ 5.8–9.0 tok/s; 2×3090 + 768 GB DDR4 ⇒ 12.2. CPU compute rarely binds below 4 bpw (~5.3 flops/byte ⇒ ~223 GFLOPS at 42 GB/s); PCIe expert STREAMING is worse than CPU compute (Gen5 x8 ~22.7 GB/s effective < half of RAM); prefill reads the union of a batch's experts (prefill ≈ bandwidth / total_expert_bytes × ubatch). A quant that fits only by ignoring the Engram table does not fit (Engram = sparse n-gram lookup, NVMe-tolerant; the routed experts are not). An iGPU GTT aperture is an ALIAS of the same RAM, not extra memory. ## 7. IBS model-access attribution (AMD CPUs) Real CPU access patterns for mmap'd weights, live, no stop (established on [[frank-archon]], 2026-09-26, ~2.7M attributed samples in 75 s). Reference: `scripts/frank-archon-expert-activity.py` (self-contained dump + sample + analyze; `--analyze-only`). 1. GGUF header-only scan (ms for a 50 GiB part) → tensor extents. **Extents from CONSECUTIVE offsets, never a type-size table** — a wrong per-element size silently under-covers every tensor and dumps tail samples into a junk bucket (first run lost 59 % of expert samples; a uniform gap/exps ratio ~1.4 across parts is the tell). Data start = `(tell + 31) & ~31`. 2. `/proc//maps` VMAs (7-group regex; pgoff = group 4, path = group 7) matched against part files; multi-VMA per part is normal. 3. `sudo perf record -e ibs_op// -c 50000 --data -o out.perf -p -- sleep ` WHILE a mixed workload runs (idle perf numbers mean nothing). `sudo perf script -i out.perf -F addr` for addresses. 4. Attribute: bisect VMAs, `foff = pgoff + (addr − vma_start)`, bisect tensor starts; per-expert index = `int(lo / (span / N_EXPERTS))` (expert-major rows). 5. Verify before believing histograms: gap ≈ 0, every tensor-bearing part nonzero, and MoE blocks should be FLAT by construction (top-k fires every block every token) — a non-flat block histogram means mis-attribution first. Established law: expert routing is per-block flat, per-EXPERT skewed. ## 8. Prefix-cache-aware routing (multi-replica serving) Measure with a **sequential-turn client**, not only a batch benchmark — a batch of distinct prompts parallelises prefill across replicas and hides the problem. The two failure modes: round-robin loses every other cache hit (90k-token contexts: warm-turn TTFT 2676 ms round-robin vs 1096 ms pinned) pinning-everything loses a card (16 requests: 18.6 s spread vs 30.1 s pinned). **The rule that gets both: route by request shape** — a request carrying more than one message is a continuation (agent loop re-sending its context) → pin to the replica that served that prefix; anything else → spread with a COUNTER, not a prefix hash. Add failover: demote a replica on connection failure and retry on a live one BEFORE writing anything to the client (safe pre-stream; never retry after streaming started). The wall no policy fixes: **a running sequence and its cached prefix draw on the SAME pool.** Three concurrent 50–80k families against 122,636 tokens/card thrash under every placement and admission policy tried (counter placement, load-balanced placement, one-large-request-per-card admission, both chunk directions — the last COSTS KV in both directions). When the working set exceeds aggregate KV, say so: the levers are capacity, fewer concurrent large contexts, or a different platform. Traps: a lifetime hit-rate counter is not a per-request verdict (probe directly: same prompt twice to an idle replica — 22.3 s cold → 1.4 s warm); salt corpora; record sample sizes; `vllm bench serve` needs `--tokenizer `; verify metric names against the live endpoint before dashboards. Test shape: drive the routing function directly with synthetic bodies (stdlib-only policy module) conversation identity is the FIRST N KiB of prompt — a shorter tested prefix hashes differently per turn and pinning silently never happens. ## 9. Decode cadence under a prefill (the step-shape census) "Decode turns to sludge the moment a long prompt arrives, then recovers" is not a link or a gather story — on a chunked-prefill engine the unit of interference is **the step**. A step that carries a prefill chunk takes the chunk's time, and every decode row sharing that step waits that long for its next token. Chunk size is `min(remaining, --checkpoint-interval, --max-num-batched-tokens)`, so on a hybrid model the interval caps it before the budget does. Census it without touching the model — the engine's own counters (`/stats`, `/metrics`, cumulative since boot): ``` decode-only step = step_ns_decode / steps_decode shared step = (step_ns - step_ns_decode) / (steps_prefill + steps_mixed) ``` Then bucket a day of `decode_tokens_per_second` by `prefill_tokens_per_second` (Prometheus `query_range`, step 120 s) and **check the lag**: correlate decode with prefill at lag 0 and again at 2-14 minutes. Lag-0-only ⇒ step-time contention, the chunk is holding the device. A lagged tail ⇒ residency churn — the prefill's working set evicted something decode needs (expert slab, KV) and decode pays after the prefill is over. `preemptions` separates the third shape: a preempted-and-recomputed sequence stops producing entirely and then re-prefills from token 0, which is a stall, not sludge. Knobs, in the order worth trying them (radiance GUIDE §4.5): - `--prefill-interleave N` — after a chunk step taken beside decoders, the next N steps carry decode rows only and admit nothing. Decoders keep their cadence; the prompt pays that in TTFT. Counts as `engine_steps_held_total`. - `--busy-prefill-chunk MODE` — the chunk's share of a step that has other work: `auto` (default) reserves a row plus the draft window per decode row behind it and an eighth of the budget per waiting prefill/request, `off` lets the chunk take the whole step (admission never runs while it does), `N` pins the share. Never under the prefill stager's smallest pass — the startup line names it, and below it every routed layer reads its pooled experts synchronously, which costs the prefill far more than sharing saves. Counts as `engine_prefill_chunks_capped_total`. - `--max-num-batched-tokens` — the blunt rung, and the only one older pins have. The vendor's own curve prices **halving the shared chunk at roughly a fifth of prefill throughput** (a 48-layer MoE at 200k on two cards — knob pricing, not this endpoint's number, so treat it as the order of magnitude a chunk decision costs). Raising it past the checkpoint interval buys nothing and loses expert residency to the arena. - `--prefill-span N` — the inverse trade: a *lone* prefill carries N intervals a step while every shared step is planned at a smaller shared budget, which on an expert-tiered box lends that arena back to the expert slab. The vendor's own measurement says the win is **long-prompt-only**: nothing at short prompts, a large TTFT gain at the far end of the window. Two traps. **The arena/slab coupling makes a shared step doubly expensive on an expert-tiered shape**: the full-plan arena takes VRAM the resident expert slab would have had, so the decode rows inside that step also read experts over the link — a smaller shared budget helps twice. And **re-check `prefix_hit_rate` / `prefix_evictions` after any chunk change**: the arena and the KV pool are the same memory, and the failure looks like turn two taking as long as turn one. Availability is a version question, not a config question: `--busy-prefill-chunk` and `--prefill-interleave` are absent from older pins — prove it on the running container (`podman exec --help | grep -iE "prefill|chunk"`), never from the vendored tree, and check the source clone's depth before dating a flag from `git log -S` (a `--depth 1` clone reports its own tip for every search). Run on: [[frank-archon]] — the census was taken on its 3-slot radiance 1.0.13 era (budget 2048 = interval 2048); the live 1.8.1 shape carries the two chunk knobs. The measured census and the verdict for this fleet's shape are that page's. ## Related - the window discipline and usage-counter law - [[PCIe Link and Atomics]] — link probing and the streaming-vs-compute ceiling - [[RDNA4 MoE Expert Offload VRAM Budget]] — the plan behind duty-cycle terms - [[frank-archon]] — the endpoint where §9's step-shape census was run