diff --git a/README.md b/README.md index 3b36dc0..6b676d7 100644 --- a/README.md +++ b/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 diff --git a/SPEC.md b/SPEC.md index b062148..13d33ae 100644 --- a/SPEC.md +++ b/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 -writes nothing to disk. When `waf` cannot be connected to, does not answer at -all, or does not answer within `SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS`, +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`. 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. @@ -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 -volume. +app image built on it would inherit it. `rproxy` writes nothing to disk, and +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 diff --git a/docs/settings.md b/docs/settings.md index 46b30fb..2b429fa 100644 --- a/docs/settings.md +++ b/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 - to the app, and `deny` answers `503`. It does not apply to an answer `waf` - gives, such as an error. + 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 diff --git a/internal/rproxy/breaker.go b/internal/rproxy/breaker.go new file mode 100644 index 0000000..6773bb9 --- /dev/null +++ b/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 + } +} diff --git a/internal/rproxy/breaker_test.go b/internal/rproxy/breaker_test.go new file mode 100644 index 0000000..564c3ed --- /dev/null +++ b/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") + } +} diff --git a/internal/rproxy/export_test.go b/internal/rproxy/export_test.go new file mode 100644 index 0000000..5f7d655 --- /dev/null +++ b/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) +} diff --git a/internal/rproxy/rproxy.go b/internal/rproxy/rproxy.go index de545b6..489c4c6 100644 --- a/internal/rproxy/rproxy.go +++ b/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 -// method it does not pass on, or one it cannot put to waf as the visitor -// sent it. It keeps nothing between requests and writes nothing to disk. "rproxy" in -// SPEC.md says what it does. +// SWW_RPROXY_WAF_BACKEND_TIMEOUT_MS, or while the circuit breaker for asks to +// waf is open. rproxy itself refuses a request with a method it does not pass +// on, or one it cannot put to waf as the visitor sent it. It keeps nothing +// 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) diff --git a/internal/rproxy/rproxy_test.go b/internal/rproxy/rproxy_test.go index b68f733..7904ee6 100644 --- a/internal/rproxy/rproxy_test.go +++ b/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() diff --git a/internal/rproxy/waf.go b/internal/rproxy/waf.go index e5f298a..1e7417f 100644 --- a/internal/rproxy/waf.go +++ b/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. diff --git a/internal/sww/rproxy_test.go b/internal/sww/rproxy_test.go index 934d92f..267704e 100644 --- a/internal/sww/rproxy_test.go +++ b/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