diff --git a/internal/proxy/request.go b/internal/proxy/request.go index b4d32fc..5eedc12 100644 --- a/internal/proxy/request.go +++ b/internal/proxy/request.go @@ -795,9 +795,19 @@ func (rq *request) responseTimedOut() { } } -// responseReceived is called once the app has sent its whole answer. +// responseReceived is called once the app has sent its whole answer. An +// app may answer before the client has sent its whole body, as with a 404 +// it sends without reading it. The timeouts then run on: until the +// transport's read of the body returns, Go's server cannot send the +// answer, and SWWAF_CLIENT_REQUEST_TIMEOUT is what ends that read for a +// client that stops sending. func (rq *request) responseReceived() { rq.complete = true + + if rq.body != nil && !rq.body.received.Load() { + return + } + rq.stopTimers() } diff --git a/internal/proxy/timeouts_test.go b/internal/proxy/timeouts_test.go index dab7791..ff00c8c 100644 --- a/internal/proxy/timeouts_test.go +++ b/internal/proxy/timeouts_test.go @@ -194,6 +194,60 @@ func sendLargeBody(t *testing.T, addr string) net.Conn { return conn } +func TestClientStopsSendingAfterTheAppHasAnswered(t *testing.T) { + t.Parallel() + + // answeredAt is when the app answered, or nil if the bytes the client + // sent never reached it. + var answeredAt atomic.Pointer[time.Time] + + // The app answers without reading the whole body, as an app does for + // a path it does not serve, and only once smallwebwaf waits for the + // rest of it: the app takes the bytes the client sent, and then waits + // half the timeout, far longer than smallwebwaf takes to go on to + // wait. + app := startApp(t, func(w http.ResponseWriter, r *http.Request) { + _, err := io.ReadFull(r.Body, make([]byte, len("the first bytes"))) + if err != nil { + return + } + + time.Sleep(shortTimeout / 2) + answeredAt.Store(new(time.Now())) + http.NotFound(w, r) + }) + addr, out := startProxy(t, app.URL, map[string]string{ + clientRequestTimeout: shortTimeoutSetting, + metricsToken: token, + }) + + start := time.Now() + got := readResponse(t, sendPartOfBody(t, addr)) + wantTimedOut(t, start) + + // Close returns once the app has finished with the request. + app.Close() + + // The app's answer came before the time ran out, so the client is + // sent that answer, not smallwebwaf's 408. Only a hold-up of the test + // process can make it come later, and SPEC.md then asks for 408, as + // smallwebwaf was waiting for the client, or for 504 if the bytes the + // client sent had not reached the app. + at := answeredAt.Load() + want := http.StatusNotFound + + switch { + case at == nil: + want = http.StatusGatewayTimeout + case at.Sub(start) >= shortTimeout: + want = http.StatusRequestTimeout + } + + wantStatus(t, got, want) + wantLine(t, out.requestLine(t), want, requestlog.ActionTimedOut) + wantLimitHits(t, addr, clientRequestTimeout, 1) +} + func TestAppTooSlowToAnswer(t *testing.T) { t.Parallel()