1 GPU utilization Symptom
gpu_util, both GPUs fictional87% before, 97% after
What I'd conclude. 97%, up from 88%. Heavier prefill pushes utilization up too, so this alone does not point at a cause.
Lab, fictional scenario
Debug exercise: p95 TTFT doubled after a deploy
Fictional scenario. Every number on this page is made up for the exercise. None of it is a measurement or a result.
Tuesday, 14:05. A deploy goes out. By 14:30, p95 time to first token is 1.9 s, up from 0.9 s. Time per output token is unchanged. Error rate is flat. Nobody touched the model weights.
Half the dashboards look bad now. Most of them are downstream of one cause. Pick what to check first.
What do you check next?
2 KV cache usage Clue
kv_cache_usage, GPU 0 fictional54% before, 96% after. preemptions per minute: 0 before, 31 after
What I'd conclude. 96% full, up from 54%, and the scheduler started preempting. Traffic did not change, so each request is holding more tokens than before.
3 Queue depth Symptom
requests_waiting fictional1 before, 37 after
What I'd conclude. Waiting requests went from about 1 to about 38. That explains the p95 but not why the queue formed. Traffic did not grow, so something is using up capacity.
4 Batch config Ruled out
git diff serving.yaml, deploy 2291 fictional max_num_seqs: 128
max_num_batched_tokens: 8192
enable_prefix_caching: true
- chat_template: templates/chat-v6.jinja
+ chat_template: templates/chat-v7.jinja
What I'd conclude. Scheduler limits did not change. One line did: the chat template. Rule out the batch config and follow the template.
5 Network and all-reduce Ruled out
allreduce_time_per_step, ms fictional0.2 ms before, 0.21 ms after
What I'd conclude. Flat at 0.21 ms per step before and after. Time per output token never moved, which already pointed away from the interconnect. Ruled out.
6 Tokenizer and prompt length Cause
prompt stats, 15 minutes before and after fictional| metric | before | after |
|---|---|---|
| prompt tokens, p50 | 640 | 2,610 |
| prompt tokens, p95 | 1,900 | 3,880 |
| prefix cache hit rate | 81% | 3% |
rendered chat-v7, first lines:
<|system|>
Current time: 2025-03-11T14:31:07Z
You are a helpful assistant. Tools: [1,900 tokens of JSON schema]
What I'd conclude. Median prompt went from 640 to 2,610 tokens. The new template prepends a 1,900-token tool schema and puts a timestamp on line one. The timestamp changes on every request, so no two prompts share a prefix and prefix caching stops working. Every request pays full prefill on about 4x the tokens.
The root cause shows once the checks point at one cause.
Root cause the timestamp broke the prefix cache
Deploy 2291 shipped a new chat template. It added a 1,900-token tool schema to every request and put a per-request timestamp at the top of the system prompt. Prompts got about 4x longer, prefix cache hits fell from 81% to 3%, and prefill grew with them. Each request held more KV cache, the cache filled, the scheduler queued and preempted, and p95 TTFT doubled.
Fix
- Roll back to chat-v6 now. Debug v7 on a canary.
- Move the timestamp to the end of the prompt, or drop it, so the shared prefix is stable again.
- Send the tool schema only to requests that use tools.
Verify
Prefix cache hits back near 80%, median prompt back near 640 tokens, KV cache under 60%, queue near zero, p95 TTFT back near 0.9 s. Check all five, not only the latency.
Prevent
Add a CI check that renders the template and fails when the token count or the first 512 tokens change without review. Alert on prompt tokens p50 and prefix cache hit rate, not only on latency.
Treat any single dashboard number with suspicion, including the ones on this page. Read a number next to what changed, and confirm it from a second source.