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

@@ -26,7 +26,7 @@ shipped in one image, with two commands that do this together:
 - `sww rproxy` is a small reverse proxy in front of one app. It sits behind a
   TLS-terminating proxy, such as traefik, nginx or Caddy. It asks `waf` about
   each request, passes the allowed ones to the app, and passes the app's answers
-  back. It keeps nothing between requests and writes nothing to disk.
+  back. It writes nothing to disk.
 - `sww waf` decides. It runs the checks and keeps the bans, the counters and
   each client's history. One `waf` serves many sites: a client banned through
   one site is refused on all of them, and its requests on all of them count

SPEC.md

@@ -2583,9 +2583,10 @@ request and ban notes name the site by its host.
 ## `rproxy`
 
 `sww rproxy` is the reverse proxy in front of one app. It asks `waf` about each
-request, and passes on what `waf` allows. It keeps nothing between requests and
+request, and passes on what `waf` allows. It writes nothing to disk. The only
-writes nothing to disk. When `waf` cannot be connected to, does not answer at
+thing it keeps between requests is its circuit breaker for asks to `waf`. When
-all, or does not answer within `SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`,
+`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.
 
@@ -2679,14 +2680,15 @@ log line has status `0`.
 ### Without an answer from `waf`
 
 `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION` decides what is done with the
-request only when `waf`:
+request when `waf`:
 
 - cannot be connected to;
 - does not answer at all;
 - does not answer within `SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`, which covers
   connecting, sending the question and reading the whole answer.
 
-An answer whose body breaks off counts as no answer at all.
+An answer whose body breaks off counts as no answer at all. The setting also
+decides, without asking `waf`, while the circuit breaker is open.
 
 `allow`, the default, passes the request to the app. `deny` answers `503`.
 Either way `rproxy` writes a process warning, its log line has
@@ -2710,6 +2712,31 @@ A visitor that goes away while `waf` is being asked is no failure of `waf`.
 `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION` does not apply. Its log line has
 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` 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:
+
+- It opens when 5 asks fail within 5 seconds. Fewer failures never open it.
+- While it is open, a request gets
+  `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION` at once, without asking `waf`.
+  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`.
+- 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.
+
 ### Passing a request to the app
 
 `rproxy` sends the app at `SWW_RPROXY_UPSTREAM_URL` the visitor's request: the
@@ -2983,8 +3010,8 @@ host directory, keeps them across deploys. A host directory mounted there needs
 no change of owner, and files an earlier owner left in it can be read and
 replaced. The volume holds a few tens of MiB at most with the defaults, and
 needs no backup beyond the host's own. The image declares no volume, since every
-app image built on it would inherit it. `rproxy` keeps nothing, and needs no
+app image built on it would inherit it. `rproxy` writes nothing to disk, and
-volume.
+needs no volume.
 
 `waf` keeps its cache files in `SWW_WAF_CACHE_DIR`, `/var/cache/sww` by default,
 which the `run` script makes. The cache directory needs no volume and can be

docs/settings.md

@@ -454,9 +454,10 @@ start, and an invalid value stops the start. Any can be given as a file, as a
   never `off`.
 - `SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION` (default `allow`): what is done
   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`. `allow` passes it
+  does not answer within `SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`, and while the
-  to the app, and `deny` answers `503`. It does not apply to an answer `waf`
+  circuit breaker for asks to `waf` is open. `allow` passes it to the app, and
-  gives, such as an error.
+  `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

@@ -0,0 +1,83 @@
+package rproxy
+
+import (
+	"errors"
+	"sync"
+	"time"
+)
+
+// What opens the circuit breaker, and how often a request asks waf while it is
+// open.
+const (
+	breakerFailures    = 5
+	breakerWindow      = 5 * time.Second
+	breakerAskInterval = time.Second
+)
+
+// errBreakerOpen is why a request did not ask waf.
+var errBreakerOpen = errors.New(
+	"waf is not asked while the circuit breaker is open",
+)
+
+// 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. 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
+	// breakerFailures of them.
+	failures []time.Time
+	open     bool
+	// lastAsk is when a request last asked waf while the breaker was open.
+	lastAsk time.Time
+}
+
+// mayAsk reports whether a request may ask waf at now. While the breaker is
+// open, it says yes once each breakerAskInterval.
+func (b *breaker) mayAsk(now time.Time) bool {
+	b.mu.Lock()
+	defer b.mu.Unlock()
+
+	if !b.open {
+		return true
+	}
+
+	if now.Sub(b.lastAsk) < breakerAskInterval {
+		return false
+	}
+
+	b.lastAsk = now
+
+	return true
+}
+
+// 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()
+
+	if b.open {
+		b.open = false
+		b.failures = nil
+	}
+}
+
+// noteFailure notes that an ask that ended at now got no answer in time, and
+// opens the breaker if breakerFailures asks have failed within breakerWindow.
+func (b *breaker) noteFailure(now time.Time) {
+	b.mu.Lock()
+	defer b.mu.Unlock()
+
+	b.failures = append(b.failures, now)
+	if len(b.failures) > breakerFailures {
+		b.failures = b.failures[1:]
+	}
+
+	if !b.open && len(b.failures) == breakerFailures &&
+		now.Sub(b.failures[0]) <= breakerWindow {
+		b.open = true
+		b.lastAsk = now
+	}
+}

internal/rproxy/breaker_test.go

@@ -0,0 +1,142 @@
+package rproxy_test
+
+import (
+	"testing"
+	"time"
+
+	"sneak.berlin/go/smallwebwaf/internal/rproxy"
+)
+
+// The breaker tests give the breaker each time themselves, counted from
+// time.Now(), and never wait.
+
+// fail notes count failed asks on b, one each step from at.
+func fail(b *rproxy.Breaker, at time.Time, count int, step time.Duration) {
+	for i := range count {
+		b.NoteFailure(at.Add(time.Duration(i) * step))
+	}
+}
+
+// openBreaker returns a breaker opened at now by five failed asks, one a
+// second.
+func openBreaker(now time.Time) *rproxy.Breaker {
+	b := &rproxy.Breaker{}
+	fail(b, now.Add(-4*time.Second), 5, time.Second)
+
+	return b
+}
+
+func TestFourFailedAsksWithinFiveSecondsLeaveTheBreakerClosed(t *testing.T) {
+	t.Parallel()
+
+	now := time.Now()
+	b := &rproxy.Breaker{}
+	fail(b, now, 4, time.Second)
+
+	if !b.MayAsk(now.Add(3 * time.Second)) {
+		t.Error("a request may not ask, want it to")
+	}
+}
+
+func TestFiveFailedAsksWithinFiveSecondsOpenTheBreaker(t *testing.T) {
+	t.Parallel()
+
+	now := time.Now()
+	b := openBreaker(now)
+
+	if b.MayAsk(now) {
+		t.Error("a request may ask, want it not to")
+	}
+}
+
+func TestFiveFailedAsksOverMoreThanFiveSecondsLeaveTheBreakerClosed(
+	t *testing.T,
+) {
+	t.Parallel()
+
+	now := time.Now()
+	b := &rproxy.Breaker{}
+	fail(b, now, 5, 1300*time.Millisecond)
+
+	if !b.MayAsk(now.Add(6 * time.Second)) {
+		t.Error("a request may not ask, want it to")
+	}
+}
+
+func TestAnAnswerBeforeTheBreakerOpensDoesNotForgetFailures(t *testing.T) {
+	t.Parallel()
+
+	now := time.Now()
+	b := &rproxy.Breaker{}
+	fail(b, now, 4, time.Millisecond)
+	b.NoteAnswer()
+	b.NoteFailure(now.Add(time.Second))
+
+	if b.MayAsk(now.Add(time.Second)) {
+		t.Error("a request may ask, want it not to")
+	}
+}
+
+func TestAnOpenBreakerLetsOneRequestAskEachSecond(t *testing.T) {
+	t.Parallel()
+
+	now := time.Now()
+	b := openBreaker(now)
+
+	for _, tc := range []struct {
+		after time.Duration
+		want  bool
+	}{
+		{999 * time.Millisecond, false},
+		{time.Second, true},
+		{time.Second, false},
+		{1500 * time.Millisecond, false},
+		{2 * time.Second, true},
+	} {
+		got := b.MayAsk(now.Add(tc.after))
+		if got != tc.want {
+			t.Errorf("may ask %v after it opened: %v, want %v",
+				tc.after, got, tc.want)
+		}
+	}
+}
+
+func TestAFailedAskKeepsTheBreakerOpen(t *testing.T) {
+	t.Parallel()
+
+	opened := time.Now()
+	b := openBreaker(opened)
+	now := opened.Add(time.Second)
+	b.MayAsk(now)
+	b.NoteFailure(now)
+
+	if b.MayAsk(now.Add(999 * time.Millisecond)) {
+		t.Error("a request may ask, want it not to")
+	}
+
+	if !b.MayAsk(now.Add(time.Second)) {
+		t.Error("a request may not ask a second later, want it to")
+	}
+}
+
+func TestOneAnswerClosesTheBreaker(t *testing.T) {
+	t.Parallel()
+
+	opened := time.Now()
+	b := openBreaker(opened)
+	now := opened.Add(time.Second)
+	b.MayAsk(now)
+	b.NoteAnswer()
+
+	if !b.MayAsk(now) {
+		t.Error("a request may not ask, want it to")
+	}
+
+	// The failures before the answer no longer count, so one more does not open
+	// the breaker again.
+	b.NoteFailure(now)
+
+	if !b.MayAsk(now) {
+		t.Error("a request may not ask after one failure, want it to")
+	}
+}

internal/rproxy/export_test.go

@@ -0,0 +1,23 @@
+package rproxy
+
+import "time"
+
+// Breaker is the circuit breaker, for tests that give it the time.
+type Breaker struct {
+	b breaker
+}
+
+// MayAsk reports whether a request may ask waf at now.
+func (b *Breaker) MayAsk(now time.Time) bool {
+	return b.b.mayAsk(now)
+}
+
+// NoteAnswer notes that an ask got an answer in time.
+func (b *Breaker) NoteAnswer() {
+	b.b.noteAnswer()
+}
+
+// NoteFailure notes that an ask that ended at now got no answer in time.
+func (b *Breaker) NoteFailure(now time.Time) {
+	b.b.noteFailure(now)
+}

internal/rproxy/rproxy.go

@@ -4,10 +4,11 @@
 // waf goes to the visitor as waf gave it.
 // SWW_RPROXY_WAF_BACKEND_NO_ANSWER_DISPOSITION decides only when waf cannot
 // be connected to, does not answer at all, or does not answer within
-// SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS. rproxy itself refuses a request with a
+// SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS, or while the circuit breaker for asks to
-// method it does not pass on, or one it cannot put to waf as the visitor
+// waf is open. rproxy itself refuses a request with a method it does not pass
-// sent it. It keeps nothing between requests and writes nothing to disk. "rproxy" in
+// on, or one it cannot put to waf as the visitor sent it. It keeps nothing
-// SPEC.md says what it does.
+// between requests but the circuit breaker, and writes nothing to disk.
+// "rproxy" in SPEC.md says what it does.
 package rproxy
 
 import (
@@ -132,6 +133,8 @@ type handler struct {
 	wafTransport http.RoundTripper
 	// reportURL is where the reports go.
 	reportURL string
+	// breaker is the circuit breaker for asks to waf.
+	breaker breaker
 	// reports waits for the reports being sent. reportsMu guards starting one
 	// against reportsStopped, which is set once nothing is to wait for another.
 	reports        sync.WaitGroup
@@ -196,7 +199,7 @@ func (h *handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	answer, err := rq.ask(r.Context())
+	answer, err := rq.askUnlessBreakerOpen(r.Context())
 	if err != nil {
 		rq.handleNoUsableAnswer(r.Context(), err)
 

internal/rproxy/rproxy_test.go

@@ -15,6 +15,7 @@ import (
 	"strconv"
 	"strings"
 	"sync"
+	"sync/atomic"
 	"testing"
 	"time"
 
@@ -1395,6 +1396,62 @@ func TestSendsNoReportWithoutAnAnswer(t *testing.T) {
 	standIn.wantNoReport(t)
 }
 
+func TestFiveFailedAsksKeepTheNextRequestFromAskingWAF(t *testing.T) {
+	t.Parallel()
+
+	for name, failure := range map[string]http.HandlerFunc{
+		"no answer at all": func(http.ResponseWriter, *http.Request) {
+			panic(http.ErrAbortHandler)
+		},
+		"a slow answer": func(_ http.ResponseWriter, r *http.Request) {
+			<-r.Context().Done()
+		},
+	} {
+		t.Run(name, func(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
+					}
+
+					failure(w, r)
+				},
+			)
+			app := startApp(t, greet)
+			addr, out := startRProxy(
+				t,
+				standIn.URL,
+				app.URL,
+				map[string]string{
+					wafBackendTimeout: "200",
+				},
+			)
+
+			for range 5 {
+				wantGreeting(t, get(t, addr, "/"))
+				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

@@ -10,6 +10,7 @@ import (
 	"maps"
 	"net/http"
 	"strings"
+	"time"
 
 	"sneak.berlin/go/smallwebwaf/internal/waf"
 )
@@ -67,7 +68,8 @@ func (rq *request) handleNoUsableAnswer(ctx context.Context, err error) {
 		rq.answer(http.StatusBadGateway)
 	default:
 		// waf cannot be connected to, does not answer at all, or does not answer
-		// within SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS. A request that keeps waf
+		// within SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS; or the circuit breaker
+		// kept the request from asking. 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
 		// here. deny closes this, at the cost of answering 503 whenever waf is
@@ -86,6 +88,31 @@ 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 still came in time. A
+// visitor that goes away tells the breaker nothing. ctx is the request's own
+// context.
+func (rq *request) askUnlessBreakerOpen(
+	ctx context.Context,
+) (*wafAnswer, error) {
+	b := &rq.h.breaker
+	if !b.mayAsk(time.Now()) {
+		return nil, errBreakerOpen
+	}
+
+	answer, err := rq.ask(ctx)
+
+	switch {
+	case err == nil, errors.Is(err, errCannotPassOn):
+		b.noteAnswer()
+	case ctx.Err() == nil:
+		b.noteFailure(time.Now())
+	}
+
+	return answer, err
+}
+
 // ask sends waf the question, and returns its answer, which must have come
 // whole within SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS. It ends when ctx does, as
 // when the visitor goes away.

internal/sww/rproxy_test.go

@@ -260,7 +260,17 @@ func TestTheSiteAnswersWhileWAFIsStoppedAndStartedAgain(t *testing.T) {
 		stop()
 	}()
 
-	wantStatus(t, site+"/", placed, http.StatusForbidden)
+	// The visitor's asks have opened rproxy's circuit breaker, which lets one
+	// request a second ask until one is answered.
+	deadline := time.Now().Add(waitLimit)
+	for statusFrom(t, site+"/", placed) != http.StatusForbidden {
+		if time.Now().After(deadline) {
+			t.Fatalf("request from %s: never answered %d", placed,
+				http.StatusForbidden)
+		}
+
+		time.Sleep(pollInterval)
+	}
 
 	close(visitorStop)
 	<-visitorDone