server: emit GPU ttft/generation/decode_tps in stream usage - #570
Conversation
Measure decode on the batch-engine worker around forward_token (excluding SSE backpressure) and expose timings on the final chat.completion usage chunk so UIs can show accurate tok/s without client-side wall-clock math.
71ba1e3 to
c10c9a9
Compare
skyrocket2026
left a comment
skyrocket2026
left a comment
There was a problem hiding this comment.
Review
Nice additive change — streaming usage with ttft_ms / generation_ms / decode_tps is the right shape for the chat UI, and measuring around forward_token (before on_token) correctly excludes SSE backpressure.
Blocker: last_timing_ is racy under continuous batching
ModelEngine::complete_streaming writes last_timing_ after the job finishes, then sparkinfer_server reads engine.last_timing() on a later line. httplib serves concurrent requests and the batch engine interleaves them, so this can happen:
- Request A finishes → sets
last_timing_ - Request B finishes → overwrites
last_timing_ - Request A’s handler reads
last_timing()→ B’s timings
Worse: if the stolen values are >= 0, the per-request wall-clock fallback in sparkinfer_server.cpp is skipped, so the UI can show another session’s tok/s.
last_timing() also returns an unlocked reference (unlike last_error() which takes mu_).
Suggested fix: return timings with the completion result (extend the return of complete_streaming, or an out-param / pair), and use that local value in the stream handler. Avoid a process-global “last timing” side channel.
Non-blocking notes
- Non-stream
/v1/chat/completionsstill emits standard usage only (fine if intentional). - Single-token completions fall back to wall-clock decode_tps (
decode_forwards == 0); OK. - Prefill seed token correctly excluded from
decode_forwards(decode tok/s after first token).
Please fix the timing handoff, then this looks good to merge.
|
Maintainer |
Closed — RTX 5090 checkbox not tickedThis PR was auto-closed because the template includes Tested on RTX 5090 as To submit for review:
If this PR does not need GPU eval (e.g. docs-only), remove the proof-of-speedup section from the description instead of leaving an unchecked box. Automated by eval bot / rtx5090-required CI. |
|
closed |
|
Reopened + |
…shutdown, metrics, live metadata, capacity Closes the production-readiness gaps identified against an OpenRouter-style provider checklist: - Request cancellation: streaming on_token now returns bool; a disconnected client (DataSink::is_writable() goes false) stops generation immediately instead of running to completion for nobody. - Overload handling: SPARKINFER_MAX_QUEUE_DEPTH admission cap returns 429 before any KV allocation is attempted, instead of failing later. - Per-request timeout: SPARKINFER_REQUEST_TIMEOUT_S (default disabled -- measured ~90s TTFT at 32k context, so no safe aggressive default exists) returns 504 when exceeded. - Graceful shutdown: SIGTERM/SIGINT stop accepting new work and let in-flight requests drain, bounded by SPARKINFER_SHUTDOWN_GRACE_S (default 30s) since svr.stop() only closes the listening socket -- a client that vanishes without a clean TCP close can otherwise block the drain indefinitely. - GET /metrics (Prometheus text format): request/error counters by outcome, token totals, active requests, free KV blocks, uptime. - GET /v1/capacity: live occupancy for orchestrator/load-balancer polling. - /v1/models, /v1/info, /v1/tokenize now report live engine max_seq instead of hardcoded constants. - TTFT/generation_ms/decode_tps on the OpenAI usage object (additive fields, ignored by standard SDKs) -- ports PR #570's idea but rebuilt on current main's by-value Result/CompletionResult pattern; #570 predates and conflicts with the concurrent-error-bleed fix in #740. Found and fixed a real pre-existing concurrency bug while load-testing the overload path: ModelEngine::complete_streaming called model_->clear_prefix_cache() for every non-prefix-matching request without checking exclusivity, but clear_prefix_cache() frees whatever session is currently active on the shared Qwen35Model -- and the continuous-batch worker thread mutates that same active-session state from its own thread independent of ModelEngine's mutex. Reproduced directly: concurrent requests without prefix caching configured (the common case) could free an unrelated in-flight request's KV blocks mid-decode, corrupting the KV cache and poisoning the CUDA context ("illegal memory access", every subsequent call failing). Fixed by gating the clear with the same prefix_exclusive check the "use prefix" branch already had. Verified end-to-end on RTX 5090: full build, ctest 10/10, and a live server smoke test covering streaming/non-streaming completions with real timing fields, context-overflow 400, cancellation (metrics-confirmed), overload 429 under genuine concurrent load, timeout 504, and bounded graceful shutdown -- including reproducing and confirming the fix for the KV corruption bug under the same concurrent load that first exposed it.
|
Superseded by This PR can't be merged as-is: it predates Closing as superseded — thanks for the original idea, it's in |
2 participants
Summary
forward_token(excluding SSE/network backpressure).ttft_ms,generation_ms, anddecode_tpson the final streamingusagechunk so UIs (e.g. sparkinfer-web) can show accurate tok/s.prompt_tokens/completion_tokens/total_tokensunchanged.Pipeline impact
steady_clocksample around each decode forward.kMaxOutputTokensat the upstream default (4096); deployment max-out remains an init/CLI concern.Test plan
sparkinfer_serverand stream a short chat; confirm usage includesdecode_tps/ttft_ms/generation_msbench_api_vs_native.py)/v1/chat/completionsstill returns standard usage