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

Every *.rules file in SWWAF_RULES_DIR not named with a leading dot is
read at start, and again 2 seconds after the directory's last change.
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
attack. path, query and uri are matched as the request line sent them;
header:Host and header:Transfer-Encoding are refused. Bans gain a 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
@@ -54,20 +55,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)
@@ -75,6 +68,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/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 (
@@ -74,6 +75,8 @@ const (
 	banScopeV4Prefix        = "SWWAF_BAN_SCOPE_V4_PREFIX"
 	instanceName            = "SWWAF_INSTANCE_NAME"
 	logRequestHeaders       = "SWWAF_LOG_REQUEST_HEADERS"
+	attackBanDuration       = "SWWAF_ATTACK_BAN_DURATION"
+	rulesDir                = "SWWAF_RULES_DIR"
 )
 
 // output collects what smallwebwaf writes on stdout.
@@ -212,14 +215,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) {
@@ -232,12 +236,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

@@ -159,20 +159,23 @@ func requestHeaders(r *http.Request, names []string) map[string]string {
 // 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
@@ -195,8 +198,8 @@ func (rq *request) check(ctx context.Context) *refusal {
 // 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 or the request's path is exempt under
-// SWWAF_RATE_LIMIT_EXEMPT_PATHS, so that every other request is counted.
-// ctx is the request's own context.
+// SWWAF_RATE_LIMIT_EXEMPT_PATHS, 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) {
@@ -223,7 +226,7 @@ func (rq *request) checkClient(ctx context.Context) string {
 		return requestlog.ActionRateLimited
 	}
 
-	return ""
+	return rq.checkRules(now)
 }
 
 // pathExempt reports whether the rate limits leave out a request for u

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 ""
+	}
+}