serverAppConfigs/serverAppConfigs-docs/LLM/LLM Performance Diagnosis.md

type, title, description, tags, timestamp

type	title	description	tags	timestamp
reference	LLM Performance Diagnosis	Probing why a served model is slow: the flat-depth probe, offload duty-cycle arithmetic, and step-shape attribution.	performance profiling moe pcie prefix-cache routing telemetry	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          <the long-suspected expert gather>

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 <unit> --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 <unit> (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/<pid>/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 <pid> -- sleep <dur> 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 <local path>; 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 curve on a 48-layer MoE at 200k on two cards: chunk 512 → 1750 t/s, 1024 → 2200, 2048 → 2706 (a 185k prompt: 138 s against 91 s), so halving the stall costs ~19 % of prefill. Raising it past the 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. Vendor TP2 expert-tiered TTFT deltas vs a plain 2048 budget: −6.1 % at 2k, +2.3 % at 18k, +49.1 % at 250k — long prompts only.

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 (320 MiB/card at TP2 for a 4096 budget), 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 <c> <binary> --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 (radiance 1.0.13, TP2 expert_tiered, budget 2048 = interval 2048) — 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