Issues / #1870
#1870 [Bug]: timings.prompt_n ignores the DONE line's prompt_read — prompt_per_second inflated up to ~40,000x when the slot already held the prompt
closed · @sdjger-xiaoniu · 1 commentaires · Sur GitHub
BenchmarksSetup & installServer & APIMulti-GPUNVIDIA / CUDAModels & quants
Description
### What happened
The `timings` block on responses reports a prefill rate that is inflated by orders of magnitude whenever the prompt was already in the slot's session cache. `cache_n`/`reused` only track the **conversation cache** (which is off in this setup: `/metrics` → `conversation_cache.enabled: false`), so `prompt_n` ends up being the **whole** prompt while `prompt_read` says the engine actually read a few tokens — or one.
Measured on 0.1.41, `qwen3.8-flash-next-iq3_s` (IQ3_S), 2x RTX 2080Ti 22GB, layer split, `--slots 2`. A 43,086-token prompt that repeats the previous request (the slot already held the whole prompt):
```
/metrics history row (native accounting, honest):
prompt_tokens 43086 | prompt_read 1 | reused 0 | prompt_ms 563.5 -> ~1.8 tok/s
response timings (what clients show, inflated):
cache_n 0 | prompt_n 43086 | prompt_ms 563.5 | prompt_per_second 76461.4
```
Same pattern on other warm turns: `prompt_n 38922 / prompt_read 1 / prompt_per_second 139056.8`, and `prompt_n 1295 / prompt_read 1 / prompt_per_second 163924.1`. Cold turns are fine (`prompt_n 2052, prompt_read 2052, prompt_ms 5339.3 -> 384.3 tok/s`).
For callers that print `timings` (llama-swap and friends) this shows a five-to-six digit tok/s number instead of "almost nothing to prefill", and any dashboard that averages it is off by 100-40,000x.
### Where it comes from
`serve/server.py` → `request_timings()`:
```python
cache_n = int(last.get("reused") or 0)
prompt_n, prompt_ms, decode_ms = max(0, prompt_tokens - cache_n), float(last["prompt_ms"]), ...
```
`reused` is the conversation cache's count; the slot-session reuse is reported in the DONE line as `prompt_read` (field 14, used by `/metrics` history and totals via `prompt_tokens_seen()`), and `reused` stays 0 when the conversation cache is disabled. The function's own docstring says *"prompt_n is what was read, cache_n what the conversation cache already held"* — so the implementation does not match the stated contract, and `serve/test_server.py:2960` (`prompt_n + cache_n == usage.prompt_tokens`) is preserved by deriving `cache_n` from `prompt_read` instead.
### Suggested fix
```python
read = last.get("prompt_read")
if read is not None:
prompt_n = max(0, int(read))
cache_n = max(0, prompt_tokens - prompt_n) # keeps prompt_n + cache_n == prompt_tokens
else:
prompt_n = max(0, prompt_tokens - cache_n) # engine before 0.1.36 has no prompt_read
```
With this, the warm case above reports `prompt_n 1, cache_n 43085, prompt_per_second ~1.8` (and `cache_n` finally tells the client the truth about how much was reused).
### Strata version, GPU, OS
0.1.41 · 2x RTX 2080Ti 22GB (layer split, `--slots 2`) · Ubuntu 26.04, driver 595.91.07
Sur le site
Liens install, modèles, releases.