rproxy: circuit breaker for asks to waf (closes #392)

Five asks that get no answer in time within five seconds open the
breaker. While open, a request takes
SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION without asking waf, except
one ask a second; the first answer closes it. Slow answers count as
failures. SPEC.md describes it.

The sww test that stops and restarts waf now waits for the breaker to
close before it expects the ban again.

Model: opus-5-5

README.md

@@ -298,7 +298,7 @@ Every setting the code reads, with its default:
 | `SWW_RPROXY_LISTEN_ADDR`                          | `:8080`                                                                                  | Where `rproxy` listens; leave the host part empty.                                                                                                                                                                                                              |
 | `SWW_RPROXY_TRUSTED_PROXIES`                      | `10.0.0.0/8,172.16.0.0/12,192.168.0.0/16`                                                | The netblocks whose `X-Forwarded-For` `rproxy` believes; set but empty, it believes none.                                                                                                                                                                       |
 | `SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`               | `2000`                                                                                   | How long `rproxy` waits for `waf`'s answer to a question and to a report, in milliseconds.                                                                                                                                                                      |
-| `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION`    | `allow`                                                                                  | What `rproxy` does with a request when `waf` gives no answer in time, and while the circuit breaker for asks to `waf` is open: `allow` passes it to the app, `deny` answers `503`.                                                                              |
+| `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION`    | `allow`                                                                                  | What `rproxy` does with a request when `waf` cannot be reached or does not answer in time: `allow` passes it to the app, `deny` answers `503`.                                                                                                                  |
 | `SWW_RPROXY_MAX_REQUEST_SIZE`                     | `100M`                                                                                   | The largest request body, a size or `off`; a larger one is answered `413`.                                                                                                                                                                                      |
 | `SWW_RPROXY_MAX_RESPONSE_SIZE`                    | `1G`                                                                                     | The largest response body, a size or `off`. The visitor gets `502` in place of a larger one, or it is cut off if it has already started.                                                                                                                        |
 | `SWW_RPROXY_MAX_REQUEST_TIME_MS`                  | `60000`                                                                                  | Two time limits, each this long, in milliseconds or `off`: one for the visitor to send its request line and headers, then one for the whole request to reach the app.                                                                                           |

SPEC.md

@@ -2584,10 +2584,11 @@ request and ban notes name the site by its host.
 
 `sww rproxy` is the reverse proxy in front of one app. It asks `waf` about each
 request, and passes on what `waf` allows. It writes nothing to disk. The only
-thing it keeps between requests is its circuit breaker for asks to `waf`.
-`SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION` decides what is done with a
-request when `waf` gives no answer in time, and while the circuit breaker is
-open. Its default, `allow`, keeps the site answering.
+thing it keeps between requests is its circuit breaker for asks to `waf`. When
+`waf` cannot be connected to, does not answer at all, or does not answer within
+`SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`,
+`SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION` decides. Its default, `allow`,
+keeps the site answering.
 
 `rproxy` reads only its `SWW_RPROXY_` settings, which `docs/settings.md` lists.
 One of them is required: `SWW_RPROXY_WAF_BACKEND`, `waf`'s URL. It has no
@@ -2605,8 +2606,7 @@ only. The image runs it by default (see "Deployment").
 4. It refuses a request with a method it does not pass on, or one it cannot put
    to `waf` as the visitor sent it (see "Requests `rproxy` refuses itself").
 5. It reads up to the first 64 KiB of the body into memory.
-6. It sends `waf` the question (see "The question"), unless the circuit breaker
-   keeps it from asking (see "The circuit breaker"). It speaks HTTP/1.1 to
+6. It sends `waf` the question (see "The question"). It speaks HTTP/1.1 to
    `waf`, whatever `waf` offers. Go's HTTP/2 client would refuse to send a
    visitor's `Upgrade` header, and most `Connection` headers. The question never
    carries the visitor's `Trailer`.
@@ -2694,10 +2694,10 @@ decides, without asking `waf`, while the circuit breaker is open.
 Either way `rproxy` writes a process warning, its log line has
 `waf_backend_no_answer`, and it sends no report.
 
-`waf` taking longer than `SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS` to decide a request
-is a bug in `waf`. Such a request gets
-`SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION`, like any request while `waf` is
-overloaded. With `deny`, it gets `503` instead of reaching the app.
+A visitor can make `waf` slow. A request that keeps `waf` busy past
+`SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`, like any request while `waf` is overloaded,
+gets `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION`. With `deny`, such a request
+gets `503` instead of reaching the app.
 
 A path under `/_sww/` that `allow` would pass on is answered `404` instead, so
 that the app never sees that prefix.
@@ -2715,10 +2715,10 @@ status `0` and no `disposition`.
 ### The circuit breaker
 
 `rproxy` stops asking `waf` for a while when `waf` keeps failing to answer. An
-ask fails when `waf` gives no answer in time (see "Without an answer from
-`waf`"), or an answer `rproxy` cannot pass on. Any other answer in time
-succeeds, whatever it decides. A visitor that goes away while `waf` is being
-asked counts as neither.
+ask fails when `waf` cannot be connected to, does not answer at all, or does not
+answer within `SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`. Any answer in time succeeds,
+whatever it decides, and so does an answer `rproxy` cannot pass on. A visitor
+that goes away while `waf` is being asked counts as neither.
 
 The breaker works like this:
 
@@ -2728,8 +2728,11 @@ The breaker works like this:
   It gets the same process warning and `waf_backend_no_answer` as a request
   whose ask failed.
 - While it is open, one request a second still asks `waf`.
-- Each ask that succeeds clears the failures counted so far, and closes the
-  breaker if it is open.
+- The first ask that succeeds closes it, and the failures before it no longer
+  count.
+
+A request that `waf` cannot decide within `SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`
+counts as a failure too. Such a request is a bug in `waf`.
 
 The breaker lives in memory, and a restart of `rproxy` closes it. It has no
 settings.

docs/request-log.md

@@ -238,8 +238,7 @@ meanings where they differ:
 - `disposition`: what was done with the request: `allow`, `deny` or `close`. It
   is `waf`'s answer, or the value of
   `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION`. It is left out when:
-    - `waf` was not asked and `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION` did
-      not apply, as for the health check;
+    - `waf` was not asked, as for the health check;
     - the visitor went away while `waf` was being asked;
     - `waf`'s answer had no valid `X-Sww-Disposition`;
     - `rproxy` could not pass on `waf`'s answer, and answered `502`.

docs/settings.md

@@ -453,9 +453,11 @@ start, and an invalid value stops the start. Any can be given as a file, as a
   for `waf`'s answer, to a question and to a report. A time in milliseconds;
   never `off`.
 - `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION` (default `allow`): what is done
-  with a request when `waf` gives no answer in time, and while the circuit
-  breaker for asks to `waf` is open. `allow` passes it to the app, and `deny`
-  answers `503`. It does not apply to an answer `waf` gives, such as an error.
+  with a request when `waf` cannot be connected to, does not answer at all, or
+  does not answer within `SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`, and while the
+  circuit breaker for asks to `waf` is open. `allow` passes it to the app, and
+  `deny` answers `503`. It does not apply to an answer `waf` gives, such as an
+  error.
 - `SWW_RPROXY_MAX_REQUEST_SIZE` (default `100M`): the largest request body. A
   size or `off`.
 - `SWW_RPROXY_MAX_RESPONSE_SIZE` (default `1G`): the largest response body. A

internal/rproxy/breaker.go

@@ -21,9 +21,8 @@ var errBreakerOpen = errors.New(
 
 // breaker is the circuit breaker for asks to waf. It opens when
 // breakerFailures asks fail within breakerWindow. An ask fails when it gets no
-// answer in time, or an answer rproxy cannot pass on. While it is open, at
-// most one request each breakerAskInterval asks waf. Any usable answer closes
-// it, whatever it decides, and forgets the failures before it.
+// answer in time. While it is open, at most one request each breakerAskInterval
+// asks waf. The first answer closes it, whatever it decides.
 type breaker struct {
 	mu sync.Mutex
 	// failures holds the times of the latest failed asks, oldest first, at most
@@ -53,14 +52,16 @@ func (b *breaker) mayAsk(now time.Time) bool {
 	return true
 }
 
-// noteAnswer notes that an ask got an answer rproxy can use. It closes the
-// breaker and forgets the failures before it.
+// noteAnswer notes that an ask got an answer in time. It closes the breaker,
+// and forgets the failures before it.
 func (b *breaker) noteAnswer() {
 	b.mu.Lock()
 	defer b.mu.Unlock()
 
-	b.open = false
-	b.failures = nil
+	if b.open {
+		b.open = false
+		b.failures = nil
+	}
 }
 
 // noteFailure notes that an ask that ended at now got no answer in time, and

internal/rproxy/breaker_test.go

@@ -63,17 +63,17 @@ func TestFiveFailedAsksOverMoreThanFiveSecondsLeaveTheBreakerClosed(
 	}
 }
 
-func TestAnAnswerBetweenFailedAsksKeepsTheBreakerClosed(t *testing.T) {
+func TestAnAnswerBeforeTheBreakerOpensDoesNotForgetFailures(t *testing.T) {
 	t.Parallel()
 
 	now := time.Now()
 	b := &rproxy.Breaker{}
-	fail(b, now, 4, 100*time.Millisecond)
+	fail(b, now, 4, time.Millisecond)
 	b.NoteAnswer()
-	fail(b, now.Add(500*time.Millisecond), 4, 100*time.Millisecond)
+	b.NoteFailure(now.Add(time.Second))
 
-	if !b.MayAsk(now.Add(900 * time.Millisecond)) {
-		t.Error("a request may not ask, want it to")
+	if b.MayAsk(now.Add(time.Second)) {
+		t.Error("a request may ask, want it not to")
 	}
 }
 

internal/rproxy/export_test.go

@@ -12,7 +12,7 @@ func (b *Breaker) MayAsk(now time.Time) bool {
 	return b.b.mayAsk(now)
 }
 
-// NoteAnswer notes that an ask got an answer rproxy can use.
+// NoteAnswer notes that an ask got an answer in time.
 func (b *Breaker) NoteAnswer() {
 	b.b.noteAnswer()
 }

internal/rproxy/rproxy_test.go

@@ -1452,83 +1452,6 @@ func TestFiveFailedAsksKeepTheNextRequestFromAskingWAF(t *testing.T) {
 	}
 }
 
-func TestVisitorsThatGoAwayWhileWAFIsAskedLeaveTheBreakerClosed(
-	t *testing.T,
-) {
-	t.Parallel()
-
-	var answering atomic.Bool
-
-	standIn := startWAF(t, func(w http.ResponseWriter, r *http.Request) {
-		if answering.Load() {
-			allow(w, r)
-
-			return
-		}
-
-		<-r.Context().Done()
-	})
-	app := startApp(t, greet)
-	addr, out := startRProxy(t, standIn.URL, app.URL, map[string]string{
-		wafBackendTimeout: "60000",
-	})
-
-	// Five of these would open the breaker if they counted as failures.
-	for range 5 {
-		conn := dial(t, addr)
-		send(t, conn, "GET / HTTP/1.1\r\nHost: site.example\r\n\r\n")
-		id := standIn.question(t).header.Get(requestIDHeader)
-
-		_ = conn.Close()
-
-		// rproxy writes the request's log line once it is done with the ask.
-		out.waitFor(t, id)
-	}
-
-	answering.Store(true)
-	wantGreeting(t, get(t, addr, "/"))
-	standIn.question(t)
-}
-
-func TestAnswersThatCannotBePassedOnOpenTheBreaker(t *testing.T) {
-	t.Parallel()
-
-	var answering atomic.Bool
-
-	tooLarge := overOneMiB(dispositionDeny)
-	standIn := startWAF(t, func(w http.ResponseWriter, r *http.Request) {
-		if answering.Load() {
-			allow(w, r)
-
-			return
-		}
-
-		tooLarge(w, r)
-	})
-	app := startApp(t, greet)
-	addr, out := startRProxy(t, standIn.URL, app.URL, map[string]string{
-		wafBackendTimeout: "60000",
-	})
-
-	for range 5 {
-		if got := get(t, addr, "/"); got.status != http.StatusBadGateway {
-			t.Errorf("answered %d, want 502", got.status)
-		}
-
-		standIn.question(t)
-	}
-
-	answering.Store(true)
-	wantGreeting(t, get(t, addr, "/"))
-	out.waitFor(t, "the circuit breaker is open")
-
-	select {
-	case <-standIn.questions:
-		t.Error("waf was asked, want it not to be")
-	case <-time.After(10 * pollInterval):
-	}
-}
-
 func TestAPathUnderOwnPrefixNeverReachesTheApp(t *testing.T) {
 	t.Parallel()
 

internal/rproxy/waf.go

@@ -90,7 +90,7 @@ func (rq *request) handleNoUsableAnswer(ctx context.Context, err error) {
 
 // askUnlessBreakerOpen asks waf, unless the circuit breaker is open and it is
 // not yet time for a request to ask. It then tells the breaker whether waf
-// answered in time. An answer rproxy cannot pass on counts as a failure. A
+// answered in time. An answer rproxy cannot pass on still came in time. A
 // visitor that goes away tells the breaker nothing. ctx is the request's own
 // context.
 func (rq *request) askUnlessBreakerOpen(
@@ -104,7 +104,7 @@ func (rq *request) askUnlessBreakerOpen(
 	answer, err := rq.ask(ctx)
 
 	switch {
-	case err == nil:
+	case err == nil, errors.Is(err, errCannotPassOn):
 		b.noteAnswer()
 	case ctx.Err() == nil:
 		b.noteFailure(time.Now())