From d8fefb1288ae5f26e9b22a1e6e2a3461ed2883fe Mon Sep 17 00:00:00 2001 From: sneak Date: Mon, 9 Nov 2026 03:43:24 +0000 Subject: [PATCH] Name request log actions so they say what they mean (closes #229) Rename too_large, rate_limited, rule_blocked and denied, and split banned into temporarily_banned and permanently_banned by whether the ban runs out. A client under both a temporary and a permanent ban gets the permanent one. A request that makes a ban permanent gets permanently_banned. A ban rule, a trap path or a CrowdSec decision gets the value for the ban it makes, and in observe mode would_action names the ban enforce mode would have made. The offence kind rule_blocked follows, as a metric label and a key in clients.json. Model: opus-5-5 --- README.md | 2 +- SPEC.md | 20 ++-- docs/request-log.md | 16 +-- docs/state-files.md | 5 +- internal/bans/admin_test.go | 45 ++++++++ internal/bans/bans.go | 36 +++++-- internal/discriminator/abuseipdb.go | 2 +- internal/discriminator/admin_test.go | 4 +- internal/discriminator/alerts_test.go | 16 +-- internal/discriminator/anomaly_test.go | 2 +- internal/discriminator/answertime_test.go | 38 ++++--- internal/discriminator/bans.go | 32 ++++-- internal/discriminator/bans_test.go | 50 ++++----- internal/discriminator/biased_test.go | 14 +-- internal/discriminator/blocklists.go | 2 +- internal/discriminator/bytelimits.go | 4 +- internal/discriminator/bytelimits_test.go | 12 +-- internal/discriminator/coreruleset_test.go | 7 +- internal/discriminator/crowdsec.go | 3 +- internal/discriminator/crowdsec_test.go | 14 +-- internal/discriminator/denynets.go | 2 +- internal/discriminator/discriminator_test.go | 18 ++-- internal/discriminator/dnsbl.go | 2 +- internal/discriminator/headerlimits.go | 2 +- internal/discriminator/history_test.go | 4 +- internal/discriminator/lookup_test.go | 6 +- internal/discriminator/metrics_test.go | 8 +- internal/discriminator/observe_test.go | 102 ++++++++++++++++-- internal/discriminator/ratelimits.go | 4 +- internal/discriminator/ratelimits_test.go | 19 ++-- internal/discriminator/refusallimit.go | 8 +- internal/discriminator/refusallimit_test.go | 32 ++++-- internal/discriminator/reputation_test.go | 42 ++++---- internal/discriminator/request.go | 31 +++--- internal/discriminator/routewatchtags_test.go | 6 +- internal/discriminator/rulefiles.go | 17 +-- internal/discriminator/rulefiles_test.go | 42 ++++---- internal/discriminator/staticlists_test.go | 16 +-- internal/discriminator/tagdeny.go | 2 +- internal/discriminator/tagdeny_test.go | 12 +-- internal/discriminator/taglists_test.go | 6 +- internal/discriminator/trappaths.go | 4 +- internal/discriminator/trappaths_test.go | 14 +-- internal/metrics/metrics.go | 8 +- internal/ratelimit/ratelimit.go | 28 ++--- internal/requestlog/requestlog.go | 43 ++++---- internal/sww/sww_test.go | 11 +- script/example-app | 9 +- 48 files changed, 522 insertions(+), 300 deletions(-) diff --git a/README.md b/README.md index e70ade3..3d9ebdf 100644 --- a/README.md +++ b/README.md @@ -173,7 +173,7 @@ does. the request have `"action":"forward"`. - To see a refusal without banning yourself, run `discriminator` with `SWW_MODE=observe` and ask for `/.env`. The request reaches the app. - `discriminator`'s log lines have `"would_action":"banned"` and + `discriminator`'s log lines have `"would_action":"temporarily_banned"` and `"rule_ids":["env-file"]`. A ban you get in `enforce` mode is lifted as "Clients and bans" below describes. - With `SWW_METRICS_TOKEN` set, this answers with the metrics, from a host on diff --git a/SPEC.md b/SPEC.md index 265cad2..1371cc8 100644 --- a/SPEC.md +++ b/SPEC.md @@ -321,6 +321,13 @@ ban is dropped alike. A scanner whose ban was dropped that way is refused and banned again by its next probe. A ban whose cause is `admin` is never dropped and does not count toward `SWW_MAX_BANS`, so such bans can never fill the table. +A request refused under a ban that runs out is logged with the action +`temporarily_banned`. Under a permanent ban the action is `permanently_banned`. +A request refused for a clear sign of attack or a CrowdSec decision takes the +action for the ban it made. A request that makes a ban permanent is logged as +`permanently_banned`. A request over a rate limit is logged as +`client_is_rate_limited`, whichever ban it makes. + ## Settings `docs/settings.md` lists every setting with its default and the values it takes, @@ -580,9 +587,10 @@ lower case, except a country code, which is in capitals. `SWW_TAG_DENY` and Two settings act on tags: -- `SWW_TAG_DENY` lists tags whose requests are refused with the action `denied` - (`tag_deny`). The check runs twice: just before the rate limits, and again - after the Core Rule Set, so that `exploitsignature` can refuse too. +- `SWW_TAG_DENY` lists tags whose requests are refused with the action + `client_denied` (`tag_deny`). The check runs twice: just before the rate + limits, and again after the Core Rule Set, so that `exploitsignature` can + refuse too. - `SWW_TAG_LIMIT_PERCENT` lists tags with a percentage from 1 to 99. Their clients get that percentage of every request and byte limit. The lowest percentage among a client's tags applies. `exploitsignature` cannot be listed, @@ -1338,9 +1346,9 @@ over either one: `Transfer-Encoding` do not count. `X-Request-ID` and `X-Forwarded-Proto` do. Real clients never reach these limits. The answer is `deny` with `431`, and the -log line's action is `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. +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. 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 diff --git a/docs/request-log.md b/docs/request-log.md index 8887203..19f5377 100644 --- a/docs/request-log.md +++ b/docs/request-log.md @@ -96,13 +96,15 @@ Every one of these lines has: - `action`: what was done: - `forward`: answered `allow`, so that `rproxy` passes it to the app; - - `denied`: refused for `SWW_DENY_NETS`, for a reputation source with the - action `deny`, or for a tag in `SWW_TAG_DENY`; - - `banned`: refused under a ban, or for a `ban` rule, a trap path or a - CrowdSec decision, each of which bans the client; - - `country_denied`, `rate_limited`, `rule_blocked` and `waf_blocked`: - refused by that check; - - `too_large`: over a header limit; + - `client_denied`: refused for `SWW_DENY_NETS`, for a reputation source with + the action `deny`, or for a tag in `SWW_TAG_DENY`; + - `temporarily_banned`: refused under a ban that runs out, or for a `ban` + rule, a trap path or a CrowdSec decision that made such a ban; + - `permanently_banned`: refused under a ban that never runs out, including a + ban this request made or made permanent; + - `country_denied`, `client_is_rate_limited`, `blocked_by_block_rule` and + `waf_blocked`: refused by that check; + - `request_header_too_large`: over a header limit; - `admin`: answered at one of `discriminator`'s own endpoints, or `404` for a path under `/_sww/`. - `would_action`: in `observe` mode, what `enforce` mode would have done with a diff --git a/docs/state-files.md b/docs/state-files.md index c8f1dc4..5a276c6 100644 --- a/docs/state-files.md +++ b/docs/state-files.md @@ -63,8 +63,9 @@ since it was first seen: - total requests, and how many were forwarded and how many refused; - body bytes of its requests, and of the responses it was sent; - responses by status class; -- offences by kind: `limit`, `attack`, `rule_blocked` and `waf_blocked`. A file - may also hold `token_refused`, which is kept, and which nothing adds to. +- offences by kind: `limit`, `attack`, `blocked_by_block_rule` and + `waf_blocked`. A file may also hold `token_refused`, which is kept, and which + nothing adds to. ## `lookups.json` diff --git a/internal/bans/admin_test.go b/internal/bans/admin_test.go index e695dad..cff7cdc 100644 --- a/internal/bans/admin_test.go +++ b/internal/bans/admin_test.go @@ -341,3 +341,48 @@ func TestLiftLiftsEveryActiveBanCoveringTheClient(t *testing.T) { wantChanged(t, ledger, false) } + +func TestPermanentBanOnAWiderNetblockIsReturnedOverATemporaryBan(t *testing.T) { + t.Parallel() + + client := netip.MustParseAddr("203.0.113.9") + ledger := bans.New(defaultRules()) + + // The temporary ban is made first, so that its netblock is looked at first. + ledger.BanForLimit(netip.MustParsePrefix("203.0.113.9/32"), midnight(), bans.Notes{}) + ledger.BanForAdmin(netip.MustParsePrefix("203.0.113.0/24"), midnight(), time.Time{}, + "for good") + + wantPermanentBan(t, ledger, client, midnight().Add(time.Minute)) +} + +func TestOlderPermanentBanIsReturnedOverANewerTemporaryBan(t *testing.T) { + t.Parallel() + + netblock := netip.MustParsePrefix("203.0.113.0/24") + ledger := bans.New(defaultRules()) + + ledger.BanForAdmin(netblock, midnight(), time.Time{}, "for good") + ledger.BanForAdmin(netblock, midnight().Add(time.Minute), midnight().Add(time.Hour), + "for an hour") + + wantPermanentBan(t, ledger, netblock.Addr(), midnight().Add(2*time.Minute)) +} + +// wantPermanentBan checks that Find and Check return a permanent ban for +// client at now. +func wantPermanentBan( + t *testing.T, ledger *bans.Ledger, client netip.Addr, now time.Time, +) { + t.Helper() + + for name, look := range map[string]func(netip.Addr, time.Time) (bans.Ban, bool, bool){ + "Find": ledger.Find, + "Check": ledger.Check, + } { + ban, banned, _ := look(client, now) + if !banned || !ban.Permanent() { + t.Errorf("%s returned %+v and banned %v, want a permanent ban", name, ban, banned) + } + } +} diff --git a/internal/bans/bans.go b/internal/bans/bans.go index 9256b3f..e794135 100644 --- a/internal/bans/bans.go +++ b/internal/bans/bans.go @@ -274,16 +274,27 @@ func (l *Ledger) Find(client netip.Addr, now time.Time) (Ban, bool, bool) { // activeBan returns the ban in bans, a netblock's bans oldest first, that // is active at now, or nil when none is. If several are, it returns the -// one that started last. Every ban is looked at, since a ban an admin adds -// to bans.json can start before the netblock's others and outlast them. +// newest permanent one, or the newest when none is permanent. Every ban is +// looked at, since a ban an admin adds to bans.json can start before the +// netblock's others and outlast them. func activeBan(bans []Ban, now time.Time) *Ban { + var newest *Ban + for i := len(bans) - 1; i >= 0; i-- { - if bans[i].ActiveAt(now) { + if !bans[i].ActiveAt(now) { + continue + } + + if bans[i].Permanent() { return &bans[i] } + + if newest == nil { + newest = &bans[i] + } } - return nil + return newest } // BanForLimit bans netblock at now for a broken limit, with notes, and @@ -743,13 +754,16 @@ func (l *Ledger) markChanged() { } // active returns the ban active at now on a netblock client is in, or -// nil. +// nil. If several netblocks have one, it returns a permanent ban when +// there is one. func (l *Ledger) active(client netip.Addr, now time.Time) *Ban { lengths := l.v6Lengths if client.Is4() { lengths = l.v4Lengths } + var first *Ban + for _, length := range lengths { bans, found := l.netblocks.Get(netip.PrefixFrom(client, length).Masked()) if !found { @@ -757,12 +771,20 @@ func (l *Ledger) active(client netip.Addr, now time.Time) *Ban { } ban := activeBan(*bans, now) - if ban != nil { + if ban == nil { + continue + } + + if ban.Permanent() { return ban } + + if first == nil { + first = ban + } } - return nil + return first } // covering returns the bans of each netblock held that client is in, diff --git a/internal/discriminator/abuseipdb.go b/internal/discriminator/abuseipdb.go index 9f87a39..0edcc58 100644 --- a/internal/discriminator/abuseipdb.go +++ b/internal/discriminator/abuseipdb.go @@ -50,7 +50,7 @@ func (abuseIPDB) check(ctx context.Context, rq *request, _ time.Time) *verdict { } return &verdict{ - action: requestlog.ActionDenied, + action: requestlog.ActionClientDenied, figures: map[string]any{ figureScore: score, "min_score": rq.h.config.AbuseIPDBMinScore, }, diff --git a/internal/discriminator/admin_test.go b/internal/discriminator/admin_test.go index 0e61f25..45dec54 100644 --- a/internal/discriminator/admin_test.go +++ b/internal/discriminator/admin_test.go @@ -121,7 +121,7 @@ func TestBanAddedListedAndLiftedThroughTheEndpoints(t *testing.T) { wantBans(t, s.admin(http.MethodPost, discriminator.BansPath, banOtherClient, http.StatusOK), want) - line := s.get(client, http.StatusForbidden, requestlog.ActionBanned) + line := s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) if line.BanExpires != requestlog.FormatTime(expires) { t.Errorf("the ban ends at %s, want %s", line.BanExpires, expires) } @@ -276,7 +276,7 @@ func TestClientEndpointShowsTheClientAndItsBans(t *testing.T) { // limit of two a minute, and bans it. s.get(otherClient, http.StatusOK, requestlog.ActionForward) s.get(otherClient, http.StatusOK, requestlog.ActionForward) - s.get(otherClient, http.StatusForbidden, requestlog.ActionRateLimited) + s.get(otherClient, http.StatusForbidden, requestlog.ActionClientIsRateLimited) // Asked about by its address in IPv6 form too. for _, addr := range []string{otherClient, "::ffff:" + otherClient} { diff --git a/internal/discriminator/alerts_test.go b/internal/discriminator/alerts_test.go index 5dbdf6b..4370aad 100644 --- a/internal/discriminator/alerts_test.go +++ b/internal/discriminator/alerts_test.go @@ -31,14 +31,14 @@ func TestBanForABrokenLimitRaisesABanAlertWithItsNotes(t *testing.T) { start := clk.Now() s.get(client, http.StatusOK, requestlog.ActionForward) - s.get(client, http.StatusForbidden, requestlog.ActionRateLimited) + s.get(client, http.StatusForbidden, requestlog.ActionClientIsRateLimited) netblock := netip.MustParsePrefix("203.0.113.0/24") ban := server.Ledger.Bans(netblock)[0] // A request refused under the ban raises no other alert. clk.advance(time.Minute) - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) wantAlerts(t, queue, banAlert(alerts.EventBan, start, client, bans.Ban{ Netblock: netblock, Cause: bans.CauseLimit, @@ -62,22 +62,24 @@ func TestAttackBanRaisesABanAlertThenAPermanentBanAlert(t *testing.T) { // The probe bans the client for seven days, and its next request makes // the ban permanent. The request after that changes nothing. - s.request(client, "/.env", http.StatusForbidden, requestlog.ActionBanned) + s.request(client, "/.env", http.StatusForbidden, requestlog.ActionTemporarilyBanned) attackBan := server.Ledger.Bans(netblock)[0] clk.advance(time.Minute) - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, requestlog.ActionPermanentlyBanned) permanentBan := server.Ledger.Bans(netblock)[0] - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, requestlog.ActionPermanentlyBanned) // Another client's probe after its first ban has run out without a // request makes a permanent ban at once. - s.request(otherClient, "/.env", http.StatusForbidden, requestlog.ActionBanned) + s.request(otherClient, "/.env", http.StatusForbidden, + requestlog.ActionTemporarilyBanned) clk.advance(7 * 24 * time.Hour) - s.request(otherClient, "/.env", http.StatusForbidden, requestlog.ActionBanned) + s.request(otherClient, "/.env", http.StatusForbidden, + requestlog.ActionPermanentlyBanned) otherBans := server.Ledger.Bans(other) diff --git a/internal/discriminator/anomaly_test.go b/internal/discriminator/anomaly_test.go index 7ea5066..4c0c5a8 100644 --- a/internal/discriminator/anomaly_test.go +++ b/internal/discriminator/anomaly_test.go @@ -187,7 +187,7 @@ func TestEveryRequestIsCountedWhateverIsDoneWithIt(t *testing.T) { {allowed, "/", http.StatusOK, requestlog.ActionForward}, {exempt, "/", http.StatusOK, requestlog.ActionForward}, {client, "/static/app.js", http.StatusOK, requestlog.ActionForward}, - {denied, "/", http.StatusForbidden, requestlog.ActionDenied}, + {denied, "/", http.StatusForbidden, requestlog.ActionClientDenied}, } { for range 3 { s.request(sent.from, sent.path, sent.status, sent.action) diff --git a/internal/discriminator/answertime_test.go b/internal/discriminator/answertime_test.go index b7e4c02..40d8c87 100644 --- a/internal/discriminator/answertime_test.go +++ b/internal/discriminator/answertime_test.go @@ -84,7 +84,7 @@ func TestSixteenThousandCookiesAreRefusedWellWithinTheTimeLimit(t *testing.T) { wantDisposition(t, got, tooLarge, discriminator.DispositionDeny) line := s.out.requestLine(t) - wantLine(t, line, tooLarge, requestlog.ActionTooLarge) + wantLine(t, line, tooLarge, requestlog.ActionRequestHeaderTooLarge) if line.DurationWAF != nil { t.Errorf("the Core Rule Set read the request, for %f ms", *line.DurationWAF) @@ -157,7 +157,7 @@ func TestEachHeaderLimitRefusesARequestOverIt(t *testing.T) { if tc.refused { wantDisposition(t, got, tooLarge, discriminator.DispositionDeny) - wantLine(t, line, tooLarge, requestlog.ActionTooLarge) + wantLine(t, line, tooLarge, requestlog.ActionRequestHeaderTooLarge) return } @@ -219,9 +219,10 @@ func TestObserveModeAllowsARequestOverTheHeaderLimitsUnread(t *testing.T) { wantDisposition(t, got, http.StatusOK, discriminator.DispositionAllow) line := s.out.requestLine(t) - if line.WouldAction != requestlog.ActionTooLarge || line.DurationWAF != nil { + if line.WouldAction != requestlog.ActionRequestHeaderTooLarge || + line.DurationWAF != nil { t.Errorf("would_action %q and duration_waf %v, want %q and none", - line.WouldAction, line.DurationWAF, requestlog.ActionTooLarge) + line.WouldAction, line.DurationWAF, requestlog.ActionRequestHeaderTooLarge) } } @@ -240,7 +241,7 @@ func TestRequestsOverTheHeaderLimitsCountTowardTheRateLimits(t *testing.T) { wantDisposition(t, ask(), http.StatusForbidden, discriminator.DispositionDeny) lines := s.out.requestLines(t, 2) - wantLine(t, lines[1], http.StatusForbidden, requestlog.ActionRateLimited) + wantLine(t, lines[1], http.StatusForbidden, requestlog.ActionClientIsRateLimited) } func TestTheHeaderLimitsComeAfterTheTrapPathsAndTheRuleFiles(t *testing.T) { @@ -249,8 +250,8 @@ func TestTheHeaderLimitsComeAfterTheTrapPathsAndTheRuleFiles(t *testing.T) { for _, tc := range []struct { name, path, action string }{ - {"a trap path", "/wp-login.php", requestlog.ActionBanned}, - {"a block rule", "/blocked", requestlog.ActionRuleBlocked}, + {"a trap path", "/wp-login.php", requestlog.ActionTemporarilyBanned}, + {"a block rule", "/blocked", requestlog.ActionBlockedByBlockRule}, } { t.Run(tc.name, func(t *testing.T) { t.Parallel() @@ -280,7 +281,7 @@ func TestNotWaitingForGeoJSNeverLowersAClientsLimit(t *testing.T) { wantDisposition(t, do(t, req), tooLarge, discriminator.DispositionDeny) line := s.out.requestLine(t) - wantLine(t, line, tooLarge, requestlog.ActionTooLarge) + wantLine(t, line, tooLarge, requestlog.ActionRequestHeaderTooLarge) if line.LimitPercent != nil { t.Errorf("limit percentage %d, want none", *line.LimitPercent) @@ -304,7 +305,8 @@ func TestAClientGeoJSPlacedInNoCountryCountsAsUnknownWithoutWaiting(t *testing.T req.Header.Set(cookieHeader, cookies(cookieLimit+1)) wantDisposition(t, do(t, req), http.StatusForbidden, discriminator.DispositionDeny) - wantLine(t, s.out.requestLine(t), http.StatusForbidden, requestlog.ActionRateLimited) + wantLine(t, s.out.requestLine(t), http.StatusForbidden, + requestlog.ActionClientIsRateLimited) } func TestObserveModeWaitsForGeoJSForARequestOverTheHeaderLimits(t *testing.T) { @@ -412,33 +414,37 @@ func TestARefusedRequestDoesNotWaitForASlowGeoJS(t *testing.T) { }{ { name: "SWW_DENY_NETS", env: map[string]string{denyNets: client}, - prepare: leaveAsItIs, status: forbidden, action: requestlog.ActionDenied, + prepare: leaveAsItIs, status: forbidden, action: requestlog.ActionClientDenied, }, { name: "a ban", - prepare: banClient, status: forbidden, action: requestlog.ActionBanned, + prepare: banClient, status: forbidden, action: requestlog.ActionTemporarilyBanned, }, { name: "the rate limits", env: map[string]string{rateLimitPerMinute: "1"}, - prepare: countClient, status: forbidden, action: requestlog.ActionRateLimited, + prepare: countClient, status: forbidden, + action: requestlog.ActionClientIsRateLimited, }, { name: "the rate limits, with a biased threshold", env: map[string]string{rateLimitPerMinute: "1", unknownLimitPercent: "50"}, - prepare: countClient, status: forbidden, action: requestlog.ActionRateLimited, + prepare: countClient, status: forbidden, + action: requestlog.ActionClientIsRateLimited, }, { name: "a blocklist", env: map[string]string{blocklistURLs: dropURL}, - prepare: listClient, status: forbidden, action: requestlog.ActionDenied, + prepare: listClient, status: forbidden, action: requestlog.ActionClientDenied, }, { name: "the CrowdSec decision list", env: map[string]string{crowdSecURL: lapi, crowdSecKey: bouncerKey}, - prepare: decideOnClient, status: forbidden, action: requestlog.ActionBanned, + prepare: decideOnClient, status: forbidden, + action: requestlog.ActionTemporarilyBanned, }, { name: "the header limits", cookie: cookies(cookieLimit + 1), - prepare: leaveAsItIs, status: tooLarge, action: requestlog.ActionTooLarge, + prepare: leaveAsItIs, status: tooLarge, + action: requestlog.ActionRequestHeaderTooLarge, }, } { t.Run(tc.name, func(t *testing.T) { diff --git a/internal/discriminator/bans.go b/internal/discriminator/bans.go index 251cd5e..dbc7334 100644 --- a/internal/discriminator/bans.go +++ b/internal/discriminator/bans.go @@ -50,13 +50,23 @@ func (activeBan) check(_ context.Context, rq *request, now time.Time) *verdict { } return &verdict{ - action: requestlog.ActionBanned, + action: banAction(ban.Permanent()), figures: map[string]any{ figureNetblock: ban.Netblock.String(), "ban_expires": rq.line.BanExpires, }, } } +// banAction is the action of a request refused under a ban or for making one: +// permanent says the ban never runs out. +func banAction(permanent bool) string { + if permanent { + return requestlog.ActionPermanentlyBanned + } + + return requestlog.ActionTemporarilyBanned +} + // limitFigures are the figures of a heuristic that broke hit, a limit: its // window, the count and the limit. func limitFigures(hit ratelimit.Hit) map[string]any { @@ -151,11 +161,11 @@ func (rq *request) banForLimit(now time.Time, hit ratelimit.Hit, status int) { // attack, which notes name: the ban rule that matched, or the trap path // asked for. It fills in the rest of the notes. In observe mode it makes // no ban, and raises the alert for the ban it would have made, if that -// alert would be sent. -func (rq *request) banForAttack(now time.Time, notes bans.Notes) { +// alert would be sent. It returns the action for that ban. +func (rq *request) banForAttack(now time.Time, notes bans.Notes) string { netblock := rq.h.netblock(rq.client) if rq.h.config.Observe && !rq.wouldAlertBan(netblock, now, bans.CauseAttack) { - return + return banAction(rq.h.ledger.WouldBePermanent(netblock, now, bans.CauseAttack)) } notes.ASN = rq.line.ASN @@ -171,7 +181,7 @@ func (rq *request) banForAttack(now time.Time, notes bans.Notes) { rq.alertBan(ban) } - return + return banAction(ban.Permanent()) } ban, made := rq.h.ledger.BanForAttack(netblock, now, notes) @@ -180,16 +190,18 @@ func (rq *request) banForAttack(now time.Time, notes bans.Notes) { if made { rq.alertBan(ban) } + + return banAction(ban.Permanent()) } // banForCrowdSec bans the client's netblock at now until decision, // CrowdSec's decision on the client, ends. In observe mode it makes no // ban, and raises the alert for the ban it would have made, if that alert -// would be sent. -func (rq *request) banForCrowdSec(now time.Time, decision reputation.Decision) { +// would be sent. It returns the action for that ban. +func (rq *request) banForCrowdSec(now time.Time, decision reputation.Decision) string { netblock := rq.h.netblock(rq.client) if rq.h.config.Observe && !rq.wouldAlertBan(netblock, now, bans.CauseCrowdSec) { - return + return banAction(rq.h.ledger.WouldBePermanent(netblock, now, bans.CauseCrowdSec)) } notes := bans.Notes{ @@ -208,7 +220,7 @@ func (rq *request) banForCrowdSec(now time.Time, decision reputation.Decision) { rq.alertBan(ban) } - return + return banAction(ban.Permanent()) } ban, made := rq.h.ledger.BanForCrowdSec(netblock, now, decision.Expires, @@ -218,6 +230,8 @@ func (rq *request) banForCrowdSec(now time.Time, decision reputation.Decision) { if made { rq.alertBan(ban) } + + return banAction(ban.Permanent()) } // wouldAlertBan reports whether the alert for a ban on netblock for cause diff --git a/internal/discriminator/bans_test.go b/internal/discriminator/bans_test.go index 9875a14..5b75749 100644 --- a/internal/discriminator/bans_test.go +++ b/internal/discriminator/bans_test.go @@ -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 diff --git a/internal/discriminator/biased_test.go b/internal/discriminator/biased_test.go index 81e4bac..bbc46b5 100644 --- a/internal/discriminator/biased_test.go +++ b/internal/discriminator/biased_test.go @@ -76,7 +76,7 @@ func TestEachBiasedThresholdLowersTheRateLimits(t *testing.T) { }{ {http.StatusOK, requestlog.ActionForward}, {http.StatusOK, requestlog.ActionForward}, - {http.StatusForbidden, requestlog.ActionRateLimited}, + {http.StatusForbidden, requestlog.ActionClientIsRateLimited}, } { line := s.get(tc.from, sent.status, sent.action) wantPercent(t, "limit_percent", line.LimitPercent, line.LimitPercentSetting, @@ -192,7 +192,7 @@ func TestZeroPercentIsAZeroAllowance(t *testing.T) { // The first request breaks the limit, and bans the client; the log line // gives the 0. - line := s.get(unplaced, http.StatusForbidden, requestlog.ActionRateLimited) + line := s.get(unplaced, http.StatusForbidden, requestlog.ActionClientIsRateLimited) if line.fields["limit_percent"] != float64(0) || line.fields["limit_percent_setting"] != unknownLimitPercent { t.Errorf("log line has limit_percent %v from %v, want 0 from %s", @@ -200,7 +200,7 @@ func TestZeroPercentIsAZeroAllowance(t *testing.T) { unknownLimitPercent) } - s.get(unplaced, http.StatusForbidden, requestlog.ActionBanned) + s.get(unplaced, http.StatusForbidden, requestlog.ActionTemporarilyBanned) } func TestLowestPercentageApplies(t *testing.T) { @@ -250,7 +250,7 @@ func TestLowestPercentageApplies(t *testing.T) { // A quarter of 4 requests a minute: the second breaks the limit. s.get(tc.from, http.StatusOK, requestlog.ActionForward) - line := s.get(tc.from, http.StatusForbidden, requestlog.ActionRateLimited) + line := s.get(tc.from, http.StatusForbidden, requestlog.ActionClientIsRateLimited) wantPercent(t, "limit_percent", line.LimitPercent, line.LimitPercentSetting, tc.want) }) @@ -269,7 +269,7 @@ func TestUnknownLimitPercentGivesEveryClientWithoutACountryItsPercentage(t *test for _, from := range []string{unplaced, "10.0.0.8"} { s.get(from, http.StatusOK, requestlog.ActionForward) s.get(from, http.StatusOK, requestlog.ActionForward) - s.get(from, http.StatusForbidden, requestlog.ActionRateLimited) + s.get(from, http.StatusForbidden, requestlog.ActionClientIsRateLimited) } // One in a country has the whole limit. @@ -293,7 +293,7 @@ func TestClientWithoutAnAnswerInTimeHasTheUnknownLimitPercent(t *testing.T) { serveFromDE(t, server, http.MethodGet, http.NoBody) line := out.requestLine(t) - wantLine(t, line, http.StatusForbidden, requestlog.ActionRateLimited) + wantLine(t, line, http.StatusForbidden, requestlog.ActionClientIsRateLimited) wantPercent(t, "limit_percent", line.LimitPercent, line.LimitPercentSetting, "0 from "+unknownLimitPercent) }) @@ -374,7 +374,7 @@ func TestBanForALoweredLimitGivesThePercentageInItsNotesAndItsAlert(t *testing.T // A quarter of 12 requests a minute is 3: the fourth breaks it. "a rate limit", map[string]string{rateLimitPerMinute: "12", tagLimitPercent: asnTagDEQuarter}, - 3, http.StatusForbidden, requestlog.ActionRateLimited, + 3, http.StatusForbidden, requestlog.ActionClientIsRateLimited, "requests per minute over the limit of 3", "25 from " + tagLimitPercent, }, { diff --git a/internal/discriminator/blocklists.go b/internal/discriminator/blocklists.go index 433d0f6..fae5b0d 100644 --- a/internal/discriminator/blocklists.go +++ b/internal/discriminator/blocklists.go @@ -28,7 +28,7 @@ func (blocklists) check(_ context.Context, rq *request, _ time.Time) *verdict { } return &verdict{ - action: requestlog.ActionDenied, + action: requestlog.ActionClientDenied, figures: map[string]any{"lists": listedBy}, } } diff --git a/internal/discriminator/bytelimits.go b/internal/discriminator/bytelimits.go index 24ddc53..1e81417 100644 --- a/internal/discriminator/bytelimits.go +++ b/internal/discriminator/bytelimits.go @@ -6,8 +6,6 @@ package discriminator import ( "context" "time" - - "sneak.berlin/go/smallwebwaf/internal/requestlog" ) // byteLimits counts the request's bytes, as countedBytes gives them, for the @@ -39,5 +37,5 @@ func (byteLimits) check(_ context.Context, rq *request, now time.Time) *verdict rq.banForLimit(now, hit, rq.out.status) - return &verdict{action: requestlog.ActionBanned, figures: limitFigures(hit)} + return &verdict{figures: limitFigures(hit)} } diff --git a/internal/discriminator/bytelimits_test.go b/internal/discriminator/bytelimits_test.go index 9070985..2170b0d 100644 --- a/internal/discriminator/bytelimits_test.go +++ b/internal/discriminator/bytelimits_test.go @@ -90,7 +90,7 @@ func TestEachByteLimitBansOnceTheResponseHasEnded(t *testing.T) { line.BanExpires, tc.window, expires) } - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) wantMetric(t, s.scrape(), `sww_rate_limit_hits_total{`+ `instance="`+alertInstance+`",kind="bytes",window="`+tc.window+`"}`, 1) @@ -125,7 +125,7 @@ func TestResponseOverAByteLimitByItselfIsPassedOnWhole(t *testing.T) { len(got.body), got.err, line.LimitHit, answerBytes, minuteBytes) } - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) } func TestBytesOfAnAnswerThatBreaksOffAreCounted(t *testing.T) { @@ -147,7 +147,7 @@ func TestBytesOfAnAnswerThatBreaksOffAreCounted(t *testing.T) { answerBytes, minuteBytes, expires) } - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) } func TestWebSocketBytesAreCountedOnceItCloses(t *testing.T) { @@ -176,7 +176,7 @@ func TestWebSocketBytesAreCountedOnceItCloses(t *testing.T) { line.LimitHit, line.Counts.MinuteBytes, minuteBytes, tc.counted) } - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) }) } } @@ -218,7 +218,7 @@ func TestBytesCountSaysWhichBytesCount(t *testing.T) { } } - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) }) } } @@ -386,7 +386,7 @@ func TestObserveModeLeavesOutTheBytesOfARequestEnforceModeRefuses(t *testing.T) // counted, and the byte limit is not broken. Its line gives the bytes // counted before it. line := s.upload() - wantWouldAction(t, line, requestlog.ActionRateLimited) + wantWouldAction(t, line, requestlog.ActionClientIsRateLimited) if line.LimitHit != minute || line.Counts.MinuteBytes != bodyBytes+answerBytes { t.Errorf("log line has limit_hit %q and minute_bytes %v, want minute and %d", diff --git a/internal/discriminator/coreruleset_test.go b/internal/discriminator/coreruleset_test.go index 054b457..a03f8e8 100644 --- a/internal/discriminator/coreruleset_test.go +++ b/internal/discriminator/coreruleset_test.go @@ -92,7 +92,8 @@ func TestDetectedAttackIsRefusedByTagDenyLast(t *testing.T) { wafMode: detect, tagDeny: "exploitsignature", }) - line := s.request(client, sqlInjection, http.StatusForbidden, requestlog.ActionDenied) + line := s.request(client, sqlInjection, http.StatusForbidden, + requestlog.ActionClientDenied) wantHeuristic(t, line, "tag_deny", `{"tag": "exploitsignature"}`) } @@ -195,7 +196,7 @@ func TestCoreRuleSetIsNotRunWhenOffOrForAnExemptClientPathOrRuleFileRefusal( // A request a rule file refuses is not inspected. line = s.request(otherClient, "/blocked?id=1'%20OR%20'1'='1", http.StatusForbidden, - requestlog.ActionRuleBlocked) + requestlog.ActionBlockedByBlockRule) wantWAF(t, line, nil) // With SWW_WAF_MODE off, no request is. @@ -403,7 +404,7 @@ func TestCoreRuleSetRefusalIsAnOffenceAndCountsTowardTheErrorBurst(t *testing.T) line.LimitHit, line.Offence) } - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) want := ratelimit.Offences{Limit: 1, WAFBlocked: 3} if offences := historyOf(t, server, client).Offences; offences != want { diff --git a/internal/discriminator/crowdsec.go b/internal/discriminator/crowdsec.go index 12ec1f1..6e1473f 100644 --- a/internal/discriminator/crowdsec.go +++ b/internal/discriminator/crowdsec.go @@ -30,10 +30,9 @@ func (crowdSec) check(_ context.Context, rq *request, now time.Time) *verdict { rq.addTag(config.CrowdSecTag) rq.noteHit(bans.ReputationHit{Source: rq.h.config.CrowdSecDecisionsURL}, "listed by the CrowdSec decision list") - rq.banForCrowdSec(now, decision) return &verdict{ - action: requestlog.ActionBanned, + action: rq.banForCrowdSec(now, decision), figures: map[string]any{ "scenario": decision.Scenario, "expires": requestlog.FormatTime(decision.Expires), diff --git a/internal/discriminator/crowdsec_test.go b/internal/discriminator/crowdsec_test.go index 9fd3e9e..8a63627 100644 --- a/internal/discriminator/crowdsec_test.go +++ b/internal/discriminator/crowdsec_test.go @@ -39,7 +39,7 @@ func TestClientTheCrowdSecDecisionListListsIsBannedUntilTheDecisionEnds(t *testi expires := requestlog.FormatTime(fetched.Add(4 * time.Hour)) // Its first request is refused, and bans it until the decision ends. - line := s.get(client, http.StatusForbidden, requestlog.ActionBanned) + line := s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) wantReputation(t, line, decisionsURL) if line.BanExpires != expires { @@ -72,7 +72,7 @@ func TestClientTheCrowdSecDecisionListListsIsBannedUntilTheDecisionEnds(t *testi // ban, and once it has ended the client is let through. clk.advance(4*time.Hour - time.Second) - line = s.get(client, http.StatusForbidden, requestlog.ActionBanned) + line = s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) wantReputation(t, line) if line.BanExpires != expires { @@ -105,7 +105,7 @@ func TestCrowdSecBanNamesItsHeuristicScenarioAndEnd(t *testing.T) { `"scenario": "crowdsecurity/ssh-bf", "scope": "Ip", "type": "ban", `+ `"value": "`+client+`"}]`) - line := s.get(client, http.StatusForbidden, requestlog.ActionBanned) + line := s.get(client, http.StatusForbidden, requestlog.ActionTemporarilyBanned) wantHeuristic(t, line, "crowdsec", `{"scenario": "crowdsecurity/ssh-bf", `+ `"expires": "`+requestlog.FormatTime(clk.Now().Add(4*time.Hour))+`"}`) wantTags(t, line, "crowdsec") @@ -129,9 +129,9 @@ func TestEndedCrowdSecDecisionNoLongerBansThoughTheCopyStillHoldsIt(t *testing.T // Just before its end, the decision bans a client in the netblock, and // one on an IPv6 address bans the address's group, the /64. clk.advance(time.Minute - time.Nanosecond) - s.get("198.51.100.7", http.StatusForbidden, requestlog.ActionBanned) - s.get("2001:db8::9", http.StatusForbidden, requestlog.ActionBanned) - s.get("2001:db8::5", http.StatusForbidden, requestlog.ActionBanned) + s.get("198.51.100.7", http.StatusForbidden, requestlog.ActionTemporarilyBanned) + s.get("2001:db8::9", http.StatusForbidden, requestlog.ActionTemporarilyBanned) + s.get("2001:db8::5", http.StatusForbidden, requestlog.ActionTemporarilyBanned) // Once it has ended, it bans no other client, and the bans it made end // with it. @@ -164,7 +164,7 @@ func TestObserveModeForwardsAClientTheCrowdSecDecisionListListsAndAlertsTheBan( `"value": "`+client+`"}]`) line := s.get(client, http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionBanned) + wantWouldAction(t, line, requestlog.ActionTemporarilyBanned) wantReputation(t, line, decisionsURL) if held := server.Ledger.Snapshot(); len(held) != 0 { diff --git a/internal/discriminator/denynets.go b/internal/discriminator/denynets.go index a23b6c0..41002e6 100644 --- a/internal/discriminator/denynets.go +++ b/internal/discriminator/denynets.go @@ -19,7 +19,7 @@ func (denyNets) check(_ context.Context, rq *request, _ time.Time) *verdict { for _, netblock := range rq.h.config.DenyNets { if netblock.Contains(rq.client) { return &verdict{ - action: requestlog.ActionDenied, + action: requestlog.ActionClientDenied, figures: map[string]any{figureNetblock: netblock.String()}, } } diff --git a/internal/discriminator/discriminator_test.go b/internal/discriminator/discriminator_test.go index b746940..22e103f 100644 --- a/internal/discriminator/discriminator_test.go +++ b/internal/discriminator/discriminator_test.go @@ -639,7 +639,7 @@ func TestQuestionDeniedGetsTheBanResponse(t *testing.T) { got := s.ask(client, "/") wantDisposition(t, got, status, discriminator.DispositionDeny) wantBody(t, got, http.StatusText(status)+"\n") - wantLine(t, s.out.requestLine(t), status, requestlog.ActionDenied) + wantLine(t, s.out.requestLine(t), status, requestlog.ActionClientDenied) }) } } @@ -655,8 +655,8 @@ func TestBanResponseCloseIsAnAnswerOfItsOwn(t *testing.T) { wantDisposition(t, got, http.StatusOK, discriminator.DispositionClose) wantBody(t, got, "") // The visitor is sent nothing. - wantLine(t, s.out.requestLine(t), 0, requestlog.ActionDenied) - wantMetric(t, s.metrics(), `sww_requests_total{action="denied",instance="`+ + wantLine(t, s.out.requestLine(t), 0, requestlog.ActionClientDenied) + wantMetric(t, s.metrics(), `sww_requests_total{action="client_denied",instance="`+ alertInstance+`",status_class="none"}`, 1) } @@ -671,12 +671,12 @@ func TestBlockRuleIsDeniedWith403AndABanRuleWithTheBanResponse(t *testing.T) { got := s.ask(client, "/blocked") wantDisposition(t, got, http.StatusForbidden, discriminator.DispositionDeny) wantLine(t, s.out.requestLine(t), http.StatusForbidden, - requestlog.ActionRuleBlocked) + requestlog.ActionBlockedByBlockRule) got = s.ask(client, "/.env") wantDisposition(t, got, http.StatusTooManyRequests, discriminator.DispositionDeny) wantLine(t, s.out.requestLines(t, 2)[1], http.StatusTooManyRequests, - requestlog.ActionBanned) + requestlog.ActionTemporarilyBanned) } func TestQuestionUnderTheOwnPrefixIsDeniedWith404AfterTheChecks(t *testing.T) { @@ -709,7 +709,7 @@ func TestObserveModeAllowsAndLogsWhatEnforceModeWouldHaveDone(t *testing.T) { line := s.out.requestLine(t) wantLine(t, line, http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionDenied) + wantWouldAction(t, line, requestlog.ActionClientDenied) } func TestObserveModeRefusalAnsweredAllowCountsForTheErrorBurst(t *testing.T) { @@ -894,7 +894,7 @@ func TestDeniedRequestIsFinishedAtItsDecision(t *testing.T) { t.Errorf("history is %+v, want the refused request alone", history) } - const series = `sww_requests_total{action="rate_limited",instance="` + + const series = `sww_requests_total{action="client_is_rate_limited",instance="` + alertInstance + `",status_class="4xx"}` wantMetric(t, s.metrics(), series, 1) @@ -1298,11 +1298,11 @@ func TestEveryDeniedRequestsReportGetsItsLastLine(t *testing.T) { }{ { "deny", map[string]string{denyNets: client}, "/", http.StatusForbidden, - requestlog.ActionDenied, + requestlog.ActionClientDenied, }, { "close", map[string]string{denyNets: client, banResponse: banResponseClose}, "/", - 0, requestlog.ActionDenied, + 0, requestlog.ActionClientDenied, }, {"own prefix", nil, discriminator.HealthPath, http.StatusNotFound, requestlog.ActionAdmin}, diff --git a/internal/discriminator/dnsbl.go b/internal/discriminator/dnsbl.go index 8c31da7..f00fd10 100644 --- a/internal/discriminator/dnsbl.go +++ b/internal/discriminator/dnsbl.go @@ -37,7 +37,7 @@ func (dnsbl) check(ctx context.Context, rq *request, _ time.Time) *verdict { } return &verdict{ - action: requestlog.ActionDenied, + action: requestlog.ActionClientDenied, figures: map[string]any{"zones": listedBy}, } } diff --git a/internal/discriminator/headerlimits.go b/internal/discriminator/headerlimits.go index 15be4b7..ff9345a 100644 --- a/internal/discriminator/headerlimits.go +++ b/internal/discriminator/headerlimits.go @@ -30,7 +30,7 @@ func (headerLimits) check(_ context.Context, rq *request, _ time.Time) *verdict } return &verdict{ - action: requestlog.ActionTooLarge, + action: requestlog.ActionRequestHeaderTooLarge, figures: map[string]any{ "fields": fields, "fields_limit": maxHeaderFields, "cookies": cookies, "cookies_limit": maxCookies, diff --git a/internal/discriminator/history_test.go b/internal/discriminator/history_test.go index 43471e3..a33ddd8 100644 --- a/internal/discriminator/history_test.go +++ b/internal/discriminator/history_test.go @@ -31,9 +31,9 @@ func TestHistoryKeepsEachRequestOfTheClient(t *testing.T) { s.get(fromDE, http.StatusOK, requestlog.ActionForward) clk.advance(time.Second) s.get(fromDE, http.StatusOK, requestlog.ActionForward) - s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited) + s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited) clk.advance(time.Second) - s.get(fromDE, http.StatusForbidden, requestlog.ActionBanned) + s.get(fromDE, http.StatusForbidden, requestlog.ActionTemporarilyBanned) want := ratelimit.History{ FirstSeen: start, diff --git a/internal/discriminator/lookup_test.go b/internal/discriminator/lookup_test.go index 92075a5..21cb967 100644 --- a/internal/discriminator/lookup_test.go +++ b/internal/discriminator/lookup_test.go @@ -40,7 +40,7 @@ func TestEveryClientIsLookedUpWithoutWaitingWhileNoSettingNeedsIt(t *testing.T) // comes too. None waits for GeoJS. for _, line := range []logLine{ s.get(fromDE, http.StatusOK, requestlog.ActionForward), - s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited), + s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited), s.get(fromKP, http.StatusOK, requestlog.ActionForward), } { got := asnAndCountry{line.ASN, line.ASName, line.Country} @@ -179,7 +179,7 @@ func TestASNumberAndNameInTheLogLineTheHistoryTheBanNotesAndTheAlert(t *testing. for _, line := range []logLine{ s.get(fromDE, http.StatusOK, requestlog.ActionForward), - s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited), + s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited), } { if got := (asnAndCountry{line.ASN, line.ASName, line.Country}); got != want { t.Errorf("log line has %+v, want %+v", got, want) @@ -264,7 +264,7 @@ func TestClientsAreLookedUpInTheLookupDatabaseAndGeoJSIsNotAsked(t *testing.T) { want asnAndCountry }{ {s.get(fromDE, http.StatusOK, requestlog.ActionForward), de}, - {s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited), de}, + {s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited), de}, { s.get(fromKP, http.StatusForbidden, requestlog.ActionCountryDenied), asnAndCountry{asnKP, asNameKP, "KP"}, diff --git a/internal/discriminator/metrics_test.go b/internal/discriminator/metrics_test.go index 72af353..68ea54e 100644 --- a/internal/discriminator/metrics_test.go +++ b/internal/discriminator/metrics_test.go @@ -125,15 +125,15 @@ func TestMetricsCountLimitsAndBans(t *testing.T) { }) // SWW_BAN_RESPONSE=close sends no status at all. - s.get(denied, 0, requestlog.ActionDenied) + s.get(denied, 0, requestlog.ActionClientDenied) // A first broken limit bans for an hour. s.get(client, http.StatusOK, requestlog.ActionForward) - s.get(client, 0, requestlog.ActionRateLimited) + s.get(client, 0, requestlog.ActionClientIsRateLimited) metrics := s.scrape() wantMetric(t, metrics, - `sww_requests_total{action="denied",instance="app",status_class="none"}`, 1) + `sww_requests_total{action="client_denied",instance="app",status_class="none"}`, 1) wantMetric(t, metrics, `sww_rate_limit_hits_total{instance="app",`+ `kind="requests",window="minute"}`, 1) wantMetric(t, metrics, `sww_offences_total{instance="app",kind="limit"}`, 1) @@ -147,7 +147,7 @@ func TestMetricsCountLimitsAndBans(t *testing.T) { // A limit broken again right after would ban for three hours, longer // than SWW_MAX_BAN_DURATION, so the ban is permanent. s.get(client, http.StatusOK, requestlog.ActionForward) - s.get(client, 0, requestlog.ActionRateLimited) + s.get(client, 0, requestlog.ActionClientIsRateLimited) metrics = s.scrape() wantMetric(t, metrics, `sww_rate_limit_hits_total{instance="app",`+ diff --git a/internal/discriminator/observe_test.go b/internal/discriminator/observe_test.go index 5ca9fcc..9d44220 100644 --- a/internal/discriminator/observe_test.go +++ b/internal/discriminator/observe_test.go @@ -7,6 +7,7 @@ import ( "testing" "time" + "sneak.berlin/go/smallwebwaf/internal/alerts" "sneak.berlin/go/smallwebwaf/internal/bans" "sneak.berlin/go/smallwebwaf/internal/requestlog" ) @@ -14,6 +15,93 @@ import ( // observe is the value of SWW_MODE for observe mode. const observe = "observe" +func TestBanActionSaysWhetherTheBanRunsOut(t *testing.T) { + t.Parallel() + + const trapPath = "/wp-login.php" + + for _, tc := range []struct { + name string + cause string + // endsIn is how long after the request the ban ends: negative for a + // ban that has ended, and zero for a permanent ban. + endsIn time.Duration + path string + want string + }{ + { + "temporary ban", bans.CauseAdmin, time.Hour, "/", + requestlog.ActionTemporarilyBanned, + }, + {"permanent ban", bans.CauseAdmin, 0, "/", requestlog.ActionPermanentlyBanned}, + { + "request that makes a ban permanent", bans.CauseAttack, time.Hour, "/", + requestlog.ActionPermanentlyBanned, + }, + { + "trap path after an attack ban ended", bans.CauseAttack, -time.Hour, + trapPath, requestlog.ActionPermanentlyBanned, + }, + { + "first trap path after another ban ended", bans.CauseAdmin, -time.Hour, + trapPath, requestlog.ActionTemporarilyBanned, + }, + } { + for _, modeValue := range []string{"enforce", observe} { + t.Run(tc.name+" in "+modeValue, func(t *testing.T) { + t.Parallel() + + s, clk, server := startWithClock(t, "", map[string]string{ + trapPaths: trapPathList, mode: modeValue, + }) + + ban := bans.Ban{ + Netblock: netip.MustParsePrefix(client + "/32"), + Start: clk.Now().Add(-2 * time.Hour), + Cause: tc.cause, + } + if tc.endsIn != 0 { + ban.Expires = clk.Now().Add(tc.endsIn) + } + + server.Ledger.Load([]bans.Ban{ban}) + + if modeValue == observe { + line := s.request(client, tc.path, http.StatusOK, requestlog.ActionForward) + wantWouldAction(t, line, tc.want) + + return + } + + s.request(client, tc.path, http.StatusForbidden, tc.want) + }) + } + } +} + +func TestObserveModeNamesAPermanentBanWhoseAlertWouldBeSent(t *testing.T) { + t.Parallel() + + s, clk, server, queue := startWithAlerts(t, map[string]string{ + trapPaths: trapPathList, mode: observe, + }) + + server.Ledger.Load([]bans.Ban{{ + Netblock: netip.MustParsePrefix(client + "/32"), + Start: clk.Now().Add(-2 * time.Hour), + Expires: clk.Now().Add(-time.Hour), + Cause: bans.CauseAttack, + }}) + + line := s.request(client, "/wp-login.php", http.StatusOK, requestlog.ActionForward) + wantWouldAction(t, line, requestlog.ActionPermanentlyBanned) + + waiting := queue.Snapshot().Waiting[alerts.DestinationWebhook] + if len(waiting) != 1 || waiting[0].Event != alerts.EventPermanentBan { + t.Errorf("alerts waiting are %+v, want one %s", waiting, alerts.EventPermanentBan) + } +} + func TestObserveModeNamesTheHeuristicThatWouldHaveRefused(t *testing.T) { t.Parallel() @@ -22,7 +110,7 @@ func TestObserveModeNamesTheHeuristicThatWouldHaveRefused(t *testing.T) { }) line := s.get(client, http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionDenied) + wantWouldAction(t, line, requestlog.ActionClientDenied) wantHeuristic(t, line, "deny_nets", `{"netblock": "`+client+`/32"}`) } @@ -69,10 +157,10 @@ func TestObserveModeForwardsWhatEnforceModeRefuses(t *testing.T) { s.get(fromDE, http.StatusOK, requestlog.ActionForward) for _, sent := range []struct{ from, refusal string }{ - {denied, requestlog.ActionDenied}, - {banned, requestlog.ActionBanned}, - {fromKP, requestlog.ActionDenied}, - {fromDE, requestlog.ActionRateLimited}, + {denied, requestlog.ActionClientDenied}, + {banned, requestlog.ActionTemporarilyBanned}, + {fromKP, requestlog.ActionClientDenied}, + {fromDE, requestlog.ActionClientIsRateLimited}, } { if !tc.observe { line := s.get(sent.from, http.StatusForbidden, sent.refusal) @@ -110,7 +198,7 @@ func TestObserveModeMakesNoBanAndKeepsTheBansItHas(t *testing.T) { for range 2 { line := s.get(client, http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionRateLimited) + wantWouldAction(t, line, requestlog.ActionClientIsRateLimited) if line.LimitHit != minute || line.Offence != requestlog.OffenceLimit || line.BanExpires != "" { @@ -123,7 +211,7 @@ func TestObserveModeMakesNoBanAndKeepsTheBansItHas(t *testing.T) { // The ban read from bans.json refuses nothing, and so counts no // refusal in its notes, but is kept. line := s.get(otherClient, http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionBanned) + wantWouldAction(t, line, requestlog.ActionTemporarilyBanned) if line.BanExpires != requestlog.FormatTime(kept.Expires) { t.Errorf("log line has ban_expires %q, want %s", line.BanExpires, diff --git a/internal/discriminator/ratelimits.go b/internal/discriminator/ratelimits.go index 1eb943c..bccfab9 100644 --- a/internal/discriminator/ratelimits.go +++ b/internal/discriminator/ratelimits.go @@ -42,7 +42,9 @@ func (rateLimits) check(_ context.Context, rq *request, now time.Time) *verdict rq.banForLimit(now, hit, rq.h.config.BanResponse) - return &verdict{action: requestlog.ActionRateLimited, figures: limitFigures(hit)} + return &verdict{ + action: requestlog.ActionClientIsRateLimited, figures: limitFigures(hit), + } } // overAWholeRateLimit reports whether the heuristic rate_limits will refuse the diff --git a/internal/discriminator/ratelimits_test.go b/internal/discriminator/ratelimits_test.go index 926f22f..0e3a8b0 100644 --- a/internal/discriminator/ratelimits_test.go +++ b/internal/discriminator/ratelimits_test.go @@ -59,7 +59,7 @@ func TestRateLimitRefusesBeforeTheApp(t *testing.T) { if sent.want == http.StatusOK { wantLine(t, line, http.StatusOK, requestlog.ActionForward) } else { - wantLine(t, line, http.StatusForbidden, requestlog.ActionRateLimited) + wantLine(t, line, http.StatusForbidden, requestlog.ActionClientIsRateLimited) if line.LimitHit != minute { t.Errorf("log line has limit_hit %q, want minute", line.LimitHit) @@ -79,7 +79,7 @@ func TestRateLimitRefusalNamesItsHeuristicWindowCountAndLimit(t *testing.T) { s.get(client, http.StatusOK, requestlog.ActionForward) - line := s.get(client, http.StatusForbidden, requestlog.ActionRateLimited) + line := s.get(client, http.StatusForbidden, requestlog.ActionClientIsRateLimited) wantHeuristic(t, line, "rate_limits", `{"window": "minute", "count": 2, "limit": 1}`) } @@ -102,7 +102,7 @@ func TestIPv6GroupPrefixSetsTheClientTheLimitsCount(t *testing.T) { status int action string }{ - {rateLimitPerMinute, "1", http.StatusForbidden, requestlog.ActionRateLimited}, + {rateLimitPerMinute, "1", http.StatusForbidden, requestlog.ActionClientIsRateLimited}, {bytesLimitPerMinute, byteLimit, http.StatusOK, requestlog.ActionForward}, } { t.Run(tc.setting, func(t *testing.T) { @@ -160,14 +160,17 @@ func TestRateLimitExemptPathsAreNeitherCountedNorRefused(t *testing.T) { // A path outside every prefix is counted: /assets is not under // /assets/, and breaks the limit. - s.request(client, "/assets", http.StatusForbidden, requestlog.ActionRateLimited) + s.request(client, "/assets", http.StatusForbidden, + requestlog.ActionClientIsRateLimited) // A ban, SWW_DENY_NETS and SWW_TAG_DENY still refuse a path under a // prefix. - s.request(client, "/assets/app.js", http.StatusForbidden, requestlog.ActionBanned) - s.request(denied, "/assets/app.js", http.StatusForbidden, requestlog.ActionDenied) + s.request(client, "/assets/app.js", http.StatusForbidden, + requestlog.ActionTemporarilyBanned) + s.request(denied, "/assets/app.js", http.StatusForbidden, + requestlog.ActionClientDenied) s.request(fromKP, "/assets/app.js", - http.StatusForbidden, requestlog.ActionDenied) + http.StatusForbidden, requestlog.ActionClientDenied) } func TestRateLimitCountsPathsThatAreNotExempt(t *testing.T) { @@ -211,7 +214,7 @@ func TestRateLimitCountsPathsThatAreNotExempt(t *testing.T) { // Counted, the second request breaks the limit of one request // a minute. s.request(client, sent, http.StatusOK, requestlog.ActionForward) - s.request(client, sent, http.StatusForbidden, requestlog.ActionRateLimited) + s.request(client, sent, http.StatusForbidden, requestlog.ActionClientIsRateLimited) }) } } diff --git a/internal/discriminator/refusallimit.go b/internal/discriminator/refusallimit.go index a7d2375..5eb13f7 100644 --- a/internal/discriminator/refusallimit.go +++ b/internal/discriminator/refusallimit.go @@ -28,7 +28,7 @@ func (refusalLimit) check(_ context.Context, rq *request, now time.Time) *verdic return nil } - if !rq.attack && !rq.ruleBlocked && !rq.wafBlocked { + if !rq.attack && !rq.blockedByBlockRule && !rq.wafBlocked { return nil } @@ -42,13 +42,13 @@ func (refusalLimit) check(_ context.Context, rq *request, now time.Time) *verdic status := rq.out.status switch rq.line.WouldAction { - case requestlog.ActionRuleBlocked, requestlog.ActionWAFBlocked: + case requestlog.ActionBlockedByBlockRule, requestlog.ActionWAFBlocked: status = http.StatusForbidden - case requestlog.ActionBanned: + case requestlog.ActionTemporarilyBanned, requestlog.ActionPermanentlyBanned: status = cfg.BanResponse } rq.banForLimit(now, hit, status) - return &verdict{action: requestlog.ActionBanned, figures: limitFigures(hit)} + return &verdict{figures: limitFigures(hit)} } diff --git a/internal/discriminator/refusallimit_test.go b/internal/discriminator/refusallimit_test.go index 09a34b9..c3fc168 100644 --- a/internal/discriminator/refusallimit_test.go +++ b/internal/discriminator/refusallimit_test.go @@ -37,9 +37,10 @@ func (r refused) send(s *sender, from string) logLine { switch r { case blockRule: return s.request(from, blockedPath, http.StatusForbidden, - requestlog.ActionRuleBlocked) + requestlog.ActionBlockedByBlockRule) case banRule: - return s.request(from, probePath, http.StatusForbidden, requestlog.ActionBanned) + return s.request(from, probePath, http.StatusForbidden, + requestlog.ActionTemporarilyBanned) } s.t.Fatalf("no request for the refusal %d", r) @@ -71,9 +72,20 @@ func TestErrorBurstBreaksAtOneOverTheThreshold(t *testing.T) { name string // refusals are four, one over the threshold of three. refusals []refused + // nextAction is the action of the client's next request: the next + // request after a ban for a ban rule makes it permanent. + nextAction string }{ - {"block rule", []refused{blockRule, blockRule, blockRule, blockRule}}, - {"a ban rule last", []refused{blockRule, blockRule, blockRule, banRule}}, + { + "block rule", + []refused{blockRule, blockRule, blockRule, blockRule}, + requestlog.ActionTemporarilyBanned, + }, + { + "a ban rule last", + []refused{blockRule, blockRule, blockRule, banRule}, + requestlog.ActionPermanentlyBanned, + }, } { t.Run(tc.name, func(t *testing.T) { t.Parallel() @@ -101,7 +113,7 @@ func TestErrorBurstBreaksAtOneOverTheThreshold(t *testing.T) { "and limit", line.LimitHit, line.Offence) } - s.get(client, http.StatusForbidden, requestlog.ActionBanned) + s.get(client, http.StatusForbidden, tc.nextAction) }) } } @@ -169,7 +181,7 @@ func TestErrorBurstBanNotesHistoryAndMetrics(t *testing.T) { t.Fatalf("bans\n%+v\nwant\n%+v", got, want) } - wantOffences := ratelimit.Offences{Limit: 1, RuleBlocked: 3} + wantOffences := ratelimit.Offences{Limit: 1, BlockedByBlockRule: 3} if offences := historyOf(t, server, client).Offences; offences != wantOffences { t.Errorf("history counts the offences %+v, want %+v", offences, wantOffences) } @@ -179,7 +191,7 @@ func TestErrorBurstBanNotesHistoryAndMetrics(t *testing.T) { `kind="refusals",window="minute"}`, 1) wantMetric(t, metrics, `sww_offences_total{instance="app",kind="limit"}`, 1) wantMetric(t, metrics, - `sww_offences_total{instance="app",kind="rule_blocked"}`, 3) + `sww_offences_total{instance="app",kind="blocked_by_block_rule"}`, 3) wantMetric(t, metrics, `sww_bans_made_total{cause="limit",instance="app"}`, 1) } @@ -298,7 +310,7 @@ func TestErrorBurstCountsEachClientTheChecksApplyTo(t *testing.T) { t.Errorf("log line has limit_hit %q, want error_burst", line.LimitHit) } - s.get(exempt, http.StatusForbidden, requestlog.ActionBanned) + s.get(exempt, http.StatusForbidden, requestlog.ActionTemporarilyBanned) } func TestErrorBurstBanSetsTheRefusalsBackToZero(t *testing.T) { @@ -341,7 +353,7 @@ func TestObserveModeLogsAndAlertsTheErrorBurst(t *testing.T) { for range 2 { line := s.request(otherClient, blockedPath, http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionBanned) + wantWouldAction(t, line, requestlog.ActionTemporarilyBanned) if line.LimitHit != "" { t.Errorf("log line has limit_hit %q, want none", line.LimitHit) @@ -353,7 +365,7 @@ func TestObserveModeLogsAndAlertsTheErrorBurst(t *testing.T) { s.request(client, blockedPath, http.StatusOK, requestlog.ActionForward) line := s.request(client, blockedPath, http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionRuleBlocked) + wantWouldAction(t, line, requestlog.ActionBlockedByBlockRule) if line.LimitHit != requestlog.LimitHitErrorBurst || line.BanExpires != "" { t.Errorf("log line has limit_hit %q and ban_expires %q, want error_burst "+ diff --git a/internal/discriminator/reputation_test.go b/internal/discriminator/reputation_test.go index c992117..8f03a32 100644 --- a/internal/discriminator/reputation_test.go +++ b/internal/discriminator/reputation_test.go @@ -49,7 +49,7 @@ const ( func TestEachBlocklistActionForAListedAddressAndAListedNetblock(t *testing.T) { t.Parallel() - forward, denied := requestlog.ActionForward, requestlog.ActionDenied + forward, denied := requestlog.ActionForward, requestlog.ActionClientDenied for _, tc := range []struct { action string @@ -66,7 +66,7 @@ func TestEachBlocklistActionForAListedAddressAndAListedNetblock(t *testing.T) { { // Half of 4 requests a minute: the third breaks the limit. limitHalf, []int{http.StatusOK, http.StatusOK, http.StatusForbidden}, - []string{forward, forward, requestlog.ActionRateLimited}, + []string{forward, forward, requestlog.ActionClientIsRateLimited}, "50 from " + blocklistAction, }, { @@ -162,7 +162,7 @@ func TestReputationRefusalNamesItsHeuristicAndWhatListedTheClient(t *testing.T) s, server, _ := startWithLookups(t, tc.env) tc.load(t, server) - line := s.get(client, http.StatusForbidden, requestlog.ActionDenied) + line := s.get(client, http.StatusForbidden, requestlog.ActionClientDenied) wantHeuristic(t, line, tc.heuristic, tc.figures) }) } @@ -193,7 +193,7 @@ func TestObserveModeForwardsAClientABlocklistDeniesAndAlertsIt(t *testing.T) { loadLists(t, server, map[string][]string{dropURL: {fromDE}}) line := s.get(fromDE, http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionDenied) + wantWouldAction(t, line, requestlog.ActionClientDenied) wantReputation(t, line, dropURL) waiting := queue.Snapshot().Waiting[alerts.DestinationWebhook] @@ -380,7 +380,7 @@ const ( func TestEachReputationActionForAClientADNSBLZoneLists(t *testing.T) { t.Parallel() - forward, denied := requestlog.ActionForward, requestlog.ActionDenied + forward, denied := requestlog.ActionForward, requestlog.ActionClientDenied for _, tc := range []struct { action string @@ -397,7 +397,7 @@ func TestEachReputationActionForAClientADNSBLZoneLists(t *testing.T) { { // Half of 4 requests a minute: the third breaks the limit. limitHalf, []int{http.StatusOK, http.StatusOK, http.StatusForbidden}, - []string{forward, forward, requestlog.ActionRateLimited}, + []string{forward, forward, requestlog.ActionClientIsRateLimited}, "50 from " + reputationAction, }, { @@ -468,7 +468,7 @@ func TestDNSBLZonesComeAfterTheBlocklistsAndSkipAllowNets(t *testing.T) { // The blocklist refuses fromKP before its verdict is looked at, and // fromDE, in SWW_ALLOW_NETS, is not checked at all: neither is noted // for the zone, nor alerted, nor asked about. - wantReputation(t, s.get(fromKP, http.StatusForbidden, requestlog.ActionDenied), + wantReputation(t, s.get(fromKP, http.StatusForbidden, requestlog.ActionClientDenied), dropURL) wantReputation(t, s.get(fromDE, http.StatusOK, requestlog.ActionForward)) @@ -532,7 +532,7 @@ func TestObserveModeForwardsAClientADNSBLZoneDeniesAndAlertsIt(t *testing.T) { loadVerdicts(server, map[string][]string{fromDE: {dnsblZone}}) line := s.get(fromDE, http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionDenied) + wantWouldAction(t, line, requestlog.ActionClientDenied) wantReputation(t, line, dnsblZone) waiting := queue.Snapshot().Waiting[alerts.DestinationWebhook] @@ -741,8 +741,8 @@ func TestOnlyAClientThatHasCommittedAnOffenceIsCheckedWithAbuseIPDB(t *testing.T s.get(fromDE, http.StatusOK, forward) s.get(fromDE, http.StatusOK, forward) s.get(fromKP, http.StatusOK, forward) - s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited) - s.get(fromDE, http.StatusForbidden, requestlog.ActionBanned) + s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited) + s.get(fromDE, http.StatusForbidden, requestlog.ActionTemporarilyBanned) wantAbuseIPDBChecks(t, server, 0) // Once the ban has ended, fromDE's first request has it checked in the @@ -781,7 +781,7 @@ func TestIPv6ClientCostsOneAbuseIPDBCheckWhicheverOfItsAddressesSends(t *testing s.get(addresses[0], http.StatusOK, forward) } - s.get(addresses[0], http.StatusForbidden, requestlog.ActionRateLimited) + s.get(addresses[0], http.StatusForbidden, requestlog.ActionClientIsRateLimited) clk.advance(time.Hour) // Once the ban has ended, which set its counters back to zero, a @@ -814,20 +814,20 @@ func TestClientRefusedForAnOffenceIsCheckedWithAbuseIPDBAtItsNextRequest(t *test want ratelimit.Offences }{ { - "a block rule", blockedPath, http.StatusForbidden, requestlog.ActionRuleBlocked, - ratelimit.Offences{RuleBlocked: 1}, + "a block rule", blockedPath, http.StatusForbidden, + requestlog.ActionBlockedByBlockRule, ratelimit.Offences{BlockedByBlockRule: 1}, }, { "the Core Rule Set", sqlInjection, http.StatusForbidden, requestlog.ActionWAFBlocked, ratelimit.Offences{WAFBlocked: 1}, }, { - "a ban rule", probePath, http.StatusForbidden, requestlog.ActionBanned, + "a ban rule", probePath, http.StatusForbidden, requestlog.ActionTemporarilyBanned, ratelimit.Offences{Attack: 1}, }, { - "a trap path", "/xmlrpc.php", http.StatusForbidden, requestlog.ActionBanned, - ratelimit.Offences{Attack: 1}, + "a trap path", "/xmlrpc.php", http.StatusForbidden, + requestlog.ActionTemporarilyBanned, ratelimit.Offences{Attack: 1}, }, } { t.Run(tc.name, func(t *testing.T) { @@ -858,7 +858,7 @@ func TestClientRefusedForAnOffenceIsCheckedWithAbuseIPDBAtItsNextRequest(t *test func TestEachReputationActionForAClientAbuseIPDBScoresAtOrOverTheMinimum(t *testing.T) { t.Parallel() - forward, denied := requestlog.ActionForward, requestlog.ActionDenied + forward, denied := requestlog.ActionForward, requestlog.ActionClientDenied for _, tc := range []struct { action string @@ -875,7 +875,7 @@ func TestEachReputationActionForAClientAbuseIPDBScoresAtOrOverTheMinimum(t *test { // Half of 4 requests a minute: the third breaks the limit. limitHalf, []int{http.StatusOK, http.StatusOK, http.StatusForbidden}, - []string{forward, forward, requestlog.ActionRateLimited}, + []string{forward, forward, requestlog.ActionClientIsRateLimited}, "50 from " + reputationAction, }, { @@ -972,7 +972,7 @@ func TestWithoutAnAbuseIPDBKeyNoClientIsCheckedNorAScoreUsed(t *testing.T) { // fromDE's score is not used, and once it has committed an offence it // is not checked either. wantReputation(t, s.get(fromDE, http.StatusOK, forward)) - s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited) + s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited) clk.advance(time.Hour) wantReputation(t, s.get(fromDE, http.StatusOK, forward)) wantAbuseIPDBChecks(t, server, 0) @@ -996,10 +996,10 @@ func TestBanNotesNameEachReputationSourceThatListedTheClient(t *testing.T) { }{ {"for a broken rate limit", func(s *sender, from string) { s.get(from, http.StatusOK, requestlog.ActionForward) - s.get(from, http.StatusForbidden, requestlog.ActionRateLimited) + s.get(from, http.StatusForbidden, requestlog.ActionClientIsRateLimited) }}, {"for a clear sign of attack", func(s *sender, from string) { - s.request(from, probePath, http.StatusForbidden, requestlog.ActionBanned) + s.request(from, probePath, http.StatusForbidden, requestlog.ActionTemporarilyBanned) }}, } { t.Run(tc.name, func(t *testing.T) { diff --git a/internal/discriminator/request.go b/internal/discriminator/request.go index dd69bb9..b39bc7c 100644 --- a/internal/discriminator/request.go +++ b/internal/discriminator/request.go @@ -54,10 +54,10 @@ type decision struct { counted bool limitPercent, bytesPercent percentage // attack is true for a request that matched a ban rule or asked for a - // trap path, ruleBlocked for one a block rule refused, and wafBlocked for - // one the Core Rule Set refused, each an offence its client's history - // counts. - attack, ruleBlocked, wafBlocked bool + // trap path, blockedByBlockRule for one a block rule refused, and + // wafBlocked for one the Core Rule Set refused, each an offence its + // client's history counts. + attack, blockedByBlockRule, wafBlocked bool // reputation is the reputation sources that list the client, for the // notes of a ban the request makes. reputation []bans.ReputationHit @@ -187,9 +187,10 @@ func (rq *request) check(ctx context.Context) *refusal { rq.line.WouldAction = action return nil - case action == requestlog.ActionRuleBlocked || action == requestlog.ActionWAFBlocked: + case action == requestlog.ActionBlockedByBlockRule || + action == requestlog.ActionWAFBlocked: return &refusal{status: http.StatusForbidden, action: action} - case action == requestlog.ActionTooLarge: + case action == requestlog.ActionRequestHeaderTooLarge: return &refusal{status: http.StatusRequestHeaderFieldsTooLarge, action: action} default: return rq.banResponse(action) @@ -303,15 +304,15 @@ func timing(start, end time.Time) *float64 { // when it comes. func (rq *request) addToHistory() { request := ratelimit.Request{ - Forwarded: rq.allowed, - Refused: rq.refused != nil, - Status: rq.out.status, - RequestBytes: rq.requestBytes, - ResponseBytes: rq.out.bytes, - BrokeLimit: rq.line.Offence == requestlog.OffenceLimit, - Attack: rq.attack, - RuleBlocked: rq.ruleBlocked, - WAFBlocked: rq.wafBlocked, + Forwarded: rq.allowed, + Refused: rq.refused != nil, + Status: rq.out.status, + RequestBytes: rq.requestBytes, + ResponseBytes: rq.out.bytes, + BrokeLimit: rq.line.Offence == requestlog.OffenceLimit, + Attack: rq.attack, + BlockedByBlockRule: rq.blockedByBlockRule, + WAFBlocked: rq.wafBlocked, } rq.h.limiter.AddToHistory(rq.h.clientGroup(rq.client), rq.h.now(), request) diff --git a/internal/discriminator/routewatchtags_test.go b/internal/discriminator/routewatchtags_test.go index 7f02aea..33327c9 100644 --- a/internal/discriminator/routewatchtags_test.go +++ b/internal/discriminator/routewatchtags_test.go @@ -112,7 +112,7 @@ func TestRouteWatchTagsAreOnALineDenyNetsRefused(t *testing.T) { waitForRouteWatch(t, server, fromKP, 32) - line := s.get(fromKP, http.StatusForbidden, requestlog.ActionDenied) + line := s.get(fromKP, http.StatusForbidden, requestlog.ActionClientDenied) wantHeuristic(t, line, "deny_nets", `{"netblock": "`+fromKP+`/32"}`) wantTags(t, line, "asn=64511", "prefix="+prefixKP) } @@ -222,7 +222,7 @@ func TestTagDenyRefusesOnARouteWatchPrefix(t *testing.T) { waitForRouteWatch(t, server, fromKP, 32) waitForRouteWatch(t, server, fromDE, 32) - wantHeuristic(t, s.get(fromKP, http.StatusForbidden, requestlog.ActionDenied), + wantHeuristic(t, s.get(fromKP, http.StatusForbidden, requestlog.ActionClientDenied), "tag_deny", `{"tag": "prefix=`+prefixKP+`"}`) s.get(fromDE, http.StatusOK, requestlog.ActionForward) } @@ -241,5 +241,5 @@ func TestTagLimitPercentWorksWithAnIPv6Prefix(t *testing.T) { // Half of two is one: the second request breaks the limit. line := s.get(fromV6, http.StatusOK, requestlog.ActionForward) wantTags(t, line, "asn=64496", "prefix="+prefixV6) - s.get(fromV6, http.StatusForbidden, requestlog.ActionRateLimited) + s.get(fromV6, http.StatusForbidden, requestlog.ActionClientIsRateLimited) } diff --git a/internal/discriminator/rulefiles.go b/internal/discriminator/rulefiles.go index 27e9c17..1422a95 100644 --- a/internal/discriminator/rulefiles.go +++ b/internal/discriminator/rulefiles.go @@ -16,9 +16,10 @@ import ( // ruleFiles checks the request against the rules of the rule files at now, // notes the ids of those it matches in the log line, adds the tag // exploitsignature when it matches any, and refuses the request -// when the last rule it matches refuses it: with ActionRuleBlocked for a block -// rule, and ActionBanned for a ban rule. A ban rule bans the client's netblock -// for a clear sign of attack, or in observe mode raises the alert for the ban +// when the last rule it matches refuses it: with ActionBlockedByBlockRule for a +// block rule, and for a ban rule with the action for the ban it makes. A ban +// rule bans the client's netblock for a clear sign of attack, or in observe +// mode raises the alert for the ban // it would have made. Either rule's match is noted as an offence, for the // client's history. Its figures are the rule's id and action. type ruleFiles struct{} @@ -45,14 +46,16 @@ func (ruleFiles) check(_ context.Context, rq *request, now time.Time) *verdict { switch last.Action { case rules.ActionBlock: - rq.ruleBlocked = true + rq.blockedByBlockRule = true - return &verdict{action: requestlog.ActionRuleBlocked, figures: figures} + return &verdict{action: requestlog.ActionBlockedByBlockRule, figures: figures} case rules.ActionBan: rq.attack = true - rq.banForAttack(now, bans.Notes{RuleID: last.ID, Target: last.Target}) - return &verdict{action: requestlog.ActionBanned, figures: figures} + return &verdict{ + action: rq.banForAttack(now, bans.Notes{RuleID: last.ID, Target: last.Target}), + figures: figures, + } default: return nil } diff --git a/internal/discriminator/rulefiles_test.go b/internal/discriminator/rulefiles_test.go index 30a4e9f..dd8af4d 100644 --- a/internal/discriminator/rulefiles_test.go +++ b/internal/discriminator/rulefiles_test.go @@ -37,13 +37,14 @@ func TestEachRuleAction(t *testing.T) { // A block rule refuses with 403, whatever SWW_BAN_RESPONSE is, and // bans no one. line = s.request(client, "/blocked", http.StatusForbidden, - requestlog.ActionRuleBlocked) + requestlog.ActionBlockedByBlockRule) wantRuleIDs(t, line, "noted", "blocked") s.get(client, http.StatusOK, requestlog.ActionForward) // A ban rule refuses with SWW_BAN_RESPONSE, and bans the client for // seven days, the default. - line = s.request(client, "/.env", http.StatusTooManyRequests, requestlog.ActionBanned) + line = s.request(client, "/.env", http.StatusTooManyRequests, + requestlog.ActionTemporarilyBanned) wantRuleIDs(t, line, "noted", "probe") if line.BanExpires != requestlog.FormatTime(start.Add(7*24*time.Hour)) { @@ -82,7 +83,7 @@ func TestEachRuleAction(t *testing.T) { // against the rules, and makes the ban permanent. clk.advance(time.Hour) - line = s.get(client, http.StatusTooManyRequests, requestlog.ActionBanned) + line = s.get(client, http.StatusTooManyRequests, requestlog.ActionPermanentlyBanned) wantRuleIDs(t, line) if line.BanExpires != permanent { @@ -90,7 +91,7 @@ func TestEachRuleAction(t *testing.T) { } clk.advance(365 * 24 * time.Hour) - s.get(client, http.StatusTooManyRequests, requestlog.ActionBanned) + s.get(client, http.StatusTooManyRequests, requestlog.ActionPermanentlyBanned) } func TestEachRuleActionAddsTheExploitSignatureTag(t *testing.T) { @@ -103,7 +104,7 @@ func TestEachRuleActionAddsTheExploitSignatureTag(t *testing.T) { wantTags(t, s.request(client, "/noted", http.StatusOK, requestlog.ActionForward), "exploitsignature") wantTags(t, s.request(client, "/blocked", http.StatusForbidden, - requestlog.ActionRuleBlocked), "exploitsignature") + requestlog.ActionBlockedByBlockRule), "exploitsignature") wantTags(t, s.get(client, http.StatusOK, requestlog.ActionForward)) } @@ -115,10 +116,11 @@ func TestRuleRefusalNamesItsHeuristicAndTheRule(t *testing.T) { }) line := s.request(client, "/blocked", http.StatusForbidden, - requestlog.ActionRuleBlocked) + requestlog.ActionBlockedByBlockRule) wantHeuristic(t, line, "rule_files", `{"rule_id": "blocked", "rule_action": "block"}`) - line = s.request(client, "/.env", http.StatusForbidden, requestlog.ActionBanned) + line = s.request(client, "/.env", http.StatusForbidden, + requestlog.ActionTemporarilyBanned) wantHeuristic(t, line, "rule_files", `{"rule_id": "probe", "rule_action": "ban"}`) } @@ -131,7 +133,8 @@ func TestNextClearSignOfAttackAfterABanBansPermanently(t *testing.T) { }) // The first probe bans for SWW_ATTACK_BAN_DURATION. - line := s.request(client, "/.env", http.StatusForbidden, requestlog.ActionBanned) + line := s.request(client, "/.env", http.StatusForbidden, + requestlog.ActionTemporarilyBanned) if line.BanExpires != requestlog.FormatTime(clk.Now().Add(time.Hour)) { t.Errorf("log line has ban_expires %q, want an hour on", line.BanExpires) } @@ -141,7 +144,8 @@ func TestNextClearSignOfAttackAfterABanBansPermanently(t *testing.T) { clk.advance(time.Hour) s.get(client, http.StatusOK, requestlog.ActionForward) - line = s.request(client, "/.env", http.StatusForbidden, requestlog.ActionBanned) + line = s.request(client, "/.env", http.StatusForbidden, + requestlog.ActionPermanentlyBanned) if line.BanExpires != permanent { t.Errorf("log line has ban_expires %q, want permanent", line.BanExpires) } @@ -169,7 +173,8 @@ func TestRulesComeAfterTheOtherChecks(t *testing.T) { // 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) + line = s.request(client, "/.env", http.StatusForbidden, + requestlog.ActionClientIsRateLimited) wantRuleIDs(t, line) limitBan := server.Ledger.Bans(netip.MustParsePrefix(client + "/32")) @@ -179,7 +184,7 @@ func TestRulesComeAfterTheOtherChecks(t *testing.T) { // 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) + s.request(exempt, "/.env", http.StatusForbidden, requestlog.ActionTemporarilyBanned) } func TestObserveModeLogsWhatTheRulesWouldDo(t *testing.T) { @@ -191,11 +196,11 @@ func TestObserveModeLogsWhatTheRulesWouldDo(t *testing.T) { }) line := s.request(client, "/blocked", http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionRuleBlocked) + wantWouldAction(t, line, requestlog.ActionBlockedByBlockRule) wantRuleIDs(t, line, "blocked") line = s.request(client, "/.env", http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionBanned) + wantWouldAction(t, line, requestlog.ActionTemporarilyBanned) wantRuleIDs(t, line, "probe") if line.BanExpires != "" { @@ -219,9 +224,10 @@ func TestMetricsCountRuleMatchesAndBansForAnAttack(t *testing.T) { 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) + s.request(client, "/blocked", http.StatusForbidden, + requestlog.ActionBlockedByBlockRule) + s.request(client, "/.env", http.StatusForbidden, requestlog.ActionTemporarilyBanned) + s.get(client, http.StatusForbidden, requestlog.ActionPermanentlyBanned) metrics := s.scrape() wantMetric(t, metrics, @@ -229,10 +235,10 @@ func TestMetricsCountRuleMatchesAndBansForAnAttack(t *testing.T) { wantMetric(t, metrics, `sww_rule_matches_total{action="ban",instance="app",rule_id="probe"}`, 1) wantMetric(t, metrics, `sww_rules_loaded{instance="app"}`, 2) - wantMetric(t, metrics, `sww_requests_total{action="rule_blocked",`+ + wantMetric(t, metrics, `sww_requests_total{action="blocked_by_block_rule",`+ `instance="app",status_class="4xx"}`, 1) wantMetric(t, metrics, - `sww_offences_total{instance="app",kind="rule_blocked"}`, 1) + `sww_offences_total{instance="app",kind="blocked_by_block_rule"}`, 1) wantMetric(t, metrics, `sww_offences_total{instance="app",kind="attack"}`, 1) wantMetric(t, metrics, `sww_bans_made_total{cause="attack",instance="app"}`, 1) wantMetric(t, metrics, `sww_bans_made_total{cause="limit",instance="app"}`, 0) diff --git a/internal/discriminator/staticlists_test.go b/internal/discriminator/staticlists_test.go index 9ba8ad9..04643da 100644 --- a/internal/discriminator/staticlists_test.go +++ b/internal/discriminator/staticlists_test.go @@ -68,7 +68,7 @@ func TestRequestFromAllowNetsIsNotCounted(t *testing.T) { {listedAddr, http.StatusOK, requestlog.ActionForward}, {listedAddr, http.StatusOK, requestlog.ActionForward}, {unlistedAddr, http.StatusOK, requestlog.ActionForward}, - {unlistedAddr, http.StatusForbidden, requestlog.ActionRateLimited}, + {unlistedAddr, http.StatusForbidden, requestlog.ActionClientIsRateLimited}, }) } @@ -92,7 +92,7 @@ func TestDenyNetsRefuseBeforeTheLookup(t *testing.T) { wantStatus(t, do(t, req), http.StatusForbidden) line := out.endedLine(t) - wantLine(t, line, http.StatusForbidden, requestlog.ActionDenied) + wantLine(t, line, http.StatusForbidden, requestlog.ActionClientDenied) if len(asked()) != 0 { t.Errorf("GeoJS was asked about %v, want nothing", asked()) @@ -108,7 +108,7 @@ func TestDenyNetsRefusalNamesItsHeuristicAndNetblock(t *testing.T) { s, _, _ := startWithClock(t, "", map[string]string{denyNets: clientsNet}) - line := s.get(client, http.StatusForbidden, requestlog.ActionDenied) + line := s.get(client, http.StatusForbidden, requestlog.ActionClientDenied) wantHeuristic(t, line, "deny_nets", `{"netblock": "`+clientsNet+`"}`) } @@ -125,10 +125,10 @@ func TestRequestRefusedByDenyNetsIsNotCounted(t *testing.T) { // listedAddr's refused requests are not counted, so the first request // from unlistedAddr is within the limit of one a minute. wantAnswers(t, addr, out, []sentRequest{ - {listedAddr, http.StatusForbidden, requestlog.ActionDenied}, - {listedAddr, http.StatusForbidden, requestlog.ActionDenied}, + {listedAddr, http.StatusForbidden, requestlog.ActionClientDenied}, + {listedAddr, http.StatusForbidden, requestlog.ActionClientDenied}, {unlistedAddr, http.StatusOK, requestlog.ActionForward}, - {unlistedAddr, http.StatusForbidden, requestlog.ActionRateLimited}, + {unlistedAddr, http.StatusForbidden, requestlog.ActionClientIsRateLimited}, }) } @@ -152,8 +152,8 @@ func TestRateLimitExemptNetsAreNeitherCountedNorRefused(t *testing.T) { {listedAddr, http.StatusOK, requestlog.ActionForward}, {listedAddr, http.StatusOK, requestlog.ActionForward}, {unlistedAddr, http.StatusOK, requestlog.ActionForward}, - {unlistedAddr, http.StatusForbidden, requestlog.ActionRateLimited}, - {fromKP, http.StatusForbidden, requestlog.ActionDenied}, + {unlistedAddr, http.StatusForbidden, requestlog.ActionClientIsRateLimited}, + {fromKP, http.StatusForbidden, requestlog.ActionClientDenied}, }) } diff --git a/internal/discriminator/tagdeny.go b/internal/discriminator/tagdeny.go index 0437bdf..b9a349d 100644 --- a/internal/discriminator/tagdeny.go +++ b/internal/discriminator/tagdeny.go @@ -20,7 +20,7 @@ func (tagDeny) check(_ context.Context, rq *request, _ time.Time) *verdict { for _, tag := range rq.line.Tags { if slices.Contains(rq.h.config.TagDeny, tag) { return &verdict{ - action: requestlog.ActionDenied, + action: requestlog.ActionClientDenied, figures: map[string]any{"tag": tag}, } } diff --git a/internal/discriminator/tagdeny_test.go b/internal/discriminator/tagdeny_test.go index 9817303..61ee5d2 100644 --- a/internal/discriminator/tagdeny_test.go +++ b/internal/discriminator/tagdeny_test.go @@ -14,7 +14,7 @@ func TestTagDenyRefusesALookupTagAndNamesTheTag(t *testing.T) { // in capitals. s, _, _ := startWithLookups(t, map[string]string{tagDeny: "Country=kp"}) - line := s.get(fromKP, http.StatusForbidden, requestlog.ActionDenied) + line := s.get(fromKP, http.StatusForbidden, requestlog.ActionClientDenied) wantHeuristic(t, line, "tag_deny", `{"tag": "country=KP"}`) wantTags(t, line, "asn=64511", "country=KP") @@ -26,7 +26,7 @@ func TestTagDenyRefusesAnASNTag(t *testing.T) { s, _, _ := startWithLookups(t, map[string]string{tagDeny: "asn=64511"}) - wantHeuristic(t, s.get(fromKP, http.StatusForbidden, requestlog.ActionDenied), + wantHeuristic(t, s.get(fromKP, http.StatusForbidden, requestlog.ActionClientDenied), "tag_deny", `{"tag": "asn=64511"}`) s.get(fromDE, http.StatusOK, requestlog.ActionForward) } @@ -41,7 +41,7 @@ func TestTagDenyRefusesAListTagBeforeTheRateLimitsCount(t *testing.T) { // Each is refused for its tag: none is counted to break the limit of one. for range 3 { - wantHeuristic(t, s.get(fromDE, http.StatusForbidden, requestlog.ActionDenied), + wantHeuristic(t, s.get(fromDE, http.StatusForbidden, requestlog.ActionClientDenied), "tag_deny", `{"tag": "torexit"}`) } } @@ -58,7 +58,7 @@ func TestTagDenyRefusesAMixedCaseZoneByItsLowerCaseTag(t *testing.T) { }) loadVerdicts(server, map[string][]string{fromDE: {mixedCaseZone}}) - wantHeuristic(t, s.get(fromDE, http.StatusForbidden, requestlog.ActionDenied), + wantHeuristic(t, s.get(fromDE, http.StatusForbidden, requestlog.ActionClientDenied), "tag_deny", `{"tag": "dnsbl=`+dnsblZone+`"}`) } @@ -69,7 +69,7 @@ func TestTagDenyRefusesAnExploitSignatureOfARuleThatOnlyLogs(t *testing.T) { rulesDir: writeRules(t, "noted path log ^/\n"), tagDeny: "exploitsignature", }) - line := s.get(client, http.StatusForbidden, requestlog.ActionDenied) + line := s.get(client, http.StatusForbidden, requestlog.ActionClientDenied) wantHeuristic(t, line, "tag_deny", `{"tag": "exploitsignature"}`) wantTags(t, line, "exploitsignature") } @@ -87,7 +87,7 @@ func TestTagLimitPercentLowersALimitTheLowestWinning(t *testing.T) { // A quarter of 4 requests a minute: the second breaks the limit. s.get(fromDE, http.StatusOK, requestlog.ActionForward) - line := s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited) + line := s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited) wantPercent(t, "limit_percent", line.LimitPercent, line.LimitPercentSetting, "25 from "+tagLimitPercent) } diff --git a/internal/discriminator/taglists_test.go b/internal/discriminator/taglists_test.go index cffc92d..b64c4c4 100644 --- a/internal/discriminator/taglists_test.go +++ b/internal/discriminator/taglists_test.go @@ -80,7 +80,7 @@ func TestTagListsTagARequestRefusedBeforeTheLookup(t *testing.T) { }) loadLists(t, server, map[string][]string{vpnList: {fromDE, fromKP}}) - line := s.get(fromKP, http.StatusForbidden, requestlog.ActionDenied) + line := s.get(fromKP, http.StatusForbidden, requestlog.ActionClientDenied) if line.Heuristic != "deny_nets" { t.Errorf("log line has heuristic %q, want deny_nets", line.Heuristic) } @@ -89,9 +89,9 @@ func TestTagListsTagARequestRefusedBeforeTheLookup(t *testing.T) { // The second request breaks the limit of one a minute, which bans the client. s.get(fromDE, http.StatusOK, requestlog.ActionForward) - s.get(fromDE, http.StatusForbidden, requestlog.ActionRateLimited) + s.get(fromDE, http.StatusForbidden, requestlog.ActionClientIsRateLimited) - line = s.get(fromDE, http.StatusForbidden, requestlog.ActionBanned) + line = s.get(fromDE, http.StatusForbidden, requestlog.ActionTemporarilyBanned) if line.Heuristic != "active_ban" { t.Errorf("log line has heuristic %q, want active_ban", line.Heuristic) } diff --git a/internal/discriminator/trappaths.go b/internal/discriminator/trappaths.go index 3963786..adb80e6 100644 --- a/internal/discriminator/trappaths.go +++ b/internal/discriminator/trappaths.go @@ -8,7 +8,6 @@ import ( "time" "sneak.berlin/go/smallwebwaf/internal/bans" - "sneak.berlin/go/smallwebwaf/internal/requestlog" "sneak.berlin/go/smallwebwaf/internal/rules" ) @@ -30,10 +29,9 @@ func (trapPaths) check(_ context.Context, rq *request, now time.Time) *verdict { } rq.attack = true - rq.banForAttack(now, bans.Notes{TrapPath: path}) return &verdict{ - action: requestlog.ActionBanned, + action: rq.banForAttack(now, bans.Notes{TrapPath: path}), figures: map[string]any{"path": path}, } } diff --git a/internal/discriminator/trappaths_test.go b/internal/discriminator/trappaths_test.go index 7d5b757..b2af734 100644 --- a/internal/discriminator/trappaths_test.go +++ b/internal/discriminator/trappaths_test.go @@ -43,7 +43,7 @@ func TestTrapPathBansAsABanRuleDoes(t *testing.T) { // The query is not part of the path. line := s.request(client, "/wp-login.php?redirect_to=x", http.StatusTooManyRequests, - requestlog.ActionBanned) + requestlog.ActionTemporarilyBanned) wantRuleIDs(t, line) if line.BanExpires != requestlog.FormatTime(start.Add(7*24*time.Hour)) { @@ -77,7 +77,7 @@ func TestTrapPathBansAsABanRuleDoes(t *testing.T) { } // The next request is refused under the ban, and makes it permanent. - line = s.get(client, http.StatusTooManyRequests, requestlog.ActionBanned) + line = s.get(client, http.StatusTooManyRequests, requestlog.ActionPermanentlyBanned) if line.BanExpires != permanent { t.Errorf("log line has ban_expires %q, want permanent", line.BanExpires) } @@ -89,7 +89,7 @@ func TestTrapPathRefusalNamesItsHeuristicAndPath(t *testing.T) { s, _, _ := startWithClock(t, "", map[string]string{trapPaths: trapPathList}) line := s.request(client, "/wp-login.php?redirect_to=x", http.StatusForbidden, - requestlog.ActionBanned) + requestlog.ActionTemporarilyBanned) wantHeuristic(t, line, "trap_paths", `{"path": "/wp-login.php"}`) } @@ -100,7 +100,8 @@ func TestTrapPathMatchesThePathDecodedOnce(t *testing.T) { // %2577 decodes once to %77, not to w. s.request(otherClient, "/%2577p-login.php", http.StatusOK, requestlog.ActionForward) - s.request(client, "/%77p-login.php", http.StatusForbidden, requestlog.ActionBanned) + s.request(client, "/%77p-login.php", http.StatusForbidden, + requestlog.ActionTemporarilyBanned) // The ban's notes give the path as the client sent it. got := server.Ledger.Bans(netip.MustParsePrefix(client + "/32")) @@ -117,7 +118,8 @@ func TestTrapPathsNeedNoRuleFiles(t *testing.T) { "SWW_RULES_ENABLED": "false", }) - s.request(client, "/xmlrpc.php", http.StatusForbidden, requestlog.ActionBanned) + s.request(client, "/xmlrpc.php", http.StatusForbidden, + requestlog.ActionTemporarilyBanned) } func TestObserveModeLogsWhatATrapPathWouldDo(t *testing.T) { @@ -129,7 +131,7 @@ func TestObserveModeLogsWhatATrapPathWouldDo(t *testing.T) { }) line := s.request(client, "/xmlrpc.php", http.StatusOK, requestlog.ActionForward) - wantWouldAction(t, line, requestlog.ActionBanned) + wantWouldAction(t, line, requestlog.ActionTemporarilyBanned) // No ban was made. s.get(client, http.StatusOK, requestlog.ActionForward) diff --git a/internal/metrics/metrics.go b/internal/metrics/metrics.go index 4adff7b..ecae684 100644 --- a/internal/metrics/metrics.go +++ b/internal/metrics/metrics.go @@ -424,10 +424,10 @@ func (m *Metrics) LimitHit(hit ratelimit.Hit) { // them. func (m *Metrics) Offences(r ratelimit.Request) { for kind, committed := range map[string]bool{ - "limit": r.BrokeLimit, - "attack": r.Attack, - "rule_blocked": r.RuleBlocked, - "waf_blocked": r.WAFBlocked, + "limit": r.BrokeLimit, + "attack": r.Attack, + "blocked_by_block_rule": r.BlockedByBlockRule, + "waf_blocked": r.WAFBlocked, } { if committed { m.offences.WithLabelValues(kind).Inc() diff --git a/internal/ratelimit/ratelimit.go b/internal/ratelimit/ratelimit.go index 0b3c7ca..87347e6 100644 --- a/internal/ratelimit/ratelimit.go +++ b/internal/ratelimit/ratelimit.go @@ -122,12 +122,12 @@ type Responses struct { type Offences struct { // Limit is its requests that broke a rate limit, a byte limit or the // error burst, Attack those that were a clear sign of attack, a match - // of a ban rule or a request for a trap path, RuleBlocked those a block - // rule refused, and WAFBlocked those the Core Rule Set refused. - Limit int64 `json:"limit"` - Attack int64 `json:"attack"` - RuleBlocked int64 `json:"rule_blocked"` - WAFBlocked int64 `json:"waf_blocked"` + // of a ban rule or a request for a trap path, BlockedByBlockRule those a + // block rule refused, and WAFBlocked those the Core Rule Set refused. + Limit int64 `json:"limit"` + Attack int64 `json:"attack"` + BlockedByBlockRule int64 `json:"blocked_by_block_rule"` + WAFBlocked int64 `json:"waf_blocked"` // TokenRefused is what a clients.json written by an earlier version gives, // which must still load. Nothing adds to it. TokenRefused int64 `json:"token_refused,omitempty"` @@ -147,12 +147,12 @@ type Request struct { ResponseBytes int64 // BrokeLimit is true for a request that broke a rate limit, a byte // limit or the error burst, Attack for one that matched a ban rule or - // asked for a trap path, RuleBlocked for one a block rule refused, and - // WAFBlocked for one the Core Rule Set refused. - BrokeLimit bool - Attack bool - RuleBlocked bool - WAFBlocked bool + // asked for a trap path, BlockedByBlockRule for one a block rule refused, + // and WAFBlocked for one the Core Rule Set refused. + BrokeLimit bool + Attack bool + BlockedByBlockRule bool + WAFBlocked bool } // New returns a Limiter for limits, with no client counted yet, whose @@ -323,8 +323,8 @@ func (l *Limiter) AddToHistory(client netip.Prefix, now time.Time, r Request) { h.Offences.Attack++ } - if r.RuleBlocked { - h.Offences.RuleBlocked++ + if r.BlockedByBlockRule { + h.Offences.BlockedByBlockRule++ } if r.WAFBlocked { diff --git a/internal/requestlog/requestlog.go b/internal/requestlog/requestlog.go index 504c710..2b45c47 100644 --- a/internal/requestlog/requestlog.go +++ b/internal/requestlog/requestlog.go @@ -20,32 +20,37 @@ const ( // the app. ActionForward = "forward" - // ActionTooLarge is a request over the header limits. - ActionTooLarge = "too_large" + // ActionRequestHeaderTooLarge is a request over the header limits. + ActionRequestHeaderTooLarge = "request_header_too_large" - // ActionRateLimited is a request refused because it took its client - // over a rate limit, which bans the client. - ActionRateLimited = "rate_limited" + // ActionClientIsRateLimited is a request refused because it took its + // client over a rate limit, which bans the client. + ActionClientIsRateLimited = "client_is_rate_limited" - // ActionBanned is a request refused because a ban covers its client, - // or because it matched a ban rule, asked for a trap path or the - // CrowdSec decision list lists its client, each of which bans the - // client. - ActionBanned = "banned" + // ActionTemporarilyBanned is a request refused because a ban that runs + // out covers its client, or because it matched a ban rule, asked for a + // trap path or the CrowdSec decision list lists its client, and so made + // such a ban. + ActionTemporarilyBanned = "temporarily_banned" - // ActionRuleBlocked is a request refused because it matched a block - // rule. - ActionRuleBlocked = "rule_blocked" + // ActionPermanentlyBanned is a request refused because a ban that never + // runs out covers its client, or because the request made such a ban or + // made its client's ban permanent. + ActionPermanentlyBanned = "permanently_banned" + + // ActionBlockedByBlockRule is a request refused because it matched a + // block rule. + ActionBlockedByBlockRule = "blocked_by_block_rule" // ActionWAFBlocked is a request refused because the Core Rule Set // scored it at or over SWW_WAF_ANOMALY_THRESHOLD. ActionWAFBlocked = "waf_blocked" - // ActionDenied is a request refused because its client is in + // ActionClientDenied is a request refused because its client is in // SWW_DENY_NETS, in a blocklist while SWW_BLOCKLIST_ACTION is deny, // or listed by a DNSBL zone, or scored a hit by AbuseIPDB, while // SWW_REPUTATION_ACTION is deny, or that carries a tag in SWW_TAG_DENY. - ActionDenied = "denied" + ActionClientDenied = "client_denied" // ActionCountryDenied is a request refused because its client's country // is not in SWW_EXCLUSIVELY_ALLOWED_COUNTRIES. @@ -134,10 +139,10 @@ type Line struct { // The decision. Action string `json:"action"` // WouldAction is, in observe mode, the action enforce mode would have - // taken with a request it would have refused: ActionDenied, - // ActionBanned, ActionCountryDenied, ActionRateLimited, - // ActionRuleBlocked, ActionWAFBlocked, or, in discriminator, ActionTooLarge - // for the header limits. + // taken with a request it would have refused: ActionClientDenied, + // ActionTemporarilyBanned, ActionPermanentlyBanned, ActionCountryDenied, + // ActionClientIsRateLimited, ActionBlockedByBlockRule, ActionWAFBlocked, + // or, in discriminator, ActionRequestHeaderTooLarge for the header limits. WouldAction string `json:"would_action,omitempty"` // Heuristic is the name of the heuristic that refused the request, in // observe mode too, and HeuristicFigures are the figures it acted on, by diff --git a/internal/sww/sww_test.go b/internal/sww/sww_test.go index a5b62c0..3cae5f8 100644 --- a/internal/sww/sww_test.go +++ b/internal/sww/sww_test.go @@ -373,13 +373,13 @@ func TestStateKeptAcrossRestarts(t *testing.T) { out := runUntilStopped(t, env, func(url string) { wantRefused(t, url) }) - out.line(t, "action", "rate_limited") + out.line(t, "action", "client_is_rate_limited") // After another, the ban still refuses it. out = runUntilStopped(t, env, func(url string) { wantRefused(t, url) }) - out.line(t, "action", "banned") + out.line(t, "action", "temporarily_banned") } func TestBanRefusesItsNetblockAfterARestartWithAnotherScope(t *testing.T) { @@ -526,7 +526,7 @@ func TestRuleFileAddedWhileRunningTakesEffect(t *testing.T) { time.Sleep(pollInterval) } }) - out.line(t, "action", "rule_blocked") + out.line(t, "action", "blocked_by_block_rule") } func TestRuleFileThatDoesNotParseStopsTheStart(t *testing.T) { @@ -740,7 +740,7 @@ func TestBlocklistTriesAndCopiesKeptInReputationJSONAcrossRestarts(t *testing.T) time.Sleep(pollInterval) } }) - wantDeniedByList(t, out.line(t, "action", "denied"), dropURL) + wantDeniedByList(t, out.line(t, "action", "client_denied"), dropURL) if fetches := torFetches.Load(); fetches != 1 { t.Errorf("tor.txt fetched %d times, want once, before the restart", fetches) @@ -843,7 +843,8 @@ func wantDeniedByList(t *testing.T, line map[string]any, listURL string) { t.Helper() reputation, _ := line["reputation"].([]any) - if line["action"] != "denied" || len(reputation) != 1 || reputation[0] != listURL { + if line["action"] != "client_denied" || len(reputation) != 1 || + reputation[0] != listURL { t.Errorf("request log line %v, want one denied for %s", line, listURL) } } diff --git a/script/example-app b/script/example-app index 9ac4fff..3360636 100755 --- a/script/example-app +++ b/script/example-app @@ -187,15 +187,16 @@ main() { echo "example-app: rproxy passes a request to the app and its answer back" refused || fail "a second request in a minute was not refused" - wait_for "discriminator logged no ban" logged "$DISCRIMINATOR" '"action":"rate_limited"' + wait_for "discriminator logged no ban" \ + logged "$DISCRIMINATOR" '"action":"client_is_rate_limited"' echo "example-app: a second request in a minute bans the client" refused_from 203.0.113.9 /.env || fail "a probe for /.env was not refused" wait_for "discriminator logged no ban for the probe" \ - logged "$DISCRIMINATOR" '"action":"banned"' '"rule_ids":["env-file"]' + logged "$DISCRIMINATOR" '"action":"temporarily_banned"' '"rule_ids":["env-file"]' refused_from 203.0.113.9 / || fail "the client of the probe was let through" wait_for "the client's next request did not make its ban permanent" \ - logged "$DISCRIMINATOR" '"ban_expires":"permanent"' + logged "$DISCRIMINATOR" '"action":"permanently_banned"' '"ban_expires":"permanent"' echo "example-app: a probe for /.env bans the client, its next request for good" docker exec "$DISCRIMINATOR" sv stop sww >/dev/null || @@ -232,7 +233,7 @@ main() { start_app refused || fail "the new discriminator container let the banned client through" wait_for "discriminator logged no request refused under the ban" \ - logged "$DISCRIMINATOR" '"action":"banned"' + logged "$DISCRIMINATOR" '"action":"temporarily_banned"' echo "example-app: a new discriminator container on the same volume keeps the ban" docker rm --force "$DISCRIMINATOR" >/dev/null