Name request log actions so they say what they mean (closes #229)
check / check (push) Successful in 6m30s

The request log's `action` values now say what they mean, as sneak named them: `request_header_too_large`, `client_is_rate_limited`, `blocked_by_block_rule` and `client_denied`, with no aliases. `banned` splits into `temporarily_banned` and `permanently_banned`, by whether the ban runs out. When a permanent ban also covers a client, that ban is the one reported.

Trips a reader: a request over a rate limit stays `client_is_rate_limited` even when the ban it makes is permanent.
Disclosure: the offence key `rule_blocked` is renamed in `clients.json` too, so an existing file holding it stops the start and must be removed. Its `version` stays 1.

Model: opus-5-5
This commit was merged in pull request #233.
This commit is contained in:
clawbot committed 2026-11-09 06:48:26 +01:00
1 parent 6850cb0e9f
commit aede434f6a
48 files changed
+522 -300

No files matched your search

+26 -24
View File
@@ -40,7 +40,7 @@ func TestBrokenLimitBansTheClient(t *testing.T) {
// client for an hour, the default.
s.get(client, http.StatusOK, requestlog.ActionForward)
line := s.get(client, http.StatusForbidden, requestlog.ActionRateLimited)
line := s.get(client, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
if line.LimitHit != minute || line.Offence != requestlog.OffenceLimit ||
line.BanExpires != expires {
t.Errorf("log line has limit_hit %q, offence %q and ban_expires %q, "+
@@ -51,7 +51,7 @@ func TestBrokenLimitBansTheClient(t *testing.T) {
// Every request while the ban lasts is refused.
clk.advance(time.Hour - time.Second)
line = s.get(client, http.StatusForbidden, requestlog.ActionBanned)
line = s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned)
if line.BanExpires != expires || line.Offence != "" || line.LimitHit != "" {
t.Errorf("log line has ban_expires %q, offence %q and limit_hit %q, "+
"want %s and neither of the others", line.BanExpires, line.Offence,
@@ -78,7 +78,9 @@ func TestBanLengthsFollowTheSettings(t *testing.T) {
breakLimit := func() string {
s.get(client, http.StatusOK, requestlog.ActionForward)
return s.get(client, http.StatusForbidden, requestlog.ActionRateLimited).BanExpires
line := s.get(client, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
return line.BanExpires
}
wantExpires := func(got string, length time.Duration) {
t.Helper()
@@ -111,7 +113,7 @@ func TestBanLengthsFollowTheSettings(t *testing.T) {
}
clk.advance(365 * 24 * time.Hour)
s.get(client, http.StatusForbidden, requestlog.ActionBanned)
s.get(client, http.StatusForbidden, requestlog.ActionPermanentlyBanned)
}
func TestBanIsNotCountedAndResetsTheCounters(t *testing.T) {
@@ -123,10 +125,10 @@ func TestBanIsNotCountedAndResetsTheCounters(t *testing.T) {
// client for an hour.
s.get(client, http.StatusOK, requestlog.ActionForward)
s.get(client, http.StatusOK, requestlog.ActionForward)
s.get(client, http.StatusForbidden, requestlog.ActionRateLimited)
s.get(client, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
for range 3 {
s.get(client, http.StatusForbidden, requestlog.ActionBanned)
s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned)
}
// Later the same day the client has its whole allowance again: the
@@ -135,7 +137,7 @@ func TestBanIsNotCountedAndResetsTheCounters(t *testing.T) {
clk.advance(time.Hour)
s.get(client, http.StatusOK, requestlog.ActionForward)
s.get(client, http.StatusOK, requestlog.ActionForward)
s.get(client, http.StatusForbidden, requestlog.ActionRateLimited)
s.get(client, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
banned := server.Ledger.Bans(netip.MustParsePrefix(client + "/32"))
if len(banned) != 2 || banned[0].Notes.Refused != 3 {
@@ -190,10 +192,10 @@ func TestBanCoversTheClientsNetblock(t *testing.T) {
s, _, _ := startWithClock(t, "", env)
s.get(tc.breaker, http.StatusOK, requestlog.ActionForward)
s.get(tc.breaker, http.StatusForbidden, requestlog.ActionRateLimited)
s.get(tc.breaker, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
for _, sent := range tc.refused {
s.get(sent, http.StatusForbidden, requestlog.ActionBanned)
s.get(sent, http.StatusForbidden, requestlog.ActionTemporarilyBanned)
}
for _, sent := range tc.let {
@@ -216,9 +218,9 @@ func TestBannedClientIsRefusedBeforeItsCountryIsLookedUp(t *testing.T) {
// fromDE's ban covers otherClient, which is refused unasked about.
s.get(fromDE, http.StatusOK, requestlog.ActionForward)
s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited)
s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
line := s.get(otherClient, http.StatusForbidden, requestlog.ActionBanned)
line := s.get(otherClient, http.StatusForbidden, requestlog.ActionTemporarilyBanned)
if line.Country != "" {
t.Errorf("log line has country %q, want none", line.Country)
}
@@ -237,9 +239,9 @@ func TestRefusalUnderABanNamesItsHeuristicNetblockAndEnd(t *testing.T) {
expires := requestlog.FormatTime(clk.Now().Add(time.Hour))
s.get(client, http.StatusOK, requestlog.ActionForward)
s.get(client, http.StatusForbidden, requestlog.ActionRateLimited)
s.get(client, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
line := s.get(otherClient, http.StatusForbidden, requestlog.ActionBanned)
line := s.get(otherClient, http.StatusForbidden, requestlog.ActionTemporarilyBanned)
wantHeuristic(t, line, "active_ban",
`{"netblock": "`+clientsNet+`", "ban_expires": "`+expires+`"}`)
}
@@ -275,11 +277,11 @@ func TestBanResponseAnswersEveryRefusalButTheSizeLimits(t *testing.T) {
s, _, _ := startWithClock(t, geojsURL, env)
s.get(denied, tc.status, requestlog.ActionDenied)
s.get(fromKP, tc.status, requestlog.ActionDenied)
s.get(denied, tc.status, requestlog.ActionClientDenied)
s.get(fromKP, tc.status, requestlog.ActionClientDenied)
s.get(fromDE, http.StatusOK, requestlog.ActionForward)
s.get(fromDE, tc.status, requestlog.ActionRateLimited)
s.get(fromDE, tc.status, requestlog.ActionBanned)
s.get(fromDE, tc.status, requestlog.ActionClientIsRateLimited)
s.get(fromDE, tc.status, requestlog.ActionTemporarilyBanned)
})
}
}
@@ -297,9 +299,9 @@ func TestBanNotes(t *testing.T) {
s.get(fromDE, http.StatusOK, requestlog.ActionForward)
s.request(fromDE, "/repo/commits?page=2",
http.StatusForbidden, requestlog.ActionRateLimited)
s.get(fromDE, http.StatusForbidden, requestlog.ActionBanned)
s.get(fromDE, http.StatusForbidden, requestlog.ActionBanned)
http.StatusForbidden, requestlog.ActionClientIsRateLimited)
s.get(fromDE, http.StatusForbidden, requestlog.ActionTemporarilyBanned)
s.get(fromDE, http.StatusForbidden, requestlog.ActionTemporarilyBanned)
netblock := netip.MustParsePrefix(fromDE + "/32")
want := bans.Ban{
@@ -342,7 +344,7 @@ func TestBanNotes(t *testing.T) {
// The next ban counts this one among the earlier.
clk.advance(time.Hour)
s.get(fromDE, http.StatusOK, requestlog.ActionForward)
s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited)
s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
got = ledger.Bans(netblock)
if len(got) != 2 || got[1].Notes.EarlierBans != (bans.EarlierBans{Limit: 1}) {
@@ -360,12 +362,12 @@ func TestMaxBansDropsTheBanOfTheNetblockSeenLongestAgo(t *testing.T) {
// One ban is held, so otherClient's ban drops client's.
s.get(client, http.StatusOK, requestlog.ActionForward)
s.get(client, http.StatusForbidden, requestlog.ActionRateLimited)
s.get(client, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
s.get(otherClient, http.StatusOK, requestlog.ActionForward)
s.get(otherClient, http.StatusForbidden, requestlog.ActionRateLimited)
s.get(otherClient, http.StatusForbidden, requestlog.ActionClientIsRateLimited)
s.get(client, http.StatusOK, requestlog.ActionForward)
s.get(otherClient, http.StatusForbidden, requestlog.ActionBanned)
s.get(otherClient, http.StatusForbidden, requestlog.ActionTemporarilyBanned)
}
// clock is the time a test sets, by which sww counts requests and