waf: the header limits are the first check (closes #311)

A request over 50 cookies or 100 header fields is now refused by the first
check after SWW_ALLOW_NETS. It causes no lookup, no query to RouteWatch, a DNS
blocklist or AbuseIPDB, no rule file match and no Core Rule Set. The rate
limits no longer count it, and a banned or denied client gets 431 for it. It
makes no ban, makes no ban permanent and is not counted in a ban's notes. In
observe mode no lookup is made for it. Requests within the limits go through
the same checks in the same order.

Model: opus-5-5

AGENTS.md

@@ -37,3 +37,6 @@ These are the rules for agents working on this repository.
         - `192.168.0.0/16`.
     - `SPEC.md` states that default.
     - Forwarded headers count only when the peer is a trusted proxy.
+- Every time is in UTC, whatever `TZ` or the host's time zone says.
+    - Every day is a date written `YYYY-MM-DD`, never a time.
+    - `SPEC.md` states this near its start.

README.md

@@ -509,7 +509,8 @@ request reaches the app.
 
 `waf` takes the checks:
 
-3. The tag lists.
+3. The header limits, then the tag lists. A client in `SWW_ALLOW_NETS` skips the
+   header limits.
 4. The static lists, `SWW_ALLOW_NETS` and `SWW_DENY_NETS`.
 5. The bans.
 6. The lookup of the client's AS number and country.
@@ -521,7 +522,7 @@ request reaches the app.
 11. The rate limits.
 12. The trap paths.
 13. The rule files.
-14. The header limits, and then the Core Rule Set.
+14. The Core Rule Set.
 15. The tag refusals again, so that `exploitsignature` can refuse too.
 16. A path under `/_sww/` is answered `404`, so that the app never sees that
     prefix.
@@ -537,7 +538,7 @@ request reaches the app.
 A refused visitor is answered with `SWW_BAN_RESPONSE`. A `block` rule or a Core
 Rule Set match answers `403` and bans nobody, since the Core Rule Set has false
 positives; such refusals count toward `SWW_ERROR_BURST_THRESHOLD` instead. A
-request over the header limits of step 14 is answered `431`, and bans nobody
+request over the header limits of step 3 is answered `431`, and bans nobody
 either. `rproxy` itself answers `405` to a method it does not pass on, and the
 status for a size or time limit, such as `413` for a body too large.
 

SPEC.md

@@ -12,6 +12,10 @@ it is built, except what the last section lists. `README.md` says how to run it.
 under `docs/` give the settings, the formats and the lists. This document links
 to them.
 
+The whole application stores, logs and handles every time in UTC, whatever `TZ`
+or the host's time zone says. It keeps every day as a date written `YYYY-MM-DD`,
+never as a time.
+
 ## Purpose
 
 - It protects self-hosted apps on the open internet from scrapers, scanners and
@@ -145,10 +149,12 @@ field gives that name. `refusal_limit` and `byte_limits` give theirs in
     - An IPv6 client is its group: the netblock of `SWW_IPV6_GROUP_PREFIX`
       around its address, a /64 by default, since one abuser usually controls a
       whole /64. A client is therefore one IPv4 address or one IPv6 group.
-3. The tag lists (`tag_lists`; see "Request tags"). Each list that holds the
-   client adds its tag. Next, `routewatch_tags` adds the client's `asn=` and
+3. The header limits (`header_limits`; see "Answering in time"). They come first
+   after `SWW_ALLOW_NETS`, since they only count header fields and cookies.
+   Next, the tag lists (`tag_lists`; see "Request tags"). Each list that holds
+   the client adds its tag. Next, `routewatch_tags` adds the client's `asn=` and
    `prefix=` tags while `SWW_ROUTEWATCH_URL` is set. A client in
-   `SWW_ALLOW_NETS` gets no tag.
+   `SWW_ALLOW_NETS` skips the header limits and gets no tag.
 4. The static lists. A client in `SWW_ALLOW_NETS` skips steps 5 to 15, the byte
    limits and the error burst. A client in `SWW_DENY_NETS` is refused
    (`deny_nets`); a client in both lists is let through.
@@ -181,10 +187,9 @@ field gives that name. `refusal_limit` and `byte_limits` give theirs in
     refused and bans the client.
 13. The rule files (`rule_files`; see "Rule files"). Matching stops at the first
     rule that refuses.
-14. The header limits (`header_limits`; see "Answering in time"), and then the
-    Core Rule Set (`core_rule_set`; see "Attack detection"). A Core Rule Set
-    match is refused with `403` while `SWW_WAF_MODE` is `block`, and only logged
-    and alerted while it is `detect`.
+14. The Core Rule Set (`core_rule_set`; see "Attack detection"). A match is
+    refused with `403` while `SWW_WAF_MODE` is `block`, and only logged and
+    alerted while it is `detect`.
 15. The tag refusals again (`tag_deny`), so that `exploitsignature` can refuse
     too.
 16. A path under `/_sww/` is answered `404`, so that the app never sees that
@@ -237,11 +242,16 @@ apply.
 ## Bans
 
 Until a ban ends, every request from its netblock is refused with
-`SWW_BAN_RESPONSE`. The netblock is the client: its IPv4 address, widened to
-`SWW_BAN_SCOPE_V4_PREFIX`, or its IPv6 group. At the defaults a ban covers one
-address or one /64, so a permanent ban does not reach neighbours who did
-nothing. Requests refused under a ban are not counted against limits. They are
-counted in the client's history and in the ban's notes.
+`SWW_BAN_RESPONSE`, unless it is over the header limits. The netblock is the
+client: its IPv4 address, widened to `SWW_BAN_SCOPE_V4_PREFIX`, or its IPv6
+group. At the defaults a ban covers one address or one /64, so a permanent ban
+does not reach neighbours who did nothing. Requests refused under a ban are not
+counted against limits. They are counted in the client's history and in the
+ban's notes.
+
+A request over the header limits is refused with `431` before the bans are
+checked (see "Answering in time"). It makes no ban, makes no ban permanent and
+is not counted in a ban's notes.
 
 An offence is a request `waf` holds against the client. It is one of:
 
@@ -1775,6 +1785,7 @@ in. `docs/state-files.md` lists the files, what each holds, and their sizes.
     - a top-level `version` number;
     - entries sorted by client address;
     - times in RFC 3339 UTC;
+    - days as `YYYY-MM-DD`;
     - durations and sizes as plain numbers, with the unit in the field name.
 - `bans.json`, `reputation.json` and `alerts.json` are indented, so that a
   person can open `bans.json` in an editor, find an address, and remove or add
@@ -2020,7 +2031,6 @@ waits on these, which run in the background:
 
 In `enforce` mode, a question does not wait for GeoJS when it is a request:
 
-- over the header limits;
 - from a client on a fetched blocklist, while `SWW_BLOCKLIST_ACTION` is `deny`;
 - from a client on the CrowdSec decision list;
 - that would take its client over a rate limit at 100% of it, since a percentage
@@ -2032,8 +2042,8 @@ number and country stay unknown until GeoJS has answered. So while
 `SWW_UNKNOWN_LIMIT_PERCENT` does not apply to it until then, so not waiting
 never lowers its limit.
 
-The static lists and bans come before the lookup, so they never wait. These can
-still wait for GeoJS:
+The header limits, the static lists and bans come before the lookup, so they
+never wait. These can still wait for GeoJS:
 
 - a country list, which needs the answer;
 - a rate limit a percentage has lowered, which needs the answer;
@@ -2052,13 +2062,17 @@ either one:
 
 Real clients never reach these limits. The answer is `deny` with `431`, and the
 log line's action is `request_header_too_large`. The refusal makes no ban and is
-no offence. The rate limits count the request as usual, so a client that keeps
-sending such requests breaks a limit.
+no offence.
+
+The header limits are the first check after `SWW_ALLOW_NETS`. A request over
+them is refused before any later check runs. So it causes no lookup, no query to
+an outside source and no rule match, and the rate limits do not count it. A
+client under a ban or in `SWW_DENY_NETS` also gets `431` for such a request.
 
 The limits apply on every path and in every `SWW_WAF_MODE`. A client in
 `SWW_ALLOW_NETS` skips them, as it skips the Core Rule Set. In `observe` mode
-such a request is answered `allow` with `would_action`, and the Core Rule Set
-does not read it.
+such a request is answered `allow` with `would_action`, and no other check runs
+on it.
 
 The Core Rule Set runs each of its rules on each cookie, so thousands of small
 cookies would keep it busy for over a second. Within the limits, one long cookie

go.mod

@@ -3,6 +3,7 @@ module sneak.berlin/go/smallwebwaf
 go 1.26.0
 
 require (
+	cloud.google.com/go v0.123.0
 	github.com/corazawaf/coraza-coreruleset/v4 v4.25.0
 	github.com/corazawaf/coraza/v3 v3.8.2-0.20261022102553-d028be399c68
 	github.com/fsnotify/fsnotify v1.10.1

go.sum

@@ -1,3 +1,5 @@
+cloud.google.com/go v0.123.0 h1:2NAUJwPR47q+E35uaJeYoNhuNEM9kM8SjgRgdeOJUSE=
+cloud.google.com/go v0.123.0/go.mod h1:xBoMV08QcqUGuPW65Qfm1o9Y4zKZBpGS+7bImXLTAZU=
 github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
 github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw=
 github.com/cespare/xxhash/v2 v2.3.0 h1:UL815xU9SqsFlibzuggzjXhog7bL6oX9BbNZnL2UFvs=

internal/lookup/file.go

@@ -26,7 +26,7 @@ type FileParams struct {
 	// Path is the lookup database, the IPinfo Lite file in its .mmdb form
 	// (SWW_LOOKUP_DB_PATH).
 	Path string
-	// Now tells the time, normally time.Now.
+	// Now tells the time, normally time.Now in UTC.
 	Now func() time.Time
 	// ProcessLog receives each reading of the file, and why a replacement
 	// of it cannot be read.

internal/lookup/lookup.go

@@ -74,7 +74,7 @@ type Params struct {
 	// Answered, unless nil, is given each answer GeoJS gives, once it is
 	// kept.
 	Answered func(Answer)
-	// Now tells the time, normally time.Now.
+	// Now tells the time, normally time.Now in UTC.
 	Now func() time.Time
 	// ProcessLog receives GeoJS's failures.
 	ProcessLog *slog.Logger

internal/reputation/abuseipdb.go

@@ -14,6 +14,7 @@ import (
 	"sync"
 	"time"
 
+	"cloud.google.com/go/civil"
 	"github.com/hashicorp/golang-lru/v2/simplelru"
 	"sneak.berlin/go/smallwebwaf/internal/alerts"
 )
@@ -27,8 +28,6 @@ const (
 	AbuseIPDBSource = "abuseipdb"
 	// maxAnswerBytes is the most of an answer of AbuseIPDB that is read.
 	maxAnswerBytes = 64 << 10
-	// day is the length of the day the checks are counted in, in UTC.
-	day = 24 * time.Hour
 )
 
 var (
@@ -50,9 +49,9 @@ type Score struct {
 // AbuseIPDB: the day, in UTC, of the checks Spent counts, zero before the
 // first, and the scores still in use.
 type Checks struct {
-	Day    time.Time `json:"day,omitzero"`
-	Spent  int       `json:"spent"`
-	Scores []Score   `json:"scores"`
+	Day    civil.Date `json:"day,omitzero"`
+	Spent  int        `json:"spent"`
+	Scores []Score    `json:"scores"`
 }
 
 // AbuseIPDBParams are what NewAbuseIPDB needs.
@@ -93,7 +92,7 @@ type AbuseIPDB struct {
 	// checking are the clients whose check is under way.
 	checking map[netip.Prefix]bool
 	// day is the day, in UTC, of the checks spent counts.
-	day   time.Time
+	day   civil.Date
 	spent int
 	// checks and failures count the checks made and those that failed,
 	// and retryAt is when a client may be checked again after the last
@@ -143,7 +142,7 @@ func (a *AbuseIPDB) Hit(
 		return kept.Score, kept.Score >= a.params.MinScore
 	}
 
-	if today := now.Truncate(day); !a.day.Equal(today) {
+	if today := civil.DateOf(now.UTC()); a.day != today {
 		a.day, a.spent = today, 0
 	}
 
@@ -190,7 +189,7 @@ func (a *AbuseIPDB) BudgetLeft() int {
 	a.mu.Lock()
 	defer a.mu.Unlock()
 
-	if !a.day.Equal(a.params.Now().Truncate(day)) {
+	if a.day != civil.DateOf(a.params.Now().UTC()) {
 		return a.params.DailyBudget
 	}
 

internal/reputation/abuseipdb_test.go

@@ -202,6 +202,43 @@ func TestDailyBudgetKeptAcrossARestartAndWholeAgainAsTheDayEnds(t *testing.T) {
 	})
 }
 
+func TestChecksAreCountedInUTCDaysWhateverTheClocksZone(t *testing.T) {
+	t.Parallel()
+
+	synctest.Test(t, func(t *testing.T) {
+		// A clock 14 hours ahead of UTC, whose day starts at 10:00 UTC.
+		ahead := time.FixedZone("UTC+14", 14*60*60)
+		p := abuseIPDBParams()
+		p.DailyBudget = 1
+		p.Now = func() time.Time { return time.Now().In(ahead) }
+		abuseIPDB := &abuseIPDBStandIn{scores: map[string]int64{suspect: 100}}
+		checker := newAbuseIPDB(abuseIPDB, p)
+
+		// At 09:00 UTC the one check is spent.
+		time.Sleep(9 * time.Hour)
+		hitFrom(t, checker, suspect, true)
+		synctest.Wait()
+		wantBudgetLeft(t, checker, 0)
+
+		// At 11:00 UTC the clock's day has changed, but the UTC day has not.
+		time.Sleep(2 * time.Hour)
+		wantBudgetLeft(t, checker, 0)
+
+		encoded, err := json.Marshal(checker.Snapshot())
+		if err != nil {
+			t.Fatalf("encode: %v", err)
+		}
+
+		if !strings.Contains(string(encoded), `"day":"2000-01-01"`) {
+			t.Errorf("reputation.json would hold %s, want the day 2000-01-01", encoded)
+		}
+
+		// At 00:00 UTC the budget is whole again.
+		time.Sleep(13 * time.Hour)
+		wantBudgetLeft(t, checker, 1)
+	})
+}
+
 func TestFailedCheckGivesNoScoreAndNoClientIsCheckedForAMinute(t *testing.T) {
 	t.Parallel()
 

internal/state/state.go

@@ -171,9 +171,11 @@ type alertsFile struct {
 // check refuses the first entry without a field it needs, which would
 // otherwise be read as something the entry does not say. data is the
 // file, for a field that may be null or "" but not left out, which the
-// struct cannot tell apart.
+// struct cannot tell apart. Its toUTC then converts every time in it to
+// UTC, since an admin may write a time with an offset.
 type stateFile interface {
 	check(data []byte) error
+	toUTC()
 }
 
 // Load checks that files can be written in Dir, and reads the state files
@@ -918,6 +920,80 @@ func missing(i int, field string) error {
 	return fmt.Errorf("entry %d %w %q", i+1, errMissing, field)
 }
 
+// toUTC converts every time of each ban to UTC.
+func (f *bansFile) toUTC() {
+	for i := range f.Bans {
+		ban := &f.Bans[i]
+		convertToUTC(&ban.Start, ban.Expires, ban.Lifted, &ban.Notes.Request.Time)
+	}
+}
+
+// toUTC converts every time of each client to UTC.
+func (f *clientsFile) toUTC() {
+	for i := range f.Clients {
+		client := &f.Clients[i]
+		convertToUTC(&client.Minute.Start, &client.Hour.Start, &client.Day.Start,
+			&client.MinuteBytes.Start, &client.HourBytes.Start,
+			&client.DayBytes.Start, &client.MinuteRefusals.Start,
+			&client.History.FirstSeen, &client.History.LastSeen,
+			&client.History.LookedUp)
+	}
+}
+
+// toUTC converts both times of each answer to UTC.
+func (f *lookupsFile) toUTC() {
+	for i := range f.Lookups {
+		convertToUTC(&f.Lookups[i].Answered, &f.Lookups[i].Used)
+	}
+}
+
+// toUTC converts every time of each list, verdict and AbuseIPDB score to
+// UTC.
+func (f *reputationFile) toUTC() {
+	for i := range f.Lists {
+		convertToUTC(&f.Lists[i].Tried, &f.Lists[i].Fetched)
+	}
+
+	for i := range f.Verdicts {
+		convertToUTC(&f.Verdicts[i].Fetched)
+	}
+
+	for i := range f.AbuseIPDB.Scores {
+		convertToUTC(&f.AbuseIPDB.Scores[i].Fetched)
+	}
+}
+
+// toUTC converts every time of each cooldown, of the hour, of each alert
+// waiting and of each anomaly counter to UTC.
+func (f *alertsFile) toUTC() {
+	for i := range f.Cooldowns {
+		convertToUTC(&f.Cooldowns[i].Sent)
+	}
+
+	convertToUTC(&f.Hour.Start)
+
+	for _, waiting := range f.Waiting {
+		for i := range waiting {
+			convertToUTC(&waiting[i].Time)
+		}
+	}
+
+	for i := range f.AnomalyCounters {
+		counter := &f.AnomalyCounters[i]
+		convertToUTC(&counter.Minute.Start, &counter.Hour.Start,
+			&counter.MinuteBytes.Start, &counter.HourBytes.Start)
+	}
+}
+
+// convertToUTC converts each of times that is not nil to UTC.
+func convertToUTC(times ...*time.Time) {
+	for _, at := range times {
+		if at != nil {
+			*at = at.UTC()
+		}
+	}
+}
+
 // encodeOnePerLine encodes a state file whose entries, under key, are one
 // to a line, so that grep shows everything about one client.
 func encodeOnePerLine[E any](key string, entries []E) ([]byte, error) {
@@ -955,7 +1031,8 @@ func checkWritable(dir string) error {
 }
 
 // parse reads data, what the state file at path holds, into file, a
-// pointer to that file's struct, and checks its entries.
+// pointer to that file's struct, checks its entries, and converts every
+// time in it to UTC.
 func parse(path string, data []byte, file stateFile) error {
 	// The version is read first, so that a file of another version is
 	// refused for that, and not for an entry this version cannot read.
@@ -985,6 +1062,8 @@ func parse(path string, data []byte, file stateFile) error {
 		return fmt.Errorf("%s%s: %w", path, position(data, err), err)
 	}
 
+	file.toUTC()
+
 	return nil
 }
 

internal/state/state_test.go

@@ -14,6 +14,7 @@ import (
 	"os"
 	"path/filepath"
 	"reflect"
+	"regexp"
 	"slices"
 	"strconv"
 	"strings"
@@ -21,6 +22,7 @@ import (
 	"testing/synctest"
 	"time"
 
+	"cloud.google.com/go/civil"
 	"sneak.berlin/go/smallwebwaf/internal/alerts"
 	"sneak.berlin/go/smallwebwaf/internal/anomaly"
 	"sneak.berlin/go/smallwebwaf/internal/bans"
@@ -258,7 +260,7 @@ const filledReputationJSON = `{
         }
     ],
     "abuseipdb": {
-        "day": "2026-10-06T00:00:00Z",
+        "day": "2026-10-06",
         "spent": 3,
         "scores": [
             {
@@ -1306,7 +1308,7 @@ func TestEditOfEachFileTakenIn(t *testing.T) {
 		`"tried": "2026-10-06T00:00:00Z", "fetched": "2026-10-06T00:00:00Z", `+
 		`"lines": ["198.51.100.7"]}], "verdicts": [{"zone": "`+dnsblZone+`", `+
 		`"client": "198.51.100.7", "listed": true, "fetched": "2026-10-06T00:00:00Z"}], `+
-		`"abuseipdb": {"day": "2026-10-06T00:00:00Z", "spent": 9, "scores": [`+
+		`"abuseipdb": {"day": "2026-10-06", "spent": 9, "scores": [`+
 		`{"client": "198.51.100.7/32", "score": 80, "fetched": "2026-10-06T00:00:00Z"}]}}`)
 	wantTakenIn(t, lines, dir, reputationJSON)
 
@@ -1321,7 +1323,7 @@ func TestEditOfEachFileTakenIn(t *testing.T) {
 	}})
 
 	checks := reputation.Checks{
-		Day: midnight(), Spent: 9,
+		Day: civil.DateOf(midnight()), Spent: 9,
 		Scores: []reputation.Score{{Client: client, Score: 80, Fetched: midnight()}},
 	}
 	if got := params.AbuseIPDB.Snapshot(); !reflect.DeepEqual(got, checks) {
@@ -1350,6 +1352,62 @@ func TestEditOfEachFileTakenIn(t *testing.T) {
 	}
 }
 
+func TestTimesEditedWithAnOffsetWrittenBackInUTC(t *testing.T) {
+	t.Parallel()
+
+	dir := t.TempDir()
+	params := newParams(dir)
+	fill(params)
+	// A lifted ban, so that bans.json holds every time a ban has.
+	params.Ledger.Lift(netip.MustParseAddr("192.0.2.1"), midnight())
+
+	files := load(t, params)
+
+	err := files.WriteAll()
+	if err != nil {
+		t.Fatalf("write: %v", err)
+	}
+
+	// An admin saves each file with every time in it two hours ahead of
+	// UTC, midnight as "2026-10-06T02:00:00+02:00".
+	stamp := regexp.MustCompile(`"\d{4}-\d\d-\d\dT[^"]*Z"`)
+	ahead := time.FixedZone("UTC+2", 2*60*60)
+	written := map[string]string{}
+
+	for _, name := range []string{
+		bansJSON, clientsJSON, lookupsJSON, reputationJSON, alertsJSON,
+	} {
+		written[name] = readFile(t, filepath.Join(dir, name))
+		edited := stamp.ReplaceAllStringFunc(written[name], func(quoted string) string {
+			at, err := time.Parse(time.RFC3339Nano, strings.Trim(quoted, `"`))
+			if err != nil {
+				t.Fatalf("%s holds %s: %v", name, quoted, err)
+			}
+
+			return `"` + at.In(ahead).Format(time.RFC3339Nano) + `"`
+		})
+
+		if !strings.Contains(edited, "+02:00") {
+			t.Fatalf("%s holds no time:\n%s", name, edited)
+		}
+
+		edit(t, dir, name, edited)
+	}
+
+	// Each write takes its edit in first, and writes the same times back in
+	// UTC.
+	err = files.WriteAll()
+	if err != nil {
+		t.Fatalf("write: %v", err)
+	}
+
+	for name, want := range written {
+		if got := readFile(t, filepath.Join(dir, name)); got != want {
+			t.Errorf("%s written back as\n%s\nwant\n%s", name, got, want)
+		}
+	}
+}
+
 func TestOwnWritesAreNotTakenIn(t *testing.T) {
 	t.Parallel()
 
@@ -1837,10 +1895,12 @@ func fill(params state.Params) {
 		},
 		{Zone: dnsblZone, Client: client.Addr(), Listed: true, Fetched: now.Add(-time.Hour)},
 	})
-	params.AbuseIPDB.Load(reputation.Checks{Day: now, Spent: 3, Scores: []reputation.Score{
-		{Client: netip.MustParsePrefix("2001:db8::/64"), Fetched: now.Add(-2 * time.Hour)},
-		{Client: client, Score: 100, Fetched: now.Add(-time.Hour)},
-	}})
+	params.AbuseIPDB.Load(reputation.Checks{
+		Day: civil.DateOf(now), Spent: 3, Scores: []reputation.Score{
+			{Client: netip.MustParsePrefix("2001:db8::/64"), Fetched: now.Add(-2 * time.Hour)},
+			{Client: client, Score: 100, Fetched: now.Add(-time.Hour)},
+		},
+	})
 
 	// An alert waiting, a repeat of it the cooldown holds back, another
 	// alert waiting, and one past the two an hour, for the hour's summary.

internal/sww/waf_test.go

@@ -9,10 +9,14 @@ import (
 	"os"
 	"os/exec"
 	"path/filepath"
+	"regexp"
 	"strings"
 	"syscall"
 	"testing"
 	"time"
+	// The time zone database, so that the process TestMainRunsWAF starts
+	// finds the zone TZ names on any host.
+	_ "time/tzdata"
 
 	"sneak.berlin/go/smallwebwaf/internal/sww"
 	"sneak.berlin/go/smallwebwaf/internal/waf"
@@ -37,6 +41,14 @@ func TestMain(m *testing.M) {
 func TestMainRunsWAF(t *testing.T) {
 	t.Parallel()
 
+	// Kiritimati is 14 hours ahead of UTC; every time sww gives stays in UTC.
+	const zone = "Pacific/Kiritimati"
+
+	_, err := time.LoadLocation(zone)
+	if err != nil {
+		t.Fatalf("load %s: %v", zone, err)
+	}
+
 	binary, err := os.Executable()
 	if err != nil {
 		t.Fatalf("find the test binary: %v", err)
@@ -45,14 +57,16 @@ func TestMainRunsWAF(t *testing.T) {
 	ctx, cancel := context.WithTimeout(t.Context(), 3*waitLimit)
 	defer cancel()
 
+	dir := t.TempDir()
 	out := &output{}
 	cmd := exec.CommandContext(ctx, binary) //nolint:gosec // this test binary
 	cmd.Stdout = out
 
 	cmd.Env = append(os.Environ(),
+		"TZ="+zone,
 		commandForMain+"="+wafCommand,
 		listenAddr+"="+localhost+":0",
-		stateDir+"="+t.TempDir(),
+		stateDir+"="+dir,
 		rulesDir+"="+t.TempDir(),
 		lookupSource+"=off")
 
@@ -66,9 +80,11 @@ func TestMainRunsWAF(t *testing.T) {
 		_ = cmd.Wait()
 	})
 
-	addr, _ := out.line(t, "msg", "starting")["address"].(string)
+	starting := out.line(t, "msg", "starting")
+	addr, _ := starting["address"].(string)
 	ask(t, addr, "/", http.StatusOK, waf.DispositionAllow)
 
+	// The files are written as sww stops.
 	err = cmd.Process.Signal(syscall.SIGTERM)
 	if err != nil {
 		t.Fatalf("signal: %v", err)
@@ -76,7 +92,39 @@ func TestMainRunsWAF(t *testing.T) {
 
 	err = cmd.Wait()
 	if err != nil {
-		t.Errorf("exit: %v; output:\n%s", err, out.text())
+		t.Fatalf("exit: %v; output:\n%s", err, out.text())
+	}
+
+	wantUTC(t, "the process line", starting["time"])
+	wantUTC(t, "the request line", out.line(t, "type", "request")["time"])
+
+	path := filepath.Join(dir, "clients.json")
+
+	clients, err := os.ReadFile(path) //nolint:gosec // a file in the test's directory
+	if err != nil {
+		t.Fatalf("read clients.json: %v", err)
+	}
+
+	stamp := regexp.MustCompile(`"\d{4}-\d\d-\d\dT[^"]*"`)
+
+	times := stamp.FindAllString(string(clients), -1)
+	if len(times) == 0 {
+		t.Errorf("clients.json holds no time:\n%s", clients)
+	}
+
+	for _, stored := range times {
+		wantUTC(t, "clients.json", strings.Trim(stored, `"`))
+	}
+}
+
+// wantUTC checks that value, a time read from the log line or file that
+// where names, is in UTC.
+func wantUTC(t *testing.T, where string, value any) {
+	t.Helper()
+
+	text, _ := value.(string)
+	if !strings.HasSuffix(text, "Z") {
+		t.Errorf("%s gives the time %v, want one in UTC", where, value)
 	}
 }
 

internal/waf/answertime_test.go

@@ -7,6 +7,7 @@ import (
 	"net/http"
 	"net/http/httptest"
 	"net/netip"
+	"path/filepath"
 	"slices"
 	"strconv"
 	"strings"
@@ -16,6 +17,7 @@ import (
 
 	"sneak.berlin/go/smallwebwaf/internal/bans"
 	"sneak.berlin/go/smallwebwaf/internal/lookup"
+	"sneak.berlin/go/smallwebwaf/internal/lookup/lookuptest"
 	"sneak.berlin/go/smallwebwaf/internal/ratelimit"
 	"sneak.berlin/go/smallwebwaf/internal/reputation"
 	"sneak.berlin/go/smallwebwaf/internal/requestlog"
@@ -216,93 +218,199 @@ func TestObserveModeAllowsARequestOverTheHeaderLimitsUnread(t *testing.T) {
 	}
 }
 
-func TestRequestsOverTheHeaderLimitsCountTowardTheRateLimits(t *testing.T) {
+func TestTheRateLimitsDoNotCountRequestsOverTheHeaderLimits(t *testing.T) {
 	t.Parallel()
 
 	s := startWAF(t, "", map[string]string{rateLimitPerMinute: "1"})
-	ask := func() answer {
+
+	for range 2 {
 		req := s.question(siteA, client, "/")
 		req.Header.Set(cookieHeader, cookies(cookieLimit+1))
-
-		return do(t, req)
+		wantDisposition(t, do(t, req), tooLarge, waf.DispositionDeny)
 	}
 
-	wantDisposition(t, ask(), tooLarge, waf.DispositionDeny)
-	wantDisposition(t, ask(), http.StatusForbidden, waf.DispositionDeny)
-
-	lines := s.out.requestLines(t, 2)
-	wantLine(t, lines[1], http.StatusForbidden, requestlog.ActionClientIsRateLimited)
+	wantDisposition(t, s.ask(client, "/"), http.StatusOK, waf.DispositionAllow)
 }
 
-func TestTheHeaderLimitsComeAfterTheTrapPathsAndTheRuleFiles(t *testing.T) {
+func TestTheHeaderLimitsComeBeforeEveryCheckThatRefuses(t *testing.T) {
 	t.Parallel()
 
+	// The lookup database places client in Germany.
+	lookupDB := filepath.Join(t.TempDir(), "ipinfo_lite.mmdb")
+	lookuptest.Write(t, lookupDB, map[string]lookuptest.Network{
+		client + "/32": {ASN: asnDE, ASName: asNameDE, Country: "DE"},
+	})
+
 	for _, tc := range []struct {
-		name, path, action string
+		name string
+		env  map[string]string
+		path string
+		// prepare gets the server ready, at now, before the question.
+		prepare func(t *testing.T, server *waf.Server, now time.Time)
 	}{
-		{"a trap path", "/wp-login.php", requestlog.ActionTemporarilyBanned},
-		{"a block rule", "/blocked", requestlog.ActionBlockedByBlockRule},
+		{"SWW_DENY_NETS", map[string]string{denyNets: client}, "/", leaveAsItIs},
+		{"a ban", nil, "/", banClient},
+		{
+			"the country list", map[string]string{
+				lookupSource: fileSource, lookupDBPath: lookupDB, allowedCountries: "FR",
+			},
+			"/", leaveAsItIs,
+		},
+		{"a blocklist", map[string]string{blocklistURLs: dropURL}, "/", listClient},
+		{
+			"the CrowdSec decision list",
+			map[string]string{crowdSecURL: lapi, crowdSecKey: bouncerKey}, "/", decideOnClient,
+		},
+		{
+			"a DNS blocklist", map[string]string{
+				dnsblZones: dnsblZone, dnsblResolver: noResolver, reputationAction: actionDeny,
+			},
+			"/", func(_ *testing.T, server *waf.Server, _ time.Time) {
+				loadVerdicts(server, map[string][]string{client: {dnsblZone}})
+			},
+		},
+		{
+			"AbuseIPDB",
+			map[string]string{abuseIPDBKey: accountKey, reputationAction: actionDeny},
+			"/", func(_ *testing.T, server *waf.Server, _ time.Time) {
+				// Over SWW_ABUSEIPDB_MIN_SCORE, 75 by default.
+				loadScores(server, map[string]int64{client: 80})
+			},
+		},
+		{
+			"SWW_TAG_DENY", map[string]string{tagLists: "vpn=" + vpnList, tagDeny: "vpn"},
+			"/", func(t *testing.T, server *waf.Server, _ time.Time) {
+				t.Helper()
+				loadLists(t, server, map[string][]string{vpnList: {client}})
+			},
+		},
+		{"the rate limits", map[string]string{rateLimitPerMinute: "1"}, "/", countClient},
+		{
+			"a trap path", map[string]string{trapPaths: trapPathList}, "/wp-login.php",
+			leaveAsItIs,
+		},
+		{
+			"a block rule", map[string]string{rulesDir: writeRules(t, testRules)}, "/blocked",
+			leaveAsItIs,
+		},
 	} {
 		t.Run(tc.name, func(t *testing.T) {
 			t.Parallel()
 
-			s := startWAF(t, "", map[string]string{
-				trapPaths: trapPathList, rulesDir: writeRules(t, testRules),
-			})
+			s := startWAF(t, "", tc.env)
+			tc.prepare(t, s.server, s.clock.Now())
+
 			req := s.question(siteA, client, tc.path)
 			req.Header.Set(cookieHeader, cookies(cookieLimit+1))
 
-			wantDisposition(t, do(t, req), http.StatusForbidden, waf.DispositionDeny)
-			wantLine(t, s.out.requestLine(t), http.StatusForbidden, tc.action)
+			wantDisposition(t, do(t, req), tooLarge, waf.DispositionDeny)
+			wantLine(t, s.out.requestLine(t), tooLarge, requestlog.ActionRequestHeaderTooLarge)
 		})
 	}
 }
 
+func TestARequestOverTheHeaderLimitsRunsNoOtherCheck(t *testing.T) {
+	t.Parallel()
+
+	// Each check after the header limits leaves a mark on the log line of a
+	// request it reads: a tag, routewatch_tags_missing, a rule id, the
+	// counts, or the Core Rule Set's time.
+	path := filepath.Join(t.TempDir(), "ipinfo_lite.mmdb")
+	lookuptest.Write(t, path, map[string]lookuptest.Network{
+		client + "/32": {ASN: asnDE, ASName: asNameDE, Country: "DE"},
+	})
+	s := startWAF(t, "", map[string]string{
+		lookupSource: fileSource, lookupDBPath: path,
+		tagLists:      "vpn=" + vpnList,
+		routeWatchURL: startRouteWatch(t, map[string]standInRoute{client: {prefixDE, 64496}}),
+		dnsblZones:    dnsblZone, reputationAction: actionLog,
+		rulesDir: writeRules(t, "noted path log ^/\n"),
+		wafMode:  block,
+	})
+	loadLists(t, s.server, map[string][]string{vpnList: {client}})
+	loadVerdicts(s.server, map[string][]string{client: {dnsblZone}})
+
+	over := s.question(siteA, client, "/")
+	over.Header.Set(cookieHeader, cookies(cookieLimit+1))
+	wantDisposition(t, do(t, over), tooLarge, waf.DispositionDeny)
+
+	within := s.question(siteA, client, "/")
+	within.Header.Set(cookieHeader, cookies(cookieLimit))
+	wantDisposition(t, do(t, within), http.StatusOK, waf.DispositionAllow)
+
+	lines := s.out.requestLines(t, 2)
+
+	wantTags(t, lines[0])
+	wantTagsMissing(t, lines[0], "")
+
+	if lines[0].RuleIDs != nil || lines[0].Counts != (ratelimit.Counts{}) ||
+		lines[0].DurationCoreRuleSetMS != nil {
+		t.Errorf("rule ids %v, counts %+v and Core Rule Set time %v, want none",
+			lines[0].RuleIDs, lines[0].Counts, lines[0].DurationCoreRuleSetMS)
+	}
+
+	// The request within the limits shows that each check leaves its mark.
+	wantTags(t, lines[1],
+		"asn=64496", "country=DE", "dnsbl="+dnsblZone, "exploitsignature", "vpn")
+	wantTagsMissing(t, lines[1], "no_answer_yet")
+
+	if lines[1].RuleIDs == nil || lines[1].Counts.Minute != 1 ||
+		lines[1].DurationCoreRuleSetMS == nil {
+		t.Errorf("rule ids %v, counts %+v and Core Rule Set time %v, want each",
+			lines[1].RuleIDs, lines[1].Counts, lines[1].DurationCoreRuleSetMS)
+	}
+}
+
 func TestNotWaitingForGeoJSNeverLowersAClientsLimit(t *testing.T) {
 	t.Parallel()
 
+	// The client's next request takes it over the whole limit, so it does
+	// not wait.
 	geojsURL, _ := startGeoJS(t)
 	s := startWAF(t, geojsURL, map[string]string{
-		unknownLimitPercent: "0", lookupTimeout: "1h",
+		unknownLimitPercent: "0", lookupTimeout: "1h", rateLimitPerMinute: "1",
 	})
-	req := s.question(siteA, fromDE, "/")
-	req.Header.Set(cookieHeader, cookies(cookieLimit+1))
+	countClient(t, s.server, s.clock.Now())
 
-	wantDisposition(t, do(t, req), tooLarge, waf.DispositionDeny)
+	wantDisposition(t, s.ask(fromDE, "/"), http.StatusForbidden, waf.DispositionDeny)
 
 	line := s.out.requestLine(t)
-	wantLine(t, line, tooLarge, requestlog.ActionRequestHeaderTooLarge)
+	wantLine(t, line, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
 
 	if line.RateLimitPercent != nil {
 		t.Errorf("limit percentage %d, want none", *line.RateLimitPercent)
 	}
-
-	// The client is under no ban, and GeoJS places it in a country.
-	wantDisposition(t, s.ask(fromDE, "/"), http.StatusOK, waf.DispositionAllow)
 }
 
 func TestAClientGeoJSPlacedInNoCountryCountsAsUnknownWithoutWaiting(t *testing.T) {
 	t.Parallel()
 
+	// The client's next request takes it over the whole limit, so it does
+	// not wait.
 	geojsURL, _ := startGeoJS(t)
-	s := startWAF(t, geojsURL, map[string]string{unknownLimitPercent: "0"})
+	s := startWAF(t, geojsURL, map[string]string{
+		unknownLimitPercent: "0", rateLimitPerMinute: "1",
+	})
 	s.server.GeoJS.Load([]lookup.Answer{{
 		Client: netip.MustParsePrefix(client + "/32"), ASN: "AS64512",
 		Answered: s.clock.Now(), Used: s.clock.Now(),
 	}})
+	countClient(t, s.server, s.clock.Now())
 
-	req := s.question(siteA, client, "/")
-	req.Header.Set(cookieHeader, cookies(cookieLimit+1))
+	wantDisposition(t, s.ask(client, "/"), http.StatusForbidden, waf.DispositionDeny)
 
-	wantDisposition(t, do(t, req), http.StatusForbidden, waf.DispositionDeny)
-	wantLine(t, s.out.requestLine(t), http.StatusForbidden,
-		requestlog.ActionClientIsRateLimited)
+	line := s.out.requestLine(t)
+	wantLine(t, line, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
+
+	if line.RateLimitPercent == nil || *line.RateLimitPercent != 0 {
+		t.Errorf("limit percentage %v, want 0", line.RateLimitPercent)
+	}
 }
 
-func TestObserveModeWaitsForGeoJSForARequestOverTheHeaderLimits(t *testing.T) {
+func TestObserveModeAsksGeoJSNothingForARequestOverTheHeaderLimits(t *testing.T) {
 	t.Parallel()
 
-	geojsURL, _ := startGeoJS(t)
+	geojsURL, asked := startGeoJS(t)
 	s := startWAF(t, geojsURL, map[string]string{
 		mode: observe, addLookupHeaders: on, lookupTimeout: "1h",
 	})
@@ -312,10 +420,9 @@ func TestObserveModeWaitsForGeoJSForARequestOverTheHeaderLimits(t *testing.T) {
 	got := do(t, req)
 	wantDisposition(t, got, http.StatusOK, waf.DispositionAllow)
 
-	asn, country := got.header.Get("X-Client-Asn"), got.header.Get("X-Client-Country")
-	if asn != asnDE || country != "DE" {
-		t.Errorf("answered with the AS number %q and the country %q, want %q and DE",
-			asn, country, asnDE)
+	if len(asked()) != 0 || got.header.Get("X-Client-Asn") != "" {
+		t.Errorf("GeoJS was asked about %v, and the answer gave the AS number %q, "+
+			"want neither", asked(), got.header.Get("X-Client-Asn"))
 	}
 }
 

internal/waf/headerlimits.go

@@ -10,22 +10,23 @@ import (
 	"sneak.berlin/go/smallwebwaf/internal/requestlog"
 )
 
-// The header limits: the most cookies and header fields a request may have
-// when the checks reach the Core Rule Set. Real clients never reach them.
+// The header limits: the most cookies and header fields a request may have.
+// Real clients never reach them.
 const (
 	maxCookies      = 50
 	maxHeaderFields = 100
 )
 
-// headerLimits refuses a request over the header limits, with 431. Its figures
-// are the request's header fields and cookies, and the limit of each.
+// headerLimits refuses a request with more than maxHeaderFields header fields
+// or more than maxCookies cookies, with 431. Its figures are the request's
+// header fields and cookies, and the limit of each.
 type headerLimits struct{}
 
 func (headerLimits) name() string { return "header_limits" }
 
 func (headerLimits) check(_ context.Context, rq *request, _ time.Time) *verdict {
 	fields, cookies := rq.headerCounts()
-	if !overHeaderLimits(fields, cookies) {
+	if fields <= maxHeaderFields && cookies <= maxCookies {
 		return nil
 	}
 
@@ -38,13 +39,6 @@ func (headerLimits) check(_ context.Context, rq *request, _ time.Time) *verdict
 	}
 }
 
-// overHeaderLimits reports whether a request with these counts of header fields
-// and cookies, as headerCounts counts them, is over the header limits: it has
-// more than maxHeaderFields fields or more than maxCookies cookies.
-func overHeaderLimits(fields, cookies int) bool {
-	return fields > maxHeaderFields || cookies > maxCookies
-}
-
 // headerCounts returns the request's header fields, each value of a header sent
 // twice being one, and its cookies, each part of a Cookie header between
 // semicolons being one unless it is empty or only spaces and tabs. The Core

internal/waf/heuristics.go

@@ -41,8 +41,11 @@ const (
 
 // beforeLookup are the heuristics that run before the client's AS number and
 // country are looked up, so that a client they refuse is not looked up.
+// header_limits comes first: it only counts, and a request it refuses causes no
+// other work.
 func beforeLookup() []heuristic {
 	return []heuristic{
+		headerLimits{},
 		tagLists{},
 		routeWatchTags{},
 		denyNets{},
@@ -64,7 +67,6 @@ func afterLookup() []heuristic {
 		rateLimits{},
 		trapPaths{},
 		ruleFiles{},
-		headerLimits{},
 		coreRuleSet{},
 		tagDeny{},
 	}

internal/waf/waf.go

@@ -143,10 +143,9 @@ func (h *handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 
 // refusedWhateverTheAnswer reports whether the request is one that does not wait
 // for GeoJS, since the checks will refuse it at now whatever GeoJS answers about
-// its client: the heuristic crowdsec, header_limits, blocklists or rate_limits
-// will refuse it, as a function in that heuristic's file says. In observe mode,
-// which refuses nothing, none is. rproxy lets a request through when
-// waf answers too late.
+// its client: the heuristic crowdsec, blocklists or rate_limits will refuse it,
+// as a function in that heuristic's file says. In observe mode, which refuses
+// nothing, none is. rproxy lets a request through when waf answers too late.
 func (rq *request) refusedWhateverTheAnswer(now time.Time) bool {
 	if rq.h.config.Observe {
 		return false
@@ -154,8 +153,7 @@ func (rq *request) refusedWhateverTheAnswer(now time.Time) bool {
 
 	_, decided := rq.crowdSecDecisionInForce(now)
 
-	return decided || overHeaderLimits(rq.headerCounts()) ||
-		rq.refusedByBlocklists(rq.h.lists.ListedBy(rq.client)) ||
+	return decided || rq.refusedByBlocklists(rq.h.lists.ListedBy(rq.client)) ||
 		rq.overAWholeRateLimit(now)
 }