rproxy: cut off an answer that stalls after arriving before the whole request (closes #345)

When the app's answer arrived before the app had been sent the whole
request, SWRP_MAX_RESPONSE_TIME_MS had no timer: only the end of the
request started one. If the app then stalled, only a write could fail at
the deadline. With nothing written, the connection stayed open until the
request time limit.

modifyResponse now starts the response timer when it ends the request.
Once the timer cuts off the app's answer, nothing is left to flush, so the
last flush in finish succeeded and Go's server read the rest of the body.
finish now also ends that reading at once after a refusal of an answer
already passed on.

Model: opus-5-5

internal/rproxy/limits_test.go

@@ -382,19 +382,6 @@ type deadlineRecorder struct {
 	// stalled, if set, sends the part of the request body that never arrives. A
 	// read deadline that has passed ends a read of it, as on a connection.
 	stalled *io.PipeWriter
-	// flushError, if set, is what every flush returns, and nothing is flushed.
-	flushError error
-}
-
-// FlushError returns flushError if it is set, and otherwise flushes.
-func (w *deadlineRecorder) FlushError() error {
-	if w.flushError != nil {
-		return w.flushError
-	}
-
-	w.Flush()
-
-	return nil
 }
 
 // SetReadDeadline notes deadline.
@@ -460,45 +447,6 @@ func TestABodyLeftUnreadIsReadOnlyUntilTheRequestTimeLimit(t *testing.T) {
 	}
 }
 
-func TestABodyLeftUnreadIsReadNoMoreOnceTheTimeToSendTheAnswerRunsOut(t *testing.T) {
-	t.Parallel()
-
-	standIn := startWAF(t, allow)
-	app := startApp(t, answerBeforeTheBody)
-	_, _, server := startServer(t, standIn.URL, app.URL, nil)
-
-	// The visitor sends the first part and a little more, and then nothing.
-	stalled, stop := io.Pipe()
-
-	t.Cleanup(func() { _ = stop.Close() })
-
-	req := httptest.NewRequestWithContext(t.Context(), http.MethodPost, "/",
-		io.MultiReader(bytes.NewReader(make([]byte, questionBodyMaxBytes+1)), stalled))
-	req.ContentLength = 2 * questionBodyMaxBytes
-	req.Header.Set(contentLengthHeader, strconv.Itoa(2*questionBodyMaxBytes))
-
-	// Every flush fails, as once the time to send the answer has run out. The
-	// default time limits are far longer than the test, so rproxy records no
-	// refusal.
-	w := &deadlineRecorder{
-		ResponseRecorder: httptest.NewRecorder(),
-		stalled:          stop,
-		flushError:       os.ErrDeadlineExceeded,
-	}
-
-	before := time.Now()
-
-	server.Handler.ServeHTTP(w, req)
-
-	if w.Code != http.StatusOK {
-		t.Errorf("status %d, want the app's 200", w.Code)
-	}
-
-	if w.readDeadline.Before(before) || w.readDeadline.After(time.Now()) {
-		t.Errorf("the reading of the body ends at %s, want now", w.readDeadline)
-	}
-}
-
 func TestAnAnswerRProxyGivesItselfHasTheResponseTimeToBeSent(t *testing.T) {
 	t.Parallel()
 
@@ -969,8 +917,7 @@ func TestAVisitorThatStopsALittleShortHasTheConnectionClosedWhenTheAnswerIsCutOf
 ) {
 	t.Parallel()
 
-	// rproxy passes on a part sent at once well within this limit, even on a busy
-	// host.
+	// A busy host passes on a part sent at once well within this limit.
 	const limit = 2 * time.Second
 
 	// The app sends the parts in atOnce with its status and headers. It sends the
@@ -981,7 +928,11 @@ func TestAVisitorThatStopsALittleShortHasTheConnectionClosedWhenTheAnswerIsCutOf
 		atOnce, late []string
 	}{
 		{"with the body in one part", nil, []string{greeting}},
-		{"with the body in two parts", []string{greeting[:5]}, []string{greeting[5:]}},
+		{"with the body in two parts", nil, []string{greeting[:5], greeting[5:]}},
+		{
+			"with the first part of the body at once",
+			[]string{greeting[:5]}, []string{greeting[5:]},
+		},
 	} {
 		t.Run(tc.name, func(t *testing.T) {
 			t.Parallel()

internal/rproxy/request.go

@@ -272,6 +272,10 @@ func (rq *request) modifyResponse(res *http.Response) error {
 
 	rq.closeAfterAnswer()
 
+	// An answer that arrives before the app has been sent the whole request ends
+	// the request, and SWRP_MAX_RESPONSE_TIME_MS starts.
+	rq.startResponseTimer(requestEnd)
+
 	res.Body = &responseBody{body: limitBody(res.Body, maxBytes), rq: rq}
 	rq.out.afterStatus = rq.setResponseDeadline
 
@@ -386,14 +390,17 @@ func (rq *request) finish(ctx context.Context) {
 
 	// After a cut-off answer, the reading of a body that has not arrived whole
 	// ends now. Go's server would otherwise keep the connection open while it
-	// reads the rest. A flush fails if the time to send the answer ran out, and
+	// reads the rest. The app's answer is cut off by a refusal once it is passed
+	// on, as afterStatus shows, since a refusal ends the request to the app. Any
+	// answer is cut off when the time to send it runs out: a flush then fails, and
 	// every flush after a failed one fails too. ReverseProxy ignores the failure,
 	// but panics if it was still waiting for more of the app's answer; finish runs
 	// either way. Before a status, a flush would send a 200; after a 101,
 	// ReverseProxy has taken over the connection.
 	switch {
-	case rq.out.status != 0 && rq.out.status != http.StatusSwitchingProtocols &&
-		errors.Is(rq.rc.Flush(), os.ErrDeadlineExceeded):
+	case rq.out.afterStatus != nil && rq.refused.Load() != 0,
+		rq.out.status != 0 && rq.out.status != http.StatusSwitchingProtocols &&
+			errors.Is(rq.rc.Flush(), os.ErrDeadlineExceeded):
 		rq.stopPassingOnBody(time.Now())
 	case rq.refused.Load() == 0:
 		rq.stopPassingOnBody(rq.requestDeadline())
@@ -553,19 +560,29 @@ func (rq *request) wroteRequest(info httptrace.WroteRequestInfo) {
 	requestEnd := rq.endRequest()
 
 	rq.mu.Lock()
-	defer rq.mu.Unlock()
+	stopTimer(rq.requestTimer)
+	rq.mu.Unlock()
 
-	if rq.timersStopped {
+	rq.startResponseTimer(requestEnd)
+}
+
+// startResponseTimer starts SWRP_MAX_RESPONSE_TIME_MS, which runs from
+// requestEnd, unless it has started already.
+func (rq *request) startResponseTimer(requestEnd time.Time) {
+	limit := rq.h.config.MaxResponseTime
+	if limit == 0 {
 		return
 	}
 
-	stopTimer(rq.requestTimer)
+	rq.mu.Lock()
+	defer rq.mu.Unlock()
 
-	limit := rq.h.config.MaxResponseTime
-	if limit > 0 {
-		rq.responseTimer = time.AfterFunc(time.Until(requestEnd.Add(limit)),
-			rq.responseTimedOut)
+	if rq.timersStopped || rq.responseTimer != nil {
+		return
 	}
+
+	rq.responseTimer = time.AfterFunc(time.Until(requestEnd.Add(limit)),
+		rq.responseTimedOut)
 }
 
 // responseTimedOut is called when SWRP_MAX_RESPONSE_TIME_MS runs out before the