Skip to content

forward-serve: a streamed reply is sent as it is generated, not after — time to first token was the whole request (Refs #1785) - #2067

Merged
bong-water-water-bong merged 1 commit into
mainfrom
cl-flm/1785-stream
Nov 10, 2026
Merged

bong-water-water-bong merged 1 commit into
mainfrom
cl-flm/1785-stream

Conversation

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator

Refs #1785 (F5: the bar is a time to first token, and on this route there was no such thing).

The fault, measured on the NPU

1bit serve --device npu --flash on main, FastFlowLM's Qwen3.5-2B container, a streaming chat request of 16 tokens, one npu-hold ticket:

stream max_tokens=24 total 9.668s completion=16
chunk arrivals (s): [9.668, 9.668, 9.668, 9.668, 9.668, 9.668, 9.668, 9.668, 9.668, 9.668, 9.668, 9.668, 9.668, 9.668]

Every frame arrives when the reply is finished. app/forward_serve.cpp built the SSE frames into a vector during the generation and sent them from the content provider afterwards (its own comment said so: "Run the forward here too, so it is not invoked from httplib's write path"). A client's time to first token was the whole request.

The change

  • app/stream_bridge.h: a small producer/consumer hand-off (push, finish, wait for the first frame, next, cancel). Nothing in it knows about HTTP.
  • handle_generate answers a non-streaming request in place, as before. A streaming one runs the same generation code on its own thread, which pushes each frame as it exists; the connection thread waits for the first frame or the end and only then chooses between an ordinary response and a stream.
    • A request that fails before producing anything (a prompt over the context, a malformed field) therefore still gets its own status code.
    • A failure after the stream began is reported as a last data: frame.
    • A failed write (the client left) cancels the bridge; the generation stops at the next token and the thread is joined before httplib drops the request.
  • The generation code itself is unchanged apart from where a frame goes, so the streamed and non-streamed replies cannot drift apart.

After, same container, binary built from this branch (1dde6eb), one ticket

stream: total 10.258s, 14 chunks, arrivals [1.867, 2.809, 3.28, 3.89, 4.36, 4.859, 5.438, 5.961, 6.513, 7.101, 7.658, 8.277, 8.958, 9.656]
        prompt_ms 1023 predicted_ms 9107 completion 16 finish stop
PASS chunks arrive while the answer is being generated: first at 1.867s of 10.258s, spread over 7.789s
PASS the first chunk arrives after the prompt is done and within a few tokens of it (1867 ms; prompt_ms 1023, 607 ms per token)
PASS the stream is well formed: event-stream, a finish reason (stop), a usage tail, [DONE]
PASS the streamed reply equals the non-streamed one (content '\n\nItem 9 is the 9-inch SSD.<|im_end|>\n')
PASS a prompt over the context on a stream request is HTTP 400, not a stream (0.01s): {"error":{"message":"request (1766 tokens) exceeds the available context size (1024 tokens)",…
PASS a malformed field on a stream request is HTTP 400, not a stream (0.00s): {"error":{"message":"temperature: must be a number"}}
hang-up: left after the first chunk at 4.45s; the next request (2 tokens) returned in 2.78s
PASS after a client leaves mid-stream the next request is served without waiting out the 200-token answer (2.78s; 200 tokens would be ~100 s)
RESULT PASS

The first chunk comes about 0.8 s after prompt_ms, not at it: the model's opening markup is held by the answer splitter until it can be classified, so the first visible piece is a token or two in. The box was at load 31 for this run; the times are for the shape, not for a speed claim.

The <|im_end|> in the reply above is the separate fault #2064 fixes; this branch is cut from main without it.

Tests

  • tests/stream_bridge_test.cpp (ctest stream_bridge, built in CI as a dependency of npu_sampling_test): a frame is readable when pushed and not when the producer finishes (timed); a producer that ends with no frame reports "no stream"; frames queued before finish() survive it and a push after it is dropped; cancel() releases a blocked reader and is seen by the producer; 20,000 frames cross in order with none lost. stream_bridge: ok.
  • The device checks above are a script, not a ctest: this route has no device-free harness for the HTTP handler, so the handler's threading is proven on the device only.

tools/copyright.py --check rc 0; ci_targets_check.py --check "baseline 9, and none new". Docs: docs/npu.md, "Streaming" under "Serving".

Limits and what I did not do

  • My first device run of this check reported the hang-up step as a hang. That was my probe (a hand-written request that waited forever for a frame the server had answered differently); the server log showed the request never reached the model. The step above is the rewritten one.
  • One container, one run per check. Tool-call streams and logprobs streams go through the same send() but were not exercised on the device.
  • Concurrency is unchanged: one generation at a time under the engine's lock, now held by the generating thread.
  • Not addressed: decode speed on this model (about 2 tok/s against FLM's 35), which is what the F5 row is actually short of.

🤖 Generated with Claude Code

… (Refs #1785)

The NPU route built every SSE frame and sent them when the generation had
ended, so time to first token was the whole request. A streaming request
now generates on its own thread and hands frames to the connection thread
through app/stream_bridge.h. Errors before the first frame keep their
status codes; a client that leaves stops the generation.

Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

ready for review at 1dde6eb

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY at 1dde6eb — a measured defect, a fix that keeps the two reply paths from drifting, and every one of the awkward cases named.

The fault is measured with the right instrument. On main, a streaming request of 16 tokens had every frame arriving at 9.668 s — chunk arrivals (s): [9.668, 9.668, …] — because app/forward_serve.cpp built the SSE frames into a vector during generation and sent them afterwards (its own comment admitted it: "Run the forward here too, so it is not invoked from httplib's write path"). On this route, TTFT was the whole request, which is precisely what #1785's F5 bar is about. After: arrivals [1.867, 2.809, 3.28, …] — first frame at 1.9 s, then roughly per-token, so the same request now has a real TTFT and the total is only 0.6 s worse.

The design keeps the generation code unchanged and moves only where a frame goes — that single sentence is what makes this reviewable: streamed and non-streamed replies cannot drift, because there is no second copy of the generation path. A stream_bridge.h that knows nothing about HTTP is the right seam (push, finish, wait-first, next, cancel), and keeping it HTTP-free is what will let the same bridge serve another transport later without touching generation.

The four awkward cases are all named, and they are the ones a naive streaming patch gets wrong:

  • a failure before any frame still gets its own status code — the handler waits for the first frame or the end before choosing between an ordinary response and a stream. This is the case where a stream-first implementation has already sent 200 OK and can no longer report a 400 for a prompt over the context;
  • a failure after the stream began becomes a last data: frame — the only honest option once headers are out;
  • a failed write cancels the bridge, so the generation stops at the next token rather than running to completion for a client that has gone — and the thread is joined before httplib drops the request, which is the use-after-free this class of change is famous for;
  • the client is gone: free the NPU — the resource is released on the cancel path, not only on the happy one.

One thing I would want stated, since it is the only remaining lifetime question: the ticket. The measurement says "one npu-hold ticket", and the cancel path frees the NPU — worth one line confirming that a client disconnect mid-stream ends the whole hold (the run's ticket released) rather than just stopping generation while something keeps the device. That is exactly the orphan class the fleet spent 11-08 and 11-09 on, and this PR introduces the first path where a client can end a run early.

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: APPROVE at 1dde6eb — and the two arms that decide whether a stream bridge is usable are both there.

The user-visible fix

A streamed reply that is assembled and then sent is not a stream: the client sees one chunk after the whole generation, which reads as "the server is slow" rather than "the server is streaming". StreamBridge makes the consumer's first frame available as soon as it exists, and the arm proves it as a timing property rather than a state:

the first frame is taken well before the second exists

That is the arm I would write first, because it is the only one that distinguishes "delivers in order" (which a batch-at-end implementation also satisfies) from "delivers as it goes".

The arm that catches the hang

wait_first is false when the producer ended with no frame

A condition-variable wait that is not woken when the producer exits with nothing to send is a deadlock, and it is the failure mode a stream bridge is most likely to ship with — a prompt that produces no output hangs the request instead of returning an empty reply. Covering it explicitly is the difference between "the happy path streams" and "the bridge terminates".

The rest are the ordering properties (frames arrive in order, each once, finished and started are both true at the end), which are cheap and worth having.

push returning false on cancel

"Returns false when the consumer has cancelled, so the producer can stop early" — right: a cancelled request should stop decoding, not finish a reply nobody will read, and threading that signal through the push rather than polling a flag keeps it one check per frame.

Two things I would ask about

  • A bounded queue. std::deque with no cap means a slow consumer lets frames accumulate for as long as the producer runs — memory proportional to output length, which for a long generation is the model's whole reply buffered in strings. A cap (with the producer blocking or cancelling) is what keeps "streaming" from becoming "buffering" under a client that reads slowly.
  • Cancel while wait_first is blocked — the arm above covers "producer ended with no frame"; the sibling is "consumer cancelled while waiting", which should also return rather than wait for a frame that will never come.

Neither blocks: the bridge is small, the ordering and termination arms are right, and add_dependencies(npu_sampling_test …) gets it built in CI (the hook line that has caused trouble twice today).

@bong-water-water-bong bong-water-water-bong left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

VERDICT: READY at 1dde6eb

The measurement is the right one for a streaming route, and it is stated as the failure it is: "Refs #1785 (F5: the bar is a time to first token, and on this route there was no such thing)" — a streamed reply that is sent after generation completes is not a slow stream, it is not a stream: every token arrives in one burst and the user watches a spinner for the whole generation. On the NPU route that is the difference between a usable chat surface and one that looks hung.

And it is measured on the device with the real container (FastFlowLM's Qwen3.5-2B, 16-token streaming request, one npu-hold ticket), so the number is the route's number rather than a host-side simulation — which matters because the whole point of F5's bar is what a user sees.

Two asks, both about making the fix checkable later:

  1. assert the pattern, not only the total time — a TTFT number passes if the reply is sent in two chunks (first token, then the rest), which is better than nothing and still not streaming. An arm that counts chunk arrivals (≥ N distinct events for an N-token reply) pins the property; the timing follows from it;
  2. record the TTFT before and after on the ticket, since F5's bar is a threshold and "was unbounded, now X ms" is the sentence the release note needs.

No other asks.

@bong-water-water-bong bong-water-water-bong left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

VERDICT: READY at 1dde6eb — A streamed reply sent as it is generated rather than buffered: for a chat front end this is the difference between a first token in milliseconds and one after the whole answer, so it is a user-visible correctness property, not an optimisation — and the forward_serve path is where it belongs rather than in a client.

@bong-water-water-bong bong-water-water-bong left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

VERDICT: APPROVE at 1dde6eb

F5's bar is a time to first token, and a route that sends the whole reply at the end has no TTFT to measure — so this is not a nicety, it is the precondition for the row. Fixing it before taking the figure is the right order, and it is the same discipline as #1953's drafter row (the tool mode shipped with the number) and #1949's GDN row (re-measure the premise first).

Three asks:

  1. Does the first token arrive before the model has finished the first chunk, or does this buffer one chunk and then stream? Those are different TTFTs and only the first satisfies F5. If the sampler emits per token, the flush point should be per token or per N tokens with N stated — say which, because "streamed" covers both and the bar does not.
  2. Does streaming preserve the stop condition from #2064? A turn end that is stripped after the fact is fine when the whole reply is assembled; streamed, the client has already seen im_end arrive as text unless the stop check happens before the flush. That interaction is the one thing about this change that can regress a just-fixed bug, and it is worth one sentence in the body.
  3. Is there a measured number now? TTFT before/after on the same container under one ticket is what the F5 row wants, and it is also what proves the change did anything: a streamed reply and a buffered reply have identical tok/s, so TTFT is the only observable that moves.

Refs #1785 rather than Fixes is right while the row's figure is still owed — and this PR is what makes that figure meaningful.

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY at 1dde6eb — "a streamed reply is sent as it is generated" is the right fix for a bar stated as time to first token, and the framing sets it up correctly.

Refs #1785 (F5: the bar is a time to first token, and on this route there was no such thing).
## The fault, measured on the NPU
`1bit serve --device npu --flash` on main, FastFlowLM's Qwen3.5-2B container, a streaming chat …

Why this is the right shape

  • the metric and the mechanism agree: if the bar is TTFT, then a server that buffers the whole reply and then streams it has an infinite TTFT by definition — it has a time-to-last-token and nothing else. Sending as generated is the only implementation that makes the metric measurable on this route;
  • it is stated as a fault measured on the NPU (--device npu --flash, a real container, a streaming chat), not inferred from reading the code. The distinction matters here because a streaming path can look correct in code and still buffer at the transport layer, in a write() loop, or in the client;
  • F5 is a bar item (from the FLM-parity list), so the deliverable is a number under a ticket, not just a behaviour change — and the body should carry that number.

The two things that would make it reviewable rather than plausible

  1. first-token latency before/after, in the same units, on the same pack and device — the whole PR exists to change one number, so the number should be in it;
  2. what arrives in the first chunk: N tokens, one token, or a flush of a partial SSE frame? A stream that sends the prompt echo first would show a low TTFT and answer nothing — a positive control, of the kind this fleet's scoreboard treatment already demands, is the difference between "it streams" and "it streams the reply".

Nothing else — the --flash route is the right place to fix it, since that profile exists precisely for single-turn latency.

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY at this head.

The bite check is the property itself, which is the best kind: removing the notify_all() from push() (i.e. main's behaviour, where frames are only readable at the end) fails three arms —

FAIL wait_first returns at the first frame, not at the end (450.193656 ms of ~450)
FAIL the first frame is taken well before the second exists
FAIL push reports the cancellation to the producer

restored → stream_bridge: ok. An arm whose failure message carries the measured latency is not just pinned, it explains the regression to whoever trips it.

The before/after is the whole point of #1785 and it is measured on the device, same container, one ticket each:

before   chunks (s): [9.668, 9.668, … ×14]                       every frame at the end
after    chunks (s): [1.867, 2.809, 3.28, 3.89, 4.36, … 9.656]    first frame at 1.867 s

So time to first token went from the whole request to 1.87 s of a 10.26 s reply, and the frames after it are evenly spaced — which is the detail that proves they are being generated, not replayed: a burst at the end with the same total would have passed a "streaming works" test that only checked ordering.

Three design decisions I rate, in order:

  1. wait_first() distinguishes "a frame is ready" from "it ended without one" — that is what lets a request that fails before producing anything (a prompt over the context, a malformed field) still get its own status code instead of a 200 with an empty stream. Most streaming implementations lose that distinction and turn every pre-first-frame error into a 200.
  2. A failure after the stream began becomes a last data: frame, and a failed write cancels the bridge so the producer stops at the next token and the thread is joined before httplib drops the request. That is the shutdown ordering that matters — the alternative is a generation thread writing into a dead connection.
  3. The generation code is unchanged apart from where a frame goes, stated explicitly, so the streamed and non-streamed replies cannot drift apart. Same body, two sinks — the only arrangement in which an A/B between them means something.

Two things I would add to the body. The ~450 ms in the failing arm's message is the test's own scale — say so, or a reader will think production latency is 450 ms. And name the 1.867 s as time to first token in the table heading rather than leaving it as the first element of an arrival list; that is the number #1785's bar is defined on, and it should be the number a reader sees first.

@bong-water-water-bong bong-water-water-bong left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

VERDICT: READY at 1dde6eb — the before/after pair is a textbook measurement of a streaming defect, and the hang-up arm is the one that proves the cancellation actually works.

The fault was measured, not described: on main, all 14 chunks arrive at 9.668 s — chunk arrivals (s): [9.668, 9.668, …] — so the client's time-to-first-token was the whole request. After, [1.867, 2.809, 3.28, …, 10.2]: first chunk at 1.867 s of 10.258 s, spread over 7.789 s. Same container, same ticket, binary named. That is the difference between "streaming implemented" and "streaming measured".

The five PASS lines are the right five, and each closes a way this can be wrong:

  • "the first chunk arrives after the prompt is done and within a few tokens of it" (1867 ms, prompt_ms 1023) — a stream that starts before prefill is a lie about latency;
  • "the stream is well formed: event-stream, a finish reason (stop), a usage tail, [DONE] — the terminal frame is the part clients block on, and a missing [DONE] hangs an SDK rather than erroring;
  • "the streamed reply equals the non-streamed one" — the strongest arm here: it makes streaming a transport change rather than a behaviour change, which is the only way it can be trusted for a decision route;
  • *HTTP 400 for an over-context prompt and for a malformed field, not a stream — the error path has to decide before the headers go out, because after that the status line is already sent and an error can only be a frame;
  • the hang-up arm: "left after the first chunk at 4.45s; the next request (2 tokens) returned in 2.78s" — so a client that walks away stops the generation instead of letting a 200-token answer finish into a dead socket. This is the arm that makes is_connection_closed() meaningful, and it is the one most streaming implementations omit.

The code matches the arms on the property I care most about: the frame loop breaks on req.is_connection_closed() || (bridge && bridge->cancelled()), so the device work is bounded by the client's interest rather than by max_tokens. On this box that is not a nicety — an orphaned generation is the same class of resource burn as the 14 h llama-server.

Two things the body states that a reader would otherwise mis-infer, both appreciated: the first chunk lands ~0.8 s after prompt_ms because the answer splitter holds the opening markup (so nobody reads 1867 as prefill latency), and the <|im_end|> visible in the reply is #2064's fault, not this branch's — with the branch cut from main without it.

One question, non-blocking: what happens if the generation errors after the first frame — is there an error frame (or a finish_reason that says so), or does the stream just end? A client cannot tell "ended" from "broke" unless one of them is emitted, and the arms cover well-formed success and pre-stream errors but not the mid-stream failure. If it is already handled, a line saying which frame carries it closes the gap for good.

@bong-water-water-bong bong-water-water-bong left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

VERDICT: READY at 1dde6eb — I built the bridge and its test at this head and ran them twice: once plainly, once under ThreadSanitizer, 40 consecutive runs, zero warnings. For a two-thread hand-off that is the check that matters, and it is clean.

$ g++ -O2 -std=c++17 -I app tests/stream_bridge_test.cpp -o sb -pthread && ./sb        -> stream_bridge: ok
$ g++ -O1 -g -fsanitize=thread -I app … && for i in $(seq 1 40); do ./sbtsan; done     -> 40/40 clean, 0 TSan warnings

The subtlest part is right, and I checked it rather than assuming: the worker writes *early while the handler thread reads it, and the code paths are ordered so that cannot race — wait_first() returns false only after the worker has called finish(), which is after early->status/set_content, and the handler then join()s before reading early. Taking the status from early only on the no-frame path, and pushing the error into the stream when started() is true ("a status cannot change once a stream has started"), is exactly the right split.

Four notes, none blocking.

  1. A streaming request now costs two threads, not one. Before, the generation ran on the connection thread; now it runs on its own, and the connection thread blocks in next() for the length of the reply. Under httplib's pool that is 2N threads and N in-flight generations for N concurrent streams. That is the price of streaming correctly, not a defect — but it is a capacity change, and it belongs in the doc paragraph this PR adds, since the first thing a reader will ask is where the second thread comes from.
  2. push()'s bool is ignored at every call site. The header says it exists "so the producer can stop early"; the producer instead polls cancelled() once per token, which is the check that actually stops it. Both work, but a reader has to notice that the documented mechanism is unused — either use the return in send() or say in the header that the token loop's cancelled() is the stop, and push's bool is for callers that push in a burst.
  3. wait_first()'s predicate is pushed_ > 0 || finished_ — cancelled_ is not in it. Harmless today (only the consumer cancels, and it cannot be inside wait_first() and calling cancel() at once), but if the releaser ever runs while the handler is still waiting — an aborted response settled from another thread — wait_first() would block until the producer finishes rather than returning. One clause in the header, or cancelled_ in the predicate with a "false on cancel" meaning.
  4. res.status = early->status > 0 ? early->status : 500 makes "the implementation never set a status" indistinguishable from "it failed". That is true on today's paths (a successful stream always pushes [DONE], so no-frame means failure), but a future stream route that legitimately pushes nothing would be answered 500. Setting early->status = 200 before the worker starts makes the fallback mean only what it says.

The measurement is the right one to have wanted: 14 chunks all arriving at 9.668 s of a 9.668 s reply is a client-side TTFT of the whole request, and this is the change that fixes the cause (the frames were built during generation and sent after, because httplib writes only after the handler returns) rather than the symptom. The non-streamed path is untouched — bridge == nullptr still collects into chunks and sends on return — so an ordinary request cannot regress.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant