diff --git a/internal/api/handlers_logstream_test.go b/internal/api/handlers_logstream_test.go index f62fd30..f53aae4 100644 --- a/internal/api/handlers_logstream_test.go +++ b/internal/api/handlers_logstream_test.go @@ -673,3 +673,71 @@ func TestRelayLogStreamWriteDeadlineSeversStalledReader(t *testing.T) { t.Fatal("relay returned without closing the source — upstream pod-log follow leaked") } } + +// deadlineRecordWriter records the write deadlines the relay sets and never blocks on +// flush — a healthy client whose stream simply ends. It pins the deadline-CLEAR half of +// the leak guard: SetWriteDeadline stores every value, so the test can read back the +// LAST one the relay left behind after it returns. sawPositive proves a real per-write +// deadline was applied during streaming, so a broken fix that never sets a deadline at +// all cannot pass the clear-check by leaving the field zero throughout. +type deadlineRecordWriter struct { + mu sync.Mutex + hdr http.Header + lastDeadline time.Time + sawPositive bool +} + +func newDeadlineRecordWriter() *deadlineRecordWriter { + return &deadlineRecordWriter{hdr: http.Header{}} +} + +func (s *deadlineRecordWriter) Header() http.Header { return s.hdr } +func (s *deadlineRecordWriter) WriteHeader(int) {} +func (s *deadlineRecordWriter) Write(p []byte) (int, error) { return len(p), nil } +func (s *deadlineRecordWriter) Flush() {} +func (s *deadlineRecordWriter) FlushError() error { return nil } // healthy: never blocks + +func (s *deadlineRecordWriter) SetWriteDeadline(t time.Time) error { + s.mu.Lock() + s.lastDeadline = t + if !t.IsZero() { + s.sawPositive = true + } + s.mu.Unlock() + return nil +} + +func (s *deadlineRecordWriter) finalDeadline() (last time.Time, sawPositive bool) { + s.mu.Lock() + defer s.mu.Unlock() + return s.lastDeadline, s.sawPositive +} + +// TestRelayLogStreamClearsWriteDeadlineOnReturn pins the keep-alive hygiene half of the +// §8 leak guard (audit #1 follow-up). Server.WriteTimeout is deliberately UNSET so a +// healthy long SSE stream is never severed (cmd/felis api.go), and with it unset net/http +// never resets the connection's write deadline between keep-alive requests. So the +// per-write deadline the relay sets must be CLEARED when the relay returns — otherwise it +// leaks onto the NEXT request that reuses this pooled connection and fails that request's +// first write for no reason. Here a finite source EOFs cleanly; after the relay returns +// the writer's final deadline must be the zero value, and a positive deadline must have +// been set first (so a fix that never sets a deadline at all cannot pass by leaving zero +// the whole time). +func TestRelayLogStreamClearsWriteDeadlineOnReturn(t *testing.T) { + src := &recordReadCloser{r: strings.NewReader("boot\n")} + w := newDeadlineRecordWriter() + r := httptest.NewRequest("GET", "/api/v1/servers/survival/console", nil) + + relayLogStream(w, r, src) + + last, sawPositive := w.finalDeadline() + if !sawPositive { + t.Fatal("relay never set a per-write deadline — the leak guard is not wired into the write path") + } + if !last.IsZero() { + t.Fatalf("relay left a write deadline of %v set on return; it must clear it to the zero value so it cannot leak onto a reused keep-alive connection", last) + } + if !src.closed { + t.Fatal("relay returned without closing the source") + } +} diff --git a/internal/api/logstream.go b/internal/api/logstream.go index ba1e547..2b595d8 100644 --- a/internal/api/logstream.go +++ b/internal/api/logstream.go @@ -110,6 +110,13 @@ func relayLogStream(w http.ResponseWriter, r *http.Request, src io.ReadCloser) { // per-write deadline set inside writeChunk is what severs an unresponsive client; // the initial header flush below stays a plain best-effort flush (no deadline). rc := http.NewResponseController(w) + // Clear any per-write deadline on return. Server.WriteTimeout is deliberately UNSET + // (cmd/felis api.go — a WriteTimeout would sever a healthy long SSE stream), and + // with it unset net/http never resets the write deadline between keep-alive + // requests. So a deadline left set by the last writeChunk would leak onto the NEXT + // request that reuses this pooled connection and fail its first write for no reason. + // The zero time clears it; best-effort, a no-op on writers without deadline support. + defer func() { _ = rc.SetWriteDeadline(time.Time{}) }() h := w.Header() h.Set("Content-Type", "text/event-stream") @@ -118,6 +125,12 @@ func relayLogStream(w http.ResponseWriter, r *http.Request, src io.ReadCloser) { // Defeat proxy buffering (nginx / ingress) so events arrive promptly. h.Set("X-Accel-Buffering", "no") w.WriteHeader(http.StatusOK) + // Best-effort header flush, deliberately WITHOUT a write deadline. A client that + // stalls its receive window BEFORE these headers drain is therefore NOT severed by + // writeTimeout at connect time — routing this flush through the deadline guard would + // break the guard's test specificity, and the connect-time stall is already bounded + // by the per-principal stream cap (#44). Only the mid-stream stall (every writeChunk + // below) is CLOSED by the deadline guard, not merely bounded. flusher.Flush() // bufio.Scanner.Scan blocks until a line arrives, so to interleave a periodic