fix(timmy): stop SSE streams being cut at the server write timeout - #622
Merged
Conversation
tmi-ux reported net::ERR_HTTP2_PROTOCOL_ERROR on
POST /threat_models/{id}/chat/sessions/{id}/messages. Timmy answers appeared
truncated in the browser while the server logged 200 with no error.
http.Server.WriteTimeout bounds the ENTIRE response write and Go arms that
deadline when the request header is read, not per write. cmd/server/main.go
applies it unconditionally and the default is 10s, so any SSE stream living
longer than 10s has every subsequent write fail with i/o timeout. The failure
is silent: the handler keeps producing events into a dead socket, returns
normally, and the request logger records 200. The browser only learns anything
is wrong when the connection closes abruptly at handler return.
Measured against the AWS deployment, driving the real client origin:
last byte received 10,055 ms <- the 10s WriteTimeout, to within 55ms
error surfaced 25,761 ms <- handler return, connection closed
silent gap 15,706 ms
message_end never
That 15.7s gap is also wasted LLM spend: tokens were generated and billed for a
client that stopped receiving at 10s.
It explains the whole symptom set. Streams under 10s always worked — a 1.8s
message and a 1.2s session create both completed — which is why this looked
intermittent rather than systematic, and why one observed 9.8s session create
survived by 0.2s. Session creation emits progress events continuously and
finishes fast; a message goes quiet while the model thinks and then streams a
long answer, so it is the one that reliably crosses the line.
The fix clears the write deadline for the response via
http.NewResponseController. That needed a second change: gin.ResponseWriter is
an interface that does not declare Unwrap, so bufferedResponseWriter (which
JSONErrorHandler wraps every response in) promoted no Unwrap and the controller
stopped there with ErrNotSupported — the clear would have silently done
nothing. bufferedResponseWriter now exposes Unwrap, and gin's own
*responseWriter implements it the rest of the way to the connection.
Guarded by a test that streams past a deliberately short WriteTimeout through
the real middleware stack. Against the old code it fails the same way
production did — "stream broke mid-flight after 5/12 tokens (sawEnd=false):
unexpected EOF" — where 5 tokens x 60ms is the 300ms deadline.
Also removes c.Header("Connection", "keep-alive") from the SSE writer. That is
unrelated to this bug — I confirmed session-creation streams carrying the same
header complete cleanly over HTTP/2 — but it is redundant on HTTP/1.1, where Go
manages keep-alive, and RFC 9113 section 8.2.2 forbids connection-specific
header fields in HTTP/2 outright.
Not addressed here, worth a follow-up: the SSE writer's write errors are
discarded by callers, so the server cannot notice a client has gone and keeps
paying for tokens nobody receives.
lint 0 - 2421 unit tests
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01WnrVyySuyJFqcMxB8q3pNc
…able Every SendEvent/SendToken/SendError call site discarded its error with `_ =`. All 11 of them, across both streaming handlers. The writer reported failures carefully and nobody listened, so a broken stream was indistinguishable from a healthy one. That is what made the WriteTimeout truncation expensive rather than merely wrong. Measured in production: writes started failing at 10.055s, and the handler went on generating for another 15.7s — billed tokens for a socket nobody was reading. IsClientGone could not have caught it either. It only checks request-context cancellation, which covers a client that disconnects cleanly. A write that fails does NOT cancel the context — from Go's side the request is still in flight — so the check reported a healthy client throughout. So the writer now latches the first write failure, and IsClientGone reports it alongside cancellation. Latching does three things: later sends short-circuit instead of repeating a syscall that cannot succeed, the warning is logged once rather than once per token, and the existing IsClientGone checks in both handlers start firing without needing new plumbing. Marshalling failures are deliberately NOT latched — a bad payload is a bug in one event, not a broken connection, and the stream is still usable. The token callback now cancels the LLM context when it trips. Returning early only stops us WRITING; generation continues, which is the cost this is meant to avoid. The LLM context is deliberately detached via context.WithoutCancel (so a 30s request deadline cannot cap a 120s inference), which means this callback is the only thing that can end generation early. llmCancel is therefore declared before the callbacks and assigned at context creation. Remaining call sites log rather than abort, chosen per site: a lost progress or status event is not worth failing a session that is otherwise fine and readable via GET, while a lost message_end is logged explicitly as "client will appear to have been cut off mid-answer" — the exact symptom reported — because the message IS persisted and retrievable even though this client never saw it. Guarded by a test that fails writes while leaving the request context live, which is precisely the condition the old code could not detect: it asserts the failure latches, IsClientGone flips, and five further sends make zero additional write syscalls. Found the call sites with ripgrep rather than graphify: tmi has no graphify-out/graph.json, and the CLAUDE.md rule is conditional on that graph existing. lint 0 - 2422 unit tests Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WnrVyySuyJFqcMxB8q3pNc
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
The problem
tmi-ux reported
net::ERR_HTTP2_PROTOCOL_ERRORonPOST /threat_models/{id}/chat/sessions/{id}/messages. Timmy answers appeared truncated in the browser while the server logged200with no error.http.Server.WriteTimeoutbounds the entire response write, and Go arms that deadline when the request header is read — not per write.cmd/server/main.go:2106applies it unconditionally and the default is 10s, so any SSE stream living longer has every subsequent write fail withi/o timeout. Silently: the handler keeps producing events into a dead socket, returns normally, and the request logger records 200. The browser only learns anything is wrong when the connection closes abruptly at handler return.Measured against the AWS deployment, driving the real client origin
message_endThat 15.7s gap is also wasted LLM spend: tokens generated and billed for a client that stopped receiving at 10s.
It explains the whole symptom set. Streams under 10s always worked — a 1.8s message and a 1.2s session create both completed — which is why this looked intermittent rather than systematic, and why one observed 9.8s session create survived by 0.2s. Session creation emits progress events continuously and finishes fast; a message goes quiet while the model thinks and then streams a long answer, so it is the one that reliably crosses the line.
The fix
Clears the write deadline for the response via
http.NewResponseController. That needed a second change:gin.ResponseWriteris an interface that does not declareUnwrap, sobufferedResponseWriter(whichJSONErrorHandlerwraps every response in) promoted noUnwrapand the controller stopped there withErrNotSupported— the clear would have compiled, run, and silently done nothing.Second commit: stop paying for tokens nobody receives
All 11
SendEvent/SendToken/SendErrorcall sites discarded their error with_ =.IsClientGonecould not have caught this either — it only checks request-context cancellation, and a failed write does not cancel the context.The writer now latches the first write failure and
IsClientGonereports it alongside cancellation. The token callback cancels the LLM context when it trips: returning early only stops us writing, while generation continues. The LLM context is deliberately detached viacontext.WithoutCancel(so a 30s request deadline cannot cap a 120s inference), which makes that callback the only thing that can end generation early.Also
Removes
c.Header("Connection", "keep-alive")from the SSE writer. Unrelated to this bug — I confirmed session-creation streams carrying the same header complete cleanly over HTTP/2 — but it is redundant on HTTP/1.1 and RFC 9113 §8.2.2 forbids connection-specific header fields in HTTP/2.Verification
A test streams past a deliberately short
WriteTimeoutthrough the real middleware stack. Against the old code it fails the same way production did:stream broke mid-flight after 5/12 tokens (sawEnd=false): unexpected EOF, where 5 tokens × 60 ms is the 300 ms deadline. A second test fails writes while leaving the request context live — the exact condition the old code could not detect — asserting the failure latches,IsClientGoneflips, and five further sends make zero additional write syscalls.lint 0 · 2422 unit tests
🤖 Generated with Claude Code
https://claude.ai/code/session_01WnrVyySuyJFqcMxB8q3pNc