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 profiler attribution.	performance profiling moe pcie prefix-cache routing telemetry	2026-10-05T00: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.

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
• the compile fix for the pointwise-glue bound