[Bug]: BDONE replaces the request's accumulated decode_ms/generated — every finish=stop request reports a single-step decode time #1869

What happened

Requests that end with finish=stop report a single-step decode time instead of the request's accumulated decode time, so predicted_ms/predicted_per_second are wrong by ~100-200x. finish=length requests are fine, which is why this hides for a while.

Measured on 0.1.41, qwen3.8-flash-next-iq3_s (IQ3_S), 2x RTX 2080Ti 22GB, layer split, --slots 2, MTP spec=6.

The same finished request, two numbers from the engine itself:

/metrics  history row:
  output_tokens 135 | engine_generated 1 | prompt_ms 3794.7 | decode_ms 18.4 | decode_tok_s 54.3
/v1/status  last_timings (same request):
  predicted_n 135 | predicted_ms 18.4 | predicted_per_second 54.3        <- rate and ms disagree

decode_tok_s comes out sane by accident: it is computed as generated / (decode_ms/1000) = 1 / 0.0184, i.e. one token in one inter-token interval, which happens to be the right order of magnitude for a decode rate. Any client that computes completion_tokens / predicted_ms (the llama.cpp convention, and what the timings block is for) gets 7,337 tok/s for a 135-token answer at ~54 tok/s.

finish=length rows are consistent (256 tokens / 7925.5 ms -> 32.3 tok/s), so the bad value is specific to the stop path: /metrics rows for stop-finished requests are decode_ms 18.4 / 18.5 / 18.8 / 19.3 / 19.4 / 22.2 / 22.5 / 24.7 ms with engine_generated 1, while length-finished ones carry real totals.

Where it comes from

serve/server.py, the streaming loop (around line 1363 in 0.1.41) — the BDONE handler replaces the per-request stats instead of accumulating them:

elif line.startswith("BDONE "):
    ...
    self.last = {**self.last, "finish": f[3], "decode_ms": float(f[4]),
                 "generated": int(f[2]) if f[2].isdigit() else self.last.get("generated")}

serve/test_request_accounting.py is the contract here — it exercises thinking-budget continuations and asserts the totals are summed (assertEqual((row["prompt_ms"], row["decode_ms"]), (47.0, 280.0)), i.e. 40+7 / 200+80). The BDONE path overwrites, so a continuation's last segment wins over the request's totals.

Suggested fix / workaround

A segment must never shrink the request's totals — accumulate, or keep whichever value is larger:

self.last = {**self.last, "finish": f[3],
             "decode_ms": max(float(f[4]), float(self.last.get("decode_ms") or 0.0)),
             "generated": max(int(f[2]), int(self.last.get("generated") or 0)) if f[2].isdigit()
                          else self.last.get("generated")}

We have been running exactly this as a local patch since 0.1.41 (with serve.test_request_accounting + serve.test_server + serve.test_prometheus green, 284 tests) and /v1/status then reports predicted_ms 714.0 / predicted_per_second 42.0 for a 30-token stop turn — consistent with the ~54 tok/s the engine is actually doing.

Strata version, GPU, OS

0.1.41 · 2x RTX 2080Ti 22GB (layer split, --slots 2, spec=6) · Ubuntu 26.04, driver 595.91.07