A client that stops sending with little of its body left after the app has answered is timed out (closes #136)

When less than 256 KiB of a client's body is left, Go's server reads the
rest before it sends the app's answer, and the transport reads it as it
closes the body after a failed write to the app. Neither read goes
through requestBody.Read, so when SWWAF_CLIENT_REQUEST_TIMEOUT ran out
smallwebwaf took the 504 branch, which set no read deadline, and the
request held its connection for as long as the client kept it open.
That branch now ends reading the client's body at the client's
deadline too.

Model: opus-5-5

internal/bans/admin_test.go

@@ -61,59 +61,6 @@ func TestAdminsBansAreNeverDroppedAndDoNotCountTowardMaxBans(t *testing.T) {
 	wantBans(t, ledger, map[netip.Prefix]int{adminsOnly: 2, both: 1, second: 0, third: 1})
 }
 
-func TestEarlierBansCountABanDroppedAfterAnAdminsBan(t *testing.T) {
-	t.Parallel()
-
-	rules := defaultRules()
-	rules.MaxBans = 2
-	ledger := bans.New(rules)
-	netblock := netip.MustParsePrefix("203.0.113.1/32")
-	other := netip.MustParsePrefix("203.0.113.2/32")
-
-	// An admin bans the netblock for a minute, and it then breaks a limit
-	// twice, each time after its last ban has ended.
-	ledger.BanForAdmin(netblock, midnight(), midnight().Add(time.Minute),
-		"probes for logins")
-	first, _ := ledger.BanForLimit(netblock, midnight().Add(time.Minute), bans.Notes{})
-	second, _ := ledger.BanForLimit(netblock, first.Expires, bans.Notes{})
-
-	// A ban on another netblock fills the ledger, and the netblock's first
-	// ban for a limit, its earliest that is not an admin's, goes.
-	ledger.BanForLimit(other, second.Start, bans.Notes{})
-	wantBans(t, ledger, map[netip.Prefix]int{netblock: 2, other: 1})
-
-	// The netblock's next ban still counts it.
-	third, _ := ledger.BanForLimit(netblock, second.Expires, bans.Notes{})
-	if third.Notes.EarlierBans != (bans.EarlierBans{Limit: 2, Admin: 1}) {
-		t.Errorf("the third ban for a limit has earlier bans %+v, "+
-			"want 2 for a limit and 1 an admin's", third.Notes.EarlierBans)
-	}
-}
-
-func TestEarlierBansCountABanAnAdminKeepsOnce(t *testing.T) {
-	t.Parallel()
-
-	ledger := bans.New(defaultRules())
-	netblock := netip.MustParsePrefix("203.0.113.1/32")
-
-	// The netblock breaks a limit twice, the second time after its first
-	// ban has ended, and the second ban's notes count the first. An admin
-	// then keeps the first ban.
-	first, _ := ledger.BanForLimit(netblock, midnight(), bans.Notes{})
-	second, _ := ledger.BanForLimit(netblock, first.Expires, bans.Notes{})
-
-	kept := first
-	kept.Cause = bans.CauseAdmin
-	ledger.LoadEdit([]bans.Ban{kept, second})
-
-	// The netblock's next ban counts the kept ban once, as an admin's.
-	third, _ := ledger.BanForLimit(netblock, second.Expires, bans.Notes{})
-	if third.Notes.EarlierBans != (bans.EarlierBans{Limit: 1, Admin: 1}) {
-		t.Errorf("the third ban for a limit has earlier bans %+v, "+
-			"want 1 for a limit and 1 an admin's", third.Notes.EarlierBans)
-	}
-}
-
 func TestReasonOfTheBansSmallwebwafMakes(t *testing.T) {
 	t.Parallel()
 

internal/bans/bans.go

@@ -687,51 +687,26 @@ func (l *Ledger) ban(
 }
 
 // earlierBans returns how many bans a netblock with the bans held, oldest
-// first, has had, by cause. Each ban held gives a count: the bans its
-// notes count before it, and one for it and each ban held after it. A
-// ban's count misses a ban dropped after it to make room, and that of an
-// admin's ban added to bans.json without notes misses the bans before it,
-// so the count that names the most bans is taken, whole: a ban an admin
-// keeps by giving it CauseAdmin is still counted under its old cause in
-// later bans' notes, and taking each cause from another count would count
-// it twice.
+// first, has had, by cause: the first ban held counts the bans the
+// netblock had before that one, since dropped to make room, and each ban
+// held adds one.
 func earlierBans(held []Ban) EarlierBans {
-	// fromHere counts ban and the bans held after it.
-	var most, fromHere EarlierBans
+	earlier := held[0].Notes.EarlierBans
 
-	for _, ban := range slices.Backward(held) {
+	for _, ban := range held {
 		switch ban.Cause {
 		case CauseLimit:
-			fromHere.Limit++
+			earlier.Limit++
 		case CauseAttack:
-			fromHere.Attack++
+			earlier.Attack++
 		case CauseAdmin:
-			fromHere.Admin++
+			earlier.Admin++
 		case CauseCrowdSec:
-			fromHere.CrowdSec++
-		}
-
-		notes := ban.Notes.EarlierBans
-		count := EarlierBans{
-			Limit:    notes.Limit + fromHere.Limit,
-			Attack:   notes.Attack + fromHere.Attack,
-			Admin:    notes.Admin + fromHere.Admin,
-			CrowdSec: notes.CrowdSec + fromHere.CrowdSec,
-		}
-
-		// Of counts that name as many bans, the earlier ban's is taken: it
-		// counts more of the bans held by the cause they have now.
-		if count.total() >= most.total() {
-			most = count
+			earlier.CrowdSec++
 		}
 	}
 
-	return most
-}
-
-// total returns how many bans e counts, of all causes.
-func (e EarlierBans) total() int {
-	return e.Limit + e.Attack + e.Admin + e.CrowdSec
+	return earlier
 }
 
 // markChanged has Changed receive a value, unless one is waiting already.

internal/proxy/request.go

@@ -710,21 +710,17 @@ func (rq *request) requestTimedOut(limit string) {
 	}
 
 	if rq.body == nil || !rq.body.waiting.Load() {
-		// Once the app has answered, the transport, ReverseProxy and Go's
-		// server each close the client's body, and closing it reads what
-		// is left of a body under 256 KiB without requestBody.Read, so
-		// waiting is false while that read waits for the client. That
-		// read ends now, before refuse: should smallwebwaf still answer
-		// itself, answer then sets the deadline it gives its own answers.
-		if !rq.answerStarted.IsZero() {
-			rq.stopReadingBody(time.Now())
-		}
-
 		rq.refuse(refusal{
 			status: http.StatusGatewayTimeout,
 			action: requestlog.ActionTimedOut,
 			limit:  limit,
 		})
+		// Go's server, before it sends the app's answer, and the
+		// transport, as it closes the body, read what is left of a body
+		// under 256 KiB without requestBody.Read, so waiting is false
+		// while they wait for the client. Those reads end when the client
+		// is out of time.
+		rq.stopReadingBody(rq.clientRequestDeadline())
 
 		return
 	}

internal/proxy/timeouts_test.go

@@ -252,88 +252,54 @@ func TestClientStopsSendingAfterTheAppHasAnswered(t *testing.T) {
 func TestClientStopsSendingWithLittleOfItsBodyLeft(t *testing.T) {
 	t.Parallel()
 
-	for _, tc := range []struct {
-		name string
-		// limit is the setting set to shortTimeout, which runs out, and
-		// clientTimeout what SWWAF_CLIENT_REQUEST_TIMEOUT is set to when it
-		// is not limit.
-		limit, clientTimeout string
-	}{
-		{
-			name:  "client request timeout",
-			limit: clientRequestTimeout,
-		},
-		{
-			name:          "upstream request timeout, client request timeout off",
-			limit:         upstreamRequestTimeout,
-			clientTimeout: off,
-		},
-		{
-			name:          "upstream request timeout, client request timeout longer",
-			limit:         upstreamRequestTimeout,
-			clientTimeout: longTimeoutSetting,
-		},
-	} {
-		t.Run(tc.name, func(t *testing.T) {
-			t.Parallel()
+	// appClosed is closed once smallwebwaf has closed its connection to
+	// the app, which it does once it has the app's answer.
+	appClosed := make(chan struct{})
 
-			// appClosed is closed once smallwebwaf has closed its
-			// connection to the app, which it does once it has the app's
-			// answer.
-			appClosed := make(chan struct{})
+	// The app answers as soon as it has the headers, without reading the
+	// body, and says it closes the connection.
+	app := startApp(t, func(w http.ResponseWriter, _ *http.Request) {
+		conn, buf, err := http.NewResponseController(w).Hijack()
+		if err != nil {
+			return
+		}
 
-			// The app takes the bytes the client sent, so that smallwebwaf
-			// is waiting for the client to send more, and then answers
-			// without reading the rest of the body, and says it closes the
-			// connection.
-			app := startApp(t, func(w http.ResponseWriter, _ *http.Request) {
-				conn, buf, err := http.NewResponseController(w).Hijack()
-				if err != nil {
-					return
-				}
+		_, _ = buf.WriteString("HTTP/1.1 404 Not Found\r\n" +
+			"Content-Length: 0\r\nConnection: close\r\n\r\n")
+		_ = buf.Flush()
+		_, _ = io.Copy(io.Discard, buf.Reader)
+		_ = conn.Close()
 
-				_, _ = io.ReadFull(buf.Reader, make([]byte, len("the first bytes")))
-				_, _ = buf.WriteString("HTTP/1.1 404 Not Found\r\n" +
-					"Content-Length: 0\r\nConnection: close\r\n\r\n")
-				_ = buf.Flush()
-				_, _ = io.Copy(io.Discard, buf.Reader)
-				_ = conn.Close()
+		close(appClosed)
+	})
+	addr, out := startProxy(t, app.URL, map[string]string{
+		clientRequestTimeout: shortTimeoutSetting,
+		metricsToken:         token,
+	})
 
-				close(appClosed)
-			})
+	// Less than 256 KiB of the body is left after the first bytes, little
+	// enough for Go's server in smallwebwaf to read the rest itself before
+	// it sends the app's answer.
+	start := time.Now()
+	conn := dial(t, addr)
+	send(t, conn, "POST /upload HTTP/1.1\r\nHost: app\r\nContent-Length: 200000\r\n\r\n"+
+		"the first bytes")
 
-			env := map[string]string{tc.limit: shortTimeoutSetting, metricsToken: token}
-			if tc.clientTimeout != "" {
-				env[clientRequestTimeout] = tc.clientTimeout
-			}
-
-			addr, out := startProxy(t, app.URL, env)
-
-			// Less than 256 KiB of the body is left after the first bytes,
-			// little enough for Go's server in smallwebwaf to read the rest
-			// itself before it sends the app's answer.
-			start := time.Now()
-			conn := dial(t, addr)
-			send(t, conn, "POST /upload HTTP/1.1\r\nHost: app\r\nContent-Length: 200000\r\n\r\n"+
-				"the first bytes")
-
-			select {
-			case <-appClosed:
-			case <-time.After(waitLimit):
-				t.Fatal("smallwebwaf did not close its connection to the app")
-			}
-
-			// More of the body, which can no longer go to the app, and then
-			// nothing.
-			send(t, conn, strings.Repeat("x", 8<<10))
-
-			got := readResponse(t, conn)
-			wantTimedOut(t, start)
-			wantStatus(t, got, http.StatusNotFound)
-			wantLine(t, out.requestLine(t), http.StatusNotFound, requestlog.ActionTimedOut)
-			wantLimitHits(t, addr, tc.limit, 1)
-		})
+	select {
+	case <-appClosed:
+	case <-time.After(waitLimit):
+		t.Fatal("smallwebwaf did not close its connection to the app")
 	}
+
+	// More of the body, which can no longer go to the app, and then
+	// nothing.
+	send(t, conn, strings.Repeat("x", 8<<10))
+
+	got := readResponse(t, conn)
+	wantTimedOut(t, start)
+	wantStatus(t, got, http.StatusNotFound)
+	wantLine(t, out.requestLine(t), http.StatusNotFound, requestlog.ActionTimedOut)
+	wantLimitHits(t, addr, clientRequestTimeout, 1)
 }
 
 func TestAppTooSlowToAnswer(t *testing.T) {