Files
serverAppConfigs/serverAppConfigs-docs/LLM/LLM Performance Diagnosis.md
T
Frank 55f87fcdce llm: retire the trio service names — fleet services renamed to frank-archon/frank-dragoon/frank-zealot
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.
2026-10-10 17:03:14 -07:00

222 lines
13 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
---
type: reference
title: LLM Performance Diagnosis
description: Probing why a served LLM is slow — the flat-depth probe, the expert-offload duty-cycle arithmetic, kernel-time attribution via the profiler window, live telemetry without benchmarking, RAM-bandwidth ceilings, IBS tensor attribution and prefix-cache-aware routing.
tags: [performance, profiling, moe, pcie, prefix-cache, routing, telemetry]
timestamp: 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. Measured on the fp8 expert-offload shape: 12.11 tok/s FLAT from 304
to 16,095 tokens.
## 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 also
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
- [[LLM Bench Windows and Measurement]] — 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
- [[vLLM Porting and Compile Triage]] — the compile fix for the pointwise-glue bound