A client that stops sending after the app answers is timed out (closes #130)

When the app answered before the client had sent its whole body, and its
answer ended with its last bytes, every timeout was stopped,
SWWAF_CLIENT_REQUEST_TIMEOUT included. The transport went on waiting to
read the body, and Go's server cannot send the answer until that read
returns, so a client that stopped sending held the request until it
closed the connection. The timeouts now run on until the client has sent
its body, as they do before the app answers: once
SWWAF_CLIENT_REQUEST_TIMEOUT runs out the client is sent the app's
answer, the connection is closed, and the log line says timed_out.

Model: opus-5-5

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()
 }
 

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()