Rule files, and bans for a clear sign of attack (closes #24)

Every *.rules file in SWWAF_RULES_DIR is read at start and on each
change, and each request is checked against the rules after the rate
limits: log notes a match, block refuses with 403, ban refuses and bans
the netblock for SWWAF_ATTACK_BAN_DURATION, made permanent by its next
request or clear sign of attack. path, query and uri are matched as the
request line sent them. bans.json gains each ban's cause, and ban notes
count earlier bans by cause. The image ships 00-default.rules.

Judgement call: a header sent twice is matched with its values joined
by ", ".
Judgement call: SWWAF_MAX_BAN_DURATION does not cap a ban for an attack.
Not in this unit: offences for rule matches, with the error burst.

Model: opus-5-5

internal/proxy/bans.go

@@ -6,6 +6,7 @@ import (
 
 	"sneak.berlin/go/smallwebwaf/internal/bans"
 	"sneak.berlin/go/smallwebwaf/internal/requestlog"
+	"sneak.berlin/go/smallwebwaf/internal/rules"
 )
 
 // banResponse is a refusal answered with SWWAF_BAN_RESPONSE, and logged
@@ -51,20 +52,12 @@ func (rq *request) limitBroken(now time.Time) bool {
 
 	netblock := rq.netblock()
 	ban := rq.h.ledger.BanForLimit(netblock, now, bans.Notes{
-		Country: rq.line.Country,
-		Limit:   hit.Limit,
-		Window:  hit.Window,
-		Count:   hit.Requests,
-		Request: bans.Request{
-			Time:      now,
-			Method:    rq.in.Method,
-			Host:      rq.in.Host,
-			Path:      rq.in.URL.RequestURI(),
-			Status:    rq.h.config.BanResponse,
-			UserAgent: rq.in.UserAgent(),
-		},
-		// The histories count this request only once it has ended.
-		Requests: rq.h.limiter.Requests(netblock) + 1,
+		Country:  rq.line.Country,
+		Limit:    hit.Limit,
+		Window:   hit.Window,
+		Count:    hit.Requests,
+		Request:  rq.noted(now),
+		Requests: rq.netblockRequests(netblock),
 	})
 	rq.h.limiter.Reset(group)
 	rq.line.BanExpires = banExpires(ban)
@@ -72,6 +65,40 @@ func (rq *request) limitBroken(now time.Time) bool {
 	return true
 }
 
+// banForAttack bans the client's netblock at now for a clear sign of
+// attack, the match of rule, a ban rule.
+func (rq *request) banForAttack(now time.Time, rule rules.Rule) {
+	netblock := rq.netblock()
+	ban := rq.h.ledger.BanForAttack(netblock, now, bans.Notes{
+		Country:  rq.line.Country,
+		RuleID:   rule.ID,
+		Target:   rule.Target,
+		Request:  rq.noted(now),
+		Requests: rq.netblockRequests(netblock),
+	})
+	rq.line.BanExpires = banExpires(ban)
+}
+
+// noted is the request, refused at now with SWWAF_BAN_RESPONSE, as the
+// notes of the ban it makes keep it.
+func (rq *request) noted(now time.Time) bans.Request {
+	return bans.Request{
+		Time:      now,
+		Method:    rq.in.Method,
+		Host:      rq.in.Host,
+		Path:      rq.in.URL.RequestURI(),
+		Status:    rq.h.config.BanResponse,
+		UserAgent: rq.in.UserAgent(),
+	}
+}
+
+// netblockRequests is how many requests netblock has sent since it was
+// first seen, this one included: the histories count it only once it has
+// ended.
+func (rq *request) netblockRequests(netblock netip.Prefix) int64 {
+	return rq.h.limiter.Requests(netblock) + 1
+}
+
 // netblock is the netblock a ban on the client covers: its IPv4 address,
 // widened to SWWAF_BAN_SCOPE_V4_PREFIX, or the IPv6 group clientGroup
 // counts it in.

internal/proxy/bans_test.go

@@ -278,6 +278,7 @@ func TestBanNotes(t *testing.T) {
 		Netblock: netblock,
 		Start:    start,
 		Expires:  start.Add(time.Hour),
+		Cause:    bans.CauseLimit,
 		Notes: bans.Notes{
 			Country: "DE",
 			Limit:   1,
@@ -295,7 +296,7 @@ func TestBanNotes(t *testing.T) {
 			// refused under the ban.
 			Requests:    4,
 			Refused:     2,
-			EarlierBans: 0,
+			EarlierBans: bans.EarlierBans{},
 		},
 	}
 
@@ -312,8 +313,8 @@ func TestBanNotes(t *testing.T) {
 	s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited)
 
 	got = ledger.Bans(netblock)
-	if len(got) != 2 || got[1].Notes.EarlierBans != 1 {
-		t.Errorf("bans %+v, want two, the second with one earlier ban", got)
+	if len(got) != 2 || got[1].Notes.EarlierBans != (bans.EarlierBans{Limit: 1}) {
+		t.Errorf("bans %+v, want two, the second with one earlier ban for a limit", got)
 	}
 }
 

internal/proxy/passthrough_test.go

@@ -6,6 +6,7 @@ import (
 	"errors"
 	"io"
 	"net/http"
+	"reflect"
 	"slices"
 	"strings"
 	"sync/atomic"
@@ -128,7 +129,7 @@ func wantRequestFields(t *testing.T, line logLine, host string, sent, received i
 		Action: requestlog.ActionForward, DurationTotal: line.DurationTotal,
 		DurationUpstreamTotal: line.DurationUpstreamTotal,
 	}
-	if line.Line != want {
+	if !reflect.DeepEqual(line.Line, want) {
 		t.Errorf("log line\n%+v\nwant\n%+v", line.Line, want)
 	}
 

internal/proxy/proxy.go

@@ -17,6 +17,7 @@ import (
 	"sneak.berlin/go/smallwebwaf/internal/metrics"
 	"sneak.berlin/go/smallwebwaf/internal/ratelimit"
 	"sneak.berlin/go/smallwebwaf/internal/requestlog"
+	"sneak.berlin/go/smallwebwaf/internal/rules"
 )
 
 // How smallwebwaf keeps connections to the app open between requests.
@@ -51,6 +52,9 @@ type Params struct {
 	// limits, bans are made and run out, and GeoJS's answers are kept,
 	// normally time.Now in UTC, the time the state files give.
 	Now func() time.Time
+	// Rules are the rule files' rules, which each request is checked
+	// against.
+	Rules *rules.Files
 }
 
 // Server is the server smallwebwaf runs, with the parts of the proxy
@@ -90,6 +94,7 @@ func New(params Params) *Server {
 			LimitBanDuration:     params.Config.LimitBanDuration,
 			LimitBanRepeatWindow: params.Config.LimitBanRepeatWindow,
 			MaxBanDuration:       params.Config.MaxBanDuration,
+			AttackBanDuration:    params.Config.AttackBanDuration,
 			MaxBans:              params.Config.MaxBans,
 		}),
 		geojs: lookup.New(lookup.Params{
@@ -98,8 +103,10 @@ func New(params Params) *Server {
 			ProcessLog: params.ProcessLog,
 			Metrics:    m,
 		}),
+		rules: params.Rules,
 	}
 	m.AddBansAndClients(h.ledger, h.limiter, params.Now)
+	m.AddRules(params.Rules)
 
 	return &Server{
 		Server: &http.Server{
@@ -134,6 +141,7 @@ type handler struct {
 	limiter    *ratelimit.Limiter
 	ledger     *bans.Ledger
 	geojs      *lookup.GeoJS
+	rules      *rules.Files
 }
 
 // newTransport returns what carries requests to the app. It never goes

internal/proxy/proxy_test.go

@@ -17,6 +17,7 @@ import (
 	"sneak.berlin/go/smallwebwaf/internal/config"
 	"sneak.berlin/go/smallwebwaf/internal/proxy"
 	"sneak.berlin/go/smallwebwaf/internal/requestlog"
+	"sneak.berlin/go/smallwebwaf/internal/rules"
 )
 
 const (
@@ -67,6 +68,8 @@ const (
 	maxBanDuration          = "SWWAF_MAX_BAN_DURATION"
 	maxBans                 = "SWWAF_MAX_BANS"
 	banScopeV4Prefix        = "SWWAF_BAN_SCOPE_V4_PREFIX"
+	attackBanDuration       = "SWWAF_ATTACK_BAN_DURATION"
+	rulesDir                = "SWWAF_RULES_DIR"
 )
 
 // output collects what smallwebwaf writes on stdout.
@@ -197,14 +200,15 @@ func startProxyWithGeoJS(
 }
 
 // startProxyWithClock is startProxyWithGeoJS with requests counted and
-// bans made by the time now tells, and returns the server as well.
+// bans made by the time now tells, and returns the server as well. Unless
+// env sets SWWAF_RULES_DIR, it is an empty directory, of no rules.
 func startProxyWithClock(
 	t *testing.T, appURL, geojsURL string, now func() time.Time,
 	env map[string]string,
 ) (string, *output, *proxy.Server) {
 	t.Helper()
 
-	settings := map[string]string{"SWWAF_UPSTREAM_URL": appURL}
+	settings := map[string]string{"SWWAF_UPSTREAM_URL": appURL, rulesDir: t.TempDir()}
 	maps.Copy(settings, env)
 
 	cfg, err := config.FromEnvironment(func(name string) (string, bool) {
@@ -217,12 +221,22 @@ func startProxyWithClock(
 	}
 
 	out := &output{}
+	processLog := requestlog.NewProcessLogger(out)
+
+	ruleFiles, err := rules.Load(rules.Params{
+		Dir: cfg.RulesDir, Enabled: cfg.RulesEnabled, ProcessLog: processLog,
+	})
+	if err != nil {
+		t.Fatalf("rule files: %v", err)
+	}
+
 	server := proxy.New(proxy.Params{
 		Config:     cfg,
 		RequestLog: out,
-		ProcessLog: requestlog.NewProcessLogger(out),
+		ProcessLog: processLog,
 		GeoJSURL:   geojsURL,
 		Now:        now,
+		Rules:      ruleFiles,
 	})
 
 	listener, err := (&net.ListenConfig{}).Listen(t.Context(), "tcp", localhost+":0")

internal/proxy/request.go

@@ -110,20 +110,23 @@ func (h *handler) newRequest(w http.ResponseWriter, r *http.Request) *request {
 // check is the one place where a request can be refused once its client
 // is known, before its body is read or anything reaches the app. It
 // returns nil to let the request through. The checks of checkClient come
-// first, answered with SWWAF_BAN_RESPONSE, and then the size limit, so
-// that a request the rate limits count is counted even when it is
-// refused for its size. In observe mode a request checkClient refuses
-// goes on to the size limit like any other. ctx is the request's own
-// context.
+// first, answered with SWWAF_BAN_RESPONSE, or 403 for a block rule, and
+// then the size limit, so that a request the rate limits count is counted
+// even when it is refused for its size. In observe mode a request
+// checkClient refuses goes on to the size limit like any other. ctx is
+// the request's own context.
 func (rq *request) check(ctx context.Context) *refusal {
 	action := rq.checkClient(ctx)
-	if action != "" {
-		if !rq.h.config.Observe {
-			return rq.banResponse(action)
-		}
 
+	switch {
+	case action == "":
+	case rq.h.config.Observe:
 		// The log line names what enforce mode would have done.
 		rq.line.WouldAction = action
+	case action == requestlog.ActionRuleBlocked:
+		return &refusal{status: http.StatusForbidden, action: action}
+	default:
+		return rq.banResponse(action)
 	}
 
 	maxBytes := rq.h.config.RequestMaxBytes
@@ -145,8 +148,8 @@ func (rq *request) check(ctx context.Context) *refusal {
 // client either refuses is not looked up, and then the country lists; a
 // request any of them refuses is not counted for the rate limits. Then
 // come the rate limits, unless the client is in
-// SWWAF_RATE_LIMIT_EXEMPT_NETS, so that every other request is counted.
-// ctx is the request's own context.
+// SWWAF_RATE_LIMIT_EXEMPT_NETS, so that every other request is counted,
+// and last the rule files. ctx is the request's own context.
 func (rq *request) checkClient(ctx context.Context) string {
 	cfg := rq.h.config
 	if isInside(rq.client, cfg.AllowNets) {
@@ -171,7 +174,7 @@ func (rq *request) checkClient(ctx context.Context) string {
 		return requestlog.ActionRateLimited
 	}
 
-	return ""
+	return rq.checkRules(now)
 }
 
 // forward passes the request to the app and the app's answer back. ctx

internal/proxy/rulefiles_test.go

@@ -0,0 +1,232 @@
+package proxy_test
+
+import (
+	"net/http"
+	"net/netip"
+	"os"
+	"path/filepath"
+	"slices"
+	"testing"
+	"time"
+
+	"sneak.berlin/go/smallwebwaf/internal/bans"
+	"sneak.berlin/go/smallwebwaf/internal/requestlog"
+)
+
+// testRules are the rules most tests here load: a block rule for
+// /blocked and a ban rule for /.env.
+const testRules = `
+blocked  path  block  ^/blocked$
+probe    path  ban    ^/\.env$
+`
+
+func TestEachRuleAction(t *testing.T) {
+	t.Parallel()
+
+	s, clk, server := startWithClock(t, "", map[string]string{
+		rulesDir:    writeRules(t, "noted path log ^/\n"+testRules),
+		banResponse: "429",
+	})
+	start := clk.Now()
+
+	// A log rule notes its match, and lets the request through.
+	line := s.get(client, http.StatusOK, requestlog.ActionForward)
+	wantRuleIDs(t, line, "noted")
+
+	// A block rule refuses with 403, whatever SWWAF_BAN_RESPONSE is, and
+	// bans no one.
+	line = s.request(client, "/blocked", http.StatusForbidden,
+		requestlog.ActionRuleBlocked)
+	wantRuleIDs(t, line, "noted", "blocked")
+	s.get(client, http.StatusOK, requestlog.ActionForward)
+
+	// A ban rule refuses with SWWAF_BAN_RESPONSE, and bans the client for
+	// seven days, the default.
+	line = s.request(client, "/.env", http.StatusTooManyRequests, requestlog.ActionBanned)
+	wantRuleIDs(t, line, "noted", "probe")
+
+	if line.BanExpires != requestlog.FormatTime(start.Add(7*24*time.Hour)) {
+		t.Errorf("log line has ban_expires %q, want seven days on", line.BanExpires)
+	}
+
+	netblock := netip.MustParsePrefix(client + "/32")
+	want := bans.Ban{
+		Netblock: netblock,
+		Start:    start,
+		Expires:  start.Add(7 * 24 * time.Hour),
+		Cause:    bans.CauseAttack,
+		Notes: bans.Notes{
+			RuleID: "probe",
+			Target: "path",
+			Request: bans.Request{
+				Time:      start,
+				Method:    http.MethodGet,
+				Host:      appHost,
+				Path:      "/.env",
+				Status:    http.StatusTooManyRequests,
+				UserAgent: userAgent,
+			},
+			// The four requests up to and including the probe.
+			Requests: 4,
+		},
+	}
+
+	got := server.Ledger.Bans(netblock)
+	if len(got) != 1 || got[0] != want {
+		t.Fatalf("bans\n%+v\nwant\n%+v", got, want)
+	}
+
+	// The next request is refused under the ban, without being checked
+	// against the rules, and makes the ban permanent.
+	clk.advance(time.Hour)
+
+	line = s.get(client, http.StatusTooManyRequests, requestlog.ActionBanned)
+	wantRuleIDs(t, line)
+
+	if line.BanExpires != permanent {
+		t.Errorf("log line has ban_expires %q, want permanent", line.BanExpires)
+	}
+
+	clk.advance(365 * 24 * time.Hour)
+	s.get(client, http.StatusTooManyRequests, requestlog.ActionBanned)
+}
+
+func TestNextClearSignOfAttackAfterABanBansPermanently(t *testing.T) {
+	t.Parallel()
+
+	s, clk, _ := startWithClock(t, "", map[string]string{
+		rulesDir:          writeRules(t, testRules),
+		attackBanDuration: "1h",
+	})
+
+	// The first probe bans for SWWAF_ATTACK_BAN_DURATION.
+	line := s.request(client, "/.env", http.StatusForbidden, requestlog.ActionBanned)
+	if line.BanExpires != requestlog.FormatTime(clk.Now().Add(time.Hour)) {
+		t.Errorf("log line has ban_expires %q, want an hour on", line.BanExpires)
+	}
+
+	// Once that ban has run out without a request, the client is served,
+	// and its next probe bans it for good.
+	clk.advance(time.Hour)
+	s.get(client, http.StatusOK, requestlog.ActionForward)
+
+	line = s.request(client, "/.env", http.StatusForbidden, requestlog.ActionBanned)
+	if line.BanExpires != permanent {
+		t.Errorf("log line has ban_expires %q, want permanent", line.BanExpires)
+	}
+}
+
+func TestRulesComeAfterTheOtherChecks(t *testing.T) {
+	t.Parallel()
+
+	const (
+		allowed = "192.0.2.60" // in SWWAF_ALLOW_NETS
+		exempt  = "192.0.2.50" // in SWWAF_RATE_LIMIT_EXEMPT_NETS
+	)
+
+	s, _, server := startWithClock(t, "", map[string]string{
+		rulesDir:            writeRules(t, testRules),
+		allowNets:           allowed,
+		rateLimitExemptNets: exempt,
+		rateLimitPerMinute:  "1",
+	})
+
+	// A client in SWWAF_ALLOW_NETS is not checked.
+	line := s.request(allowed, "/.env", http.StatusOK, requestlog.ActionForward)
+	wantRuleIDs(t, line)
+
+	// A probe over the rate limit breaks the limit before any rule sees
+	// it.
+	s.get(client, http.StatusOK, requestlog.ActionForward)
+	line = s.request(client, "/.env", http.StatusForbidden, requestlog.ActionRateLimited)
+	wantRuleIDs(t, line)
+
+	limitBan := server.Ledger.Bans(netip.MustParsePrefix(client + "/32"))
+	if len(limitBan) != 1 || limitBan[0].Cause != bans.CauseLimit {
+		t.Errorf("bans %+v, want one for a broken limit", limitBan)
+	}
+
+	// A client the rate limits do not apply to is still checked.
+	s.get(exempt, http.StatusOK, requestlog.ActionForward)
+	s.request(exempt, "/.env", http.StatusForbidden, requestlog.ActionBanned)
+}
+
+func TestObserveModeLogsWhatTheRulesWouldDo(t *testing.T) {
+	t.Parallel()
+
+	s, _, server := startWithClock(t, "", map[string]string{
+		rulesDir: writeRules(t, testRules),
+		mode:     observe,
+	})
+
+	line := s.request(client, "/blocked", http.StatusOK, requestlog.ActionForward)
+	wantWouldAction(t, line, requestlog.ActionRuleBlocked)
+	wantRuleIDs(t, line, "blocked")
+
+	line = s.request(client, "/.env", http.StatusOK, requestlog.ActionForward)
+	wantWouldAction(t, line, requestlog.ActionBanned)
+	wantRuleIDs(t, line, "probe")
+
+	if line.BanExpires != "" {
+		t.Errorf("log line has ban_expires %q, want none", line.BanExpires)
+	}
+
+	// No ban was made.
+	line = s.get(client, http.StatusOK, requestlog.ActionForward)
+	wantWouldAction(t, line, "")
+
+	if got := server.Ledger.Snapshot(); len(got) != 0 {
+		t.Errorf("bans %+v, want none", got)
+	}
+}
+
+func TestMetricsCountRuleMatchesAndBansForAnAttack(t *testing.T) {
+	t.Parallel()
+
+	const scraper = "192.0.2.200"
+
+	s, _, _ := startWithClock(t, "", map[string]string{
+		rulesDir:     writeRules(t, testRules),
+		metricsToken: token,
+	})
+
+	s.request(client, "/blocked", http.StatusForbidden, requestlog.ActionRuleBlocked)
+	s.request(client, "/.env", http.StatusForbidden, requestlog.ActionBanned)
+	s.get(client, http.StatusForbidden, requestlog.ActionBanned)
+
+	metrics := s.scrape(scraper)
+	wantMetric(t, metrics,
+		`smallwebwaf_rule_matches_total{action="block",rule_id="blocked"}`, 1)
+	wantMetric(t, metrics,
+		`smallwebwaf_rule_matches_total{action="ban",rule_id="probe"}`, 1)
+	wantMetric(t, metrics, "smallwebwaf_rules_loaded", 2)
+	wantMetric(t, metrics,
+		`smallwebwaf_requests_total{action="rule_blocked",status_class="4xx"}`, 1)
+	wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="attack"}`, 1)
+	wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="limit"}`, 0)
+	wantMetric(t, metrics, "smallwebwaf_permanent_bans", 1)
+}
+
+// writeRules writes content as a rule file into a new directory, and
+// returns the directory.
+func writeRules(t *testing.T, content string) string {
+	t.Helper()
+
+	dir := t.TempDir()
+
+	err := os.WriteFile(filepath.Join(dir, "test.rules"), []byte(content), 0o600)
+	if err != nil {
+		t.Fatalf("write the rule file: %v", err)
+	}
+
+	return dir
+}
+
+// wantRuleIDs checks the request log line's rule_ids.
+func wantRuleIDs(t *testing.T, line logLine, want ...string) {
+	t.Helper()
+
+	if !slices.Equal(line.RuleIDs, want) {
+		t.Errorf("log line has rule_ids %v, want %v", line.RuleIDs, want)
+	}
+}

internal/proxy/rules.go

@@ -0,0 +1,40 @@
+package proxy
+
+import (
+	"time"
+
+	"sneak.berlin/go/smallwebwaf/internal/requestlog"
+	"sneak.berlin/go/smallwebwaf/internal/rules"
+)
+
+// checkRules checks the request against the rules of the rule files at
+// now, notes the ids of those it matches in the log line, and returns the
+// action of the rule that refuses it, ActionRuleBlocked for a block rule
+// and ActionBanned for a ban rule, or "" when none does. In enforce mode
+// a ban rule bans the client's netblock for a clear sign of attack.
+func (rq *request) checkRules(now time.Time) string {
+	matched := rq.h.rules.Match(rq.in)
+
+	for _, rule := range matched {
+		rq.line.RuleIDs = append(rq.line.RuleIDs, rule.ID)
+		rq.h.metrics.RuleMatched(rule.ID, rule.Action)
+	}
+
+	if len(matched) == 0 {
+		return ""
+	}
+
+	// Only the last rule matched can refuse the request.
+	switch last := matched[len(matched)-1]; last.Action {
+	case rules.ActionBlock:
+		return requestlog.ActionRuleBlocked
+	case rules.ActionBan:
+		if !rq.h.config.Observe {
+			rq.banForAttack(now, last)
+		}
+
+		return requestlog.ActionBanned
+	default:
+		return ""
+	}
+}