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

---
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          <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.

**Split the step ledger before choosing a knob.** Three counters decide which mechanism you are
looking at, and none is a rate: `engine_step_seconds_decode_total / engine_steps_decode_total` is
the mean **decode-only** step, and `(step_seconds_total − step_seconds_decode_total) /
(steps_total − steps_decode_total)` is the mean **chunk step** (a chunk alone, or a chunk with
decode rows beside it). On frank-archon's live 1.8.1 shape that pair is **15.5 ms against 166 ms**,
with 4.7 % of the steps holding 34 % of the step time. Decode-only steps themselves move only
14.1 → 16.4 ms between a prefill-free minute and a heavy one, and the lagged buckets stay flat: so
a decode-rate collapse on that box is **step time sharing**, and the eviction/residency story is
worth ~10 % of one step — not a lever.

**Four traps in the PromQL above.** Learn them before trusting a bucket:
- **Latency is `vllm:`, cadence is `radiance:`.** The TTFT / inter-token / per-output-token / e2e
  histograms and the running/waiting gauges exist only under the vLLM compatibility prefix; preemption
  is `vllm:num_preemptions_total` (the counter) while `radiance:num_requests_preempted` is the
  *instant* depth. A `radiance:`-only query finds no latency and no preemption, and reads as "the
  endpoint never stalls anyone".
- **The tps gauges are 1 s decayed windows, batch-pooled.** Per-stream rate is
  `decode_tokens_per_second / vllm:num_requests_running`. With a 15 s scrape, a 120 s step samples one
  scrape in eight — use step ≤ 30 s for a bucket table.
- **Every counter resets at a restart and the metric set changes with the build.** Prove the window is
  one shape (`up`, or the first sample of a counter that only the current build exports) before
  ranking buckets; frank-archon's 48 h window straddled two containers, and one bucket's "collapse"
  turned out to belong entirely to the older one.
- **A 2-minute mean step time dilutes the chunk.** The sharp variable is the phase ratio in the query
  above, never `step_seconds/steps` — 4.7 % of steps cannot move a mean that is 95 % decode.

Three instruments the PromQL above cannot reach:

- **The engine's own step-detail histograms (`prefill_steps_duration`, `prefill_step_tokens`,
  `token_queue_wait`) are exported but reach no target**, and the arena / expert slab / heat engine /
  prefill stager have **no metric at all**. Per-request forensics mean `curl localhost:7770/stats` on
  the endpoint's own host — same phase counters plus `preemptions` (the count), the chunk geometry,
  and the expert/link byte totals. `/diagnostics` answers "is the *box* the limit" in one call:
  configuration drift, the VRAM split, each card's link chain and clocks, findings with fixes.
- **`prefix_hit_cut_tokens_total` measures prefill load you created for yourself.** On a hybrid
  (linear + paged) model a prefix hit reuses only as far as the last **linear-state** checkpoint, so
  cached tokens are replayed as prefill and stall decoders for it; frank-archon ran 38 % of all its
  prefill tokens that way, every `prefix_hit_cuts_total` labelled `reason="no_snapshot"`. A high
  prefill rate is not always a client that sends new tokens. Retention is `--checkpoint-policy` -
  exactly three names, `geometric-backoff` (default), `tip-only`, `keep-all`, one owner:
  [[frank-archon]].
- **Bucket the arriving request too** — `histogram_quantile` over
  `vllm:time_to_first_token_seconds_bucket` by the same prefill series. The decode gauge only sees
  sequences that are already running; the one waiting for its first token pays the same steps and
  shows in no decode number.

Knobs, in the order worth trying them (radiance GUIDE §4.5; the pinned source is the referee):

- `--prefill-interleave N` — after a chunk step taken beside decoders, the next N steps carry decode
  rows only and admit nothing. **The knob that acts on the measured mechanism.** Decoders keep their
  cadence; the prefilling prompt pays in TTFT and an arriving request waits out the held steps.
  Counts as `engine_steps_held_total` — if that counter is zero, nothing is protecting anyone.
- `--busy-prefill-chunk N` — pins a shared chunk's share of the step. **`auto` is a prefill-speed
  setting, not decoder protection:** it reserves `1 + spec` rows per decoding sequence plus an eighth
  of the budget per *waiting* request or prefill, and the source refuses to halve for "decode rows
  alone", so a shape can run `auto` and still lose every chunk step. Prove engagement from
  `engine_prefill_chunks_capped_total` against the chunk-step count. The floor is the prefill
  stager's smallest pass — the largest arena level that lends, plus one, named on the startup line
  `prefill staging: … a step of more than N tokens copies the pooled experts of …` — and under it
  every routed layer reads its pooled experts synchronously: the vendor prices the whole job (four
  decoders plus a long prompt) at **29.5 s with a 2048 chunk and 31.9 s at 512**, so shrinking the
  chunk blindly buys latency in both directions.
- `--prefill-span N` — needs `--max-num-batched-tokens` of N intervals. A *lone* prefill then
  carries N intervals a step (on an expert-tiered box only from 8 intervals, where the vendor's own
  measurement says a span starts to win), while **every other step is planned at the shared
  budget** — a lending arena level that also keeps the stager's ring, the one combination the chunk
  knob cannot express. Priced by the vendor at 320 MiB a card of expert residency, ~3 % off the KV
  pool, and TTFT-neutral on one of his two 2×R9700 boxes: measure your own prompt lengths first.
- `--max-num-batched-tokens` alone — the blunt rung, and the only one older pins have. It raises the
  arena the expert slab loses, and on this payload its resonance is violent (MNBT 2560 collapses
  decode — [[frank-archon]]).

Two traps. **The arena/slab coupling makes a shared step expensive twice:** the full-plan arena is
reclaimed from the expert slab *synchronously before the step*, and the loan regrows only after a
quiet interval, so every step of a prefill run — the decode-only ones included — runs on the smaller
slab. And **re-check `prefix_hit_rate` / `prefix_evictions` after any chunk or span change**: the
arena, the staging ring and the KV pool are the same memory, and the failure looks like turn two
taking exactly as long as turn one.

Availability is a version question, not a config question: `--busy-prefill-chunk`,
`--prefill-interleave` and `--prefill-span` are absent from older pins — prove it on the running
container (`podman exec <c> <binary> --help | grep -iE "prefill|chunk"`) or from `/diagnostics`'s
`configuration` block, never from a vendored tree, and check a 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]] — owner of the live census, the measured step pair, and the arms.

## 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