Compare commits

..
1 Commits
Author SHA1 Message Date
clawbot c981e3d78d Alerts to a JSON webhook, with a cooldown and an hourly summary (closes #26)
check / check (push) Waiting to run
SWWAF_ALERT_WEBHOOK_URL gets one JSON POST per alert, in SPEC.md's
schema, with SWWAF_ALERT_WEBHOOK_HEADERS: ban and permanent_ban, with
the ban's notes, in observe mode too, marked mode observe;
source_failure for GeoJS; file_error for a rule or state file with an
error. SWWAF_ALERT_EVENTS chooses; SWWAF_ALERT_COOLDOWN holds back
repeats by netblock, file or source; past SWWAF_ALERT_MAX_PER_HOUR the
hour ends in one summary. A bounded queue, retried with backoff, holds
up no request; a 4xx other than 408 and 429 gives the alert up.
alerts.json keeps the queue, the cooldowns and the hour. Nothing shows
the URL's path or query.

Judgement call: the summary's event is summary, which SPEC.md omits.
Judgement call: an admin's ban raises no alert.

Model: opus-5-5
2026-10-07 01:00:20 +00:00
17 changed files with 663 additions and 209 deletions
+39 -30
View File
@@ -164,7 +164,9 @@ in `bin/state` unless `SWWAF_STATE_DIR` is set, and the default rule file of
neither a broken rate limit nor a `ban` rule makes a ban; a broken rate limit
does not set the client's counters back to zero, so each request over the
limit is logged as one that would be refused; and a request under a ban does
not make it permanent. The bans in `bans.json` are kept, and refuse requests
not make it permanent. A ban it would have made, or made permanent, raises the
alert `enforce` mode would have raised, marked as what would have happened
(see "Alerts" below). The bans in `bans.json` are kept, and refuse requests
again when `smallwebwaf` next runs in `enforce` mode, as long as they last.
The timeouts and size limits still apply, since they protect `smallwebwaf` and
the app themselves, and a request for one of `smallwebwaf`'s own endpoints
@@ -338,7 +340,9 @@ effective settings are logged at start.
- `SWWAF_ALERT_WEBHOOK_URL` (default unset): the webhook each alert is posted
to, an `http` or `https` URL without a user or a fragment, such as
`https://alerts.example/smallwebwaf` (see "Alerts" below). Unset or empty, no
alert is sent.
alert is sent. Since many webhooks carry their secret in the path or the
query, the settings logged at start show `********` in place of them, and a
value that stops the start is not shown.
- `SWWAF_ALERT_WEBHOOK_HEADERS` (default empty): headers sent with each alert,
such as one that authenticates it, as a list of a name, `:` and a value, such
as `Authorization:Bearer 0123456789abcdef`. A value cannot hold a comma. The
@@ -543,9 +547,12 @@ when `SWWAF_ALERT_EVENTS` names its event:
state file set aside as `<name>.bad`, or a state file it could not write while
running.
The bans you make, in `bans.json` or through the ban endpoints, raise no alert,
and neither does what `observe` mode would have done. This is the alert for a
ban for a broken rate limit, shown indented; it is sent on one line:
The bans you make, in `bans.json` or through the ban endpoints, raise no alert.
In `observe` mode, a request that would have made a ban, or made one permanent,
raises the alert `enforce` mode would have raised, for the ban as it would have
been, with `mode`, `observe`, in its `detail`: no ban was made, or made
permanent. This is the alert for a ban for a broken rate limit, shown indented;
it is sent on one line:
```json
{
@@ -598,35 +605,37 @@ ban for a broken rate limit, shown indented; it is sent on one line:
ends as `ban_expires`, in the form the request log gives it, and its `notes`,
as `bans.json` gives them; for `source_failure`, the `source`, `geojs`, the
`error`, and when GeoJS is asked again, `asking_again_in`; for `file_error`,
the `error`, which names the file and where in it the error is, and for an
edit set aside, the `file` it was renamed to.
the `file`, which for an edit set aside is the file it was renamed to, and the
`error`, which for a file that does not parse names where in it the error is.
- `suppressed_repeats` is how many repeats the cooldown held back before this
alert.
An alert for the same event on the same netblock as the last one sent, or, for
an event without a netblock, for the same event, less than
`SWWAF_ALERT_COOLDOWN` after it, is a repeat: it is held back and counted, and
the next alert sent for them gives that count as `suppressed_repeats`. So every
`file_error` alert shares one cooldown, and so does every `source_failure`
alert.
An alert for the same event as the last one sent, on the same netblock, or for a
`file_error` about the same file, or for a `source_failure` about the same
source, less than `SWWAF_ALERT_COOLDOWN` after it, is a repeat: it is held back
and counted, and the next alert sent for them gives that count as
`suppressed_repeats`.
Past `SWWAF_ALERT_MAX_PER_HOUR` alerts in an hour of the clock, in UTC, the
hour's other alerts are held back and counted by event. Once the hour has ended,
one alert sums them up: its `event` is `summary`, its `reason` says how many
were held back, and its `detail` gives the `hour` as when it started, the
`count`, and the count for each event, as `events`. An alert held back this way
starts its cooldown as one sent does.
starts no cooldown, and the repeats held back before it are given by the next
alert sent for the same event and netblock, file or source.
The alerts wait in a queue of at most 1000, from which they are sent one at a
time, the oldest first, so a webhook that is slow or down never holds up a
request. The webhook takes an alert by answering with a 2xx status. Any other
answer, a redirect included, a connection that fails, or no answer within 10
seconds is a failure: it is logged, and the alert is sent again a second later,
twice as long after each further failure in a row, up to a minute. With 1000
alerts waiting, the oldest is dropped to make room for a new one. The cooldowns,
the hour under way and the alerts still waiting are kept in `alerts.json` (see
"State files" below), so that after a restart the alerts waiting are sent, and
the cooldowns go on.
request. The webhook takes an alert by answering with a 2xx status, and refuses
it with a 4xx status other than `408` and `429`: a refused alert is logged,
counted as dropped, and given up, so that the next is sent. Any other answer, a
redirect included, a connection that fails, or no answer within 10 seconds is a
failure: it is logged, without the webhook's URL, and the alert is sent again a
second later, twice as long after each further failure in a row, up to a minute.
With 1000 alerts waiting, the oldest is dropped to make room for a new one. The
cooldowns, the hour under way and the alerts still waiting are kept in
`alerts.json` (see "State files" below), so that after a restart the alerts
waiting are sent, and the cooldowns go on.
## State files
@@ -653,13 +662,13 @@ entries by client address, but for the alerts waiting, with times in UTC.
- `lookups.json`: GeoJS's answers, one to a line, with when GeoJS gave each and
when it was last used.
- `alerts.json`: the state of the alerts (see "Alerts" above), indented to be
read: under `cooldowns`, for each event and netblock, or event alone, when the
last alert was sent, `sent`, and the repeats held back since,
`suppressed_repeats`; under `hour`, the hour under way, from its `start`, the
alerts `sent` in it and those `held_back` for its summary, by event; and under
`waiting`, the alerts still waiting to be sent, the oldest first, each as the
webhook is sent it. As an hour ends, the cooldowns that have run out with no
repeat held back are dropped.
read: under `cooldowns`, for each event and netblock, or event and `file` or
`source`, or event alone, when the last alert was sent, `sent`, and the
repeats held back since, `suppressed_repeats`; under `hour`, the hour under
way, from its `start`, the alerts `sent` in it and those `held_back` for its
summary, by event; and under `waiting`, the alerts still waiting to be sent,
the oldest first, each as the webhook is sent it. As an hour ends, the
cooldowns that have run out with no repeat held back are dropped.
`bans.json` is written `SWWAF_STATE_WRITE_DELAY` after a ban is made, lifted
through `DELETE /_smallwebwaf/bans/<client>`, or made permanent, with every such
@@ -870,7 +879,7 @@ other request. No metric carries a client's address.
`smallwebwaf_alerts_failed_total`: the requests to it that failed;
`smallwebwaf_alerts_suppressed_total`: the alerts held back, as repeats or for
an hour's summary; and `smallwebwaf_alerts_dropped_total`: those dropped from
a full queue.
a full queue, or given up as the webhook refused them.
- Go's own `go_` metrics and the process's `process_` metrics.
The requests Go's HTTP server ends before `smallwebwaf` sees them (see "Request
+99 -42
View File
@@ -5,7 +5,8 @@
// an alert past SWWAF_ALERT_MAX_PER_HOUR, for the hour's summary. The
// others wait in a bounded queue, so that a slow or unreachable webhook
// never holds up a request. The state is written to alerts.json and read
// from it by the state package.
// from it by the state package. Nothing logged names the webhook's URL,
// whose path or query can carry a secret.
package alerts
import (
@@ -75,7 +76,12 @@ const (
maxAnswerBytes = 64 << 10
)
var errStatus = errors.New("the webhook answered")
var (
errStatus = errors.New("the webhook answered")
// errRefused is a 4xx answer other than 408 and 429: the webhook
// refuses the alert itself, and would refuse it again.
errRefused = errors.New("the webhook refused the alert, answering")
)
// Params are what New needs.
type Params struct {
@@ -114,7 +120,8 @@ type Alert struct {
ASName string `json:"as_name"`
Country string `json:"country"`
// Reason is a short sentence, and Detail what is particular to the
// event.
// event: for a file_error, its "file", and for a source_failure, its
// "source", which the cooldown tells repeats by.
Reason string `json:"reason"`
Detail map[string]any `json:"detail"`
// SuppressedRepeats is how many repeats of the alert the cooldown
@@ -122,14 +129,16 @@ type Alert struct {
SuppressedRepeats int `json:"suppressed_repeats"`
}
// Cooldown is, for an event on a netblock, or for an event without a
// netblock, when the last alert let through was raised, and how many
// repeats the cooldown has held back since, as alerts.json holds it.
// Cooldown is, for an event on a netblock, or about a file or a source,
// when the last alert let through was raised, and how many repeats the
// cooldown has held back since, as alerts.json holds it.
//
//nolint:tagliatelle // the state files use snake_case, as the request log does
type Cooldown struct {
Event string `json:"event"`
Netblock netip.Prefix `json:"netblock"`
File string `json:"file,omitempty"`
Source string `json:"source,omitempty"`
Sent time.Time `json:"sent"`
SuppressedRepeats int `json:"suppressed_repeats"`
}
@@ -164,7 +173,8 @@ type Queue struct {
queued chan struct{}
mu sync.Mutex
// cooldowns are the alerts last let through, by event and netblock.
// cooldowns are the alerts last let through, by event and netblock,
// file or source.
cooldowns map[cooldownKey]*Cooldown
hour Hour
// waiting are the alerts waiting to be sent, oldest first.
@@ -174,10 +184,21 @@ type Queue struct {
}
// cooldownKey is what makes an alert a repeat of another: the same event
// on the same netblock, which is none for an event without one.
// on the same netblock, and about the same file or source, as its detail
// names them. Each is empty for an alert without one.
type cooldownKey struct {
event string
netblock netip.Prefix
file string
source string
}
// cooldownKeyOf returns what makes another alert a repeat of alert.
func cooldownKeyOf(alert *Alert) cooldownKey {
file, _ := alert.Detail["file"].(string)
source, _ := alert.Detail["source"].(string)
return cooldownKey{alert.Event, alert.Netblock, file, source}
}
// New returns a Queue with no alert yet.
@@ -201,9 +222,11 @@ func New(params Params) *Queue {
// one let through less than Cooldown before is held back and counted,
// and the next one let through gives that count. Past MaxPerHour alerts
// let through in the hour under way, by the clock, an alert is held back
// for that hour's summary instead, which is sent once the hour has ended.
// Raise never waits: an alert let through joins the queue, from which Run
// sends it, and with queueSize alerts waiting the oldest is dropped.
// for that hour's summary instead, which is sent once the hour has ended;
// it starts no cooldown, and the repeats held back before it are given by
// the next alert let through. Raise never waits: an alert let through
// joins the queue, from which Run sends it, and with queueSize alerts
// waiting the oldest is dropped.
func (q *Queue) Raise(alert Alert) {
if q.params.WebhookURL == nil || !slices.Contains(q.params.Events, alert.Event) {
return
@@ -231,13 +254,16 @@ func (q *Queue) Raise(alert Alert) {
return
}
q.startCooldown(&alert, now)
q.hour.Sent++
q.queue(&alert)
}
// Run sends the alerts waiting, oldest first, until ctx is done. An alert
// stays in the queue until the webhook answers it with a 2xx status. A
// request that fails is logged, and the alert sent again
// stays in the queue until the webhook answers it with a 2xx status, or
// refuses it with a 4xx status other than 408 and 429: a refused alert is
// logged, counted as dropped, and given up, so that the next is sent. Any
// other request that fails is logged, and the alert sent again
// firstRetryDelay later, retryDelayFactor times as long after each
// further failure in a row, up to maxRetryDelay. Run also ends each hour
// as Raise does, so that the hour's summary is sent as it ends. With no
@@ -281,6 +307,16 @@ func (q *Queue) Run(ctx context.Context) {
retryDelay = 0
retryAt = time.Time{}
case errors.Is(err, errRefused):
q.remove(alert)
q.failed.Add(1)
q.dropped.Add(1)
retryDelay = 0
retryAt = time.Time{}
q.params.ProcessLog.Warn("gave up an alert SWWAF_ALERT_WEBHOOK_URL refused",
"event", alert.Event, "error", err.Error())
case ctx.Err() == nil: // not cut off as smallwebwaf stops
q.failed.Add(1)
@@ -313,13 +349,14 @@ func (q *Queue) Suppressed() int64 {
return q.suppressed.Load()
}
// Dropped is how many alerts were dropped from a full queue.
// Dropped is how many alerts were dropped from a full queue, or given up
// as the webhook refused them.
func (q *Queue) Dropped() int64 {
return q.dropped.Load()
}
// Snapshot returns the queue's state, as alerts.json holds it, with the
// cooldowns sorted by netblock, then by event.
// cooldowns sorted by netblock, then by event, file and source.
func (q *Queue) Snapshot() State {
q.mu.Lock()
defer q.mu.Unlock()
@@ -336,11 +373,8 @@ func (q *Queue) Snapshot() State {
}
slices.SortFunc(state.Cooldowns, func(a, b Cooldown) int {
if order := a.Netblock.Compare(b.Netblock); order != 0 {
return order
}
return cmp.Compare(a.Event, b.Event)
return cmp.Or(a.Netblock.Compare(b.Netblock), cmp.Compare(a.Event, b.Event),
cmp.Compare(a.File, b.File), cmp.Compare(a.Source, b.Source))
})
for _, alert := range q.waiting {
@@ -362,7 +396,8 @@ func (q *Queue) Load(state State) {
for _, cooldown := range state.Cooldowns {
cooldown.Netblock = cooldown.Netblock.Masked()
q.cooldowns[cooldownKey{cooldown.Event, cooldown.Netblock}] = &cooldown
key := cooldownKey{cooldown.Event, cooldown.Netblock, cooldown.File, cooldown.Source}
q.cooldowns[key] = &cooldown
}
q.hour = state.Hour
@@ -380,30 +415,41 @@ func (q *Queue) Load(state State) {
}
// repeat reports whether alert, raised at now, repeats the last one let
// through less than Cooldown before, and counts it if it does. Otherwise
// it gives alert the count of the repeats held back since that one, and
// notes alert as the last one let through.
// through less than Cooldown before, and counts it if it does.
func (q *Queue) repeat(alert *Alert, now time.Time) bool {
if q.params.Cooldown == 0 {
return false
}
key := cooldownKey{alert.Event, alert.Netblock}
last, found := q.cooldowns[key]
if found && now.Sub(last.Sent) < q.params.Cooldown {
last.SuppressedRepeats++
return true
last, found := q.cooldowns[cooldownKeyOf(alert)]
if !found || now.Sub(last.Sent) >= q.params.Cooldown {
return false
}
last.SuppressedRepeats++
return true
}
// startCooldown gives alert, let through at now, the count of the repeats
// held back since the last one let through, and notes alert as the last
// one let through.
func (q *Queue) startCooldown(alert *Alert, now time.Time) {
if q.params.Cooldown == 0 {
return
}
key := cooldownKeyOf(alert)
last, found := q.cooldowns[key]
if found {
alert.SuppressedRepeats = last.SuppressedRepeats
}
q.cooldowns[key] = &Cooldown{Event: alert.Event, Netblock: alert.Netblock, Sent: now}
return false
q.cooldowns[key] = &Cooldown{
Event: alert.Event, Netblock: alert.Netblock, File: key.file, Source: key.source,
Sent: now,
}
}
// endHour ends the hour under way, if now is past it: it queues that
@@ -474,10 +520,10 @@ func (q *Queue) next() (*Alert, time.Duration) {
return oldest, q.hour.Start.Add(time.Hour).Sub(q.params.Now())
}
// remove takes alert, which Run has sent, out of the queue, unless it has
// been dropped from it, or Load has replaced the queue, since Run took it.
// Only the oldest alert is ever dropped, so alert is the oldest if it is
// there at all.
// remove takes alert, which Run has sent or given up, out of the queue,
// unless it has been dropped from it, or Load has replaced the queue,
// since Run took it. Only the oldest alert is ever dropped, so alert is
// the oldest if it is there at all.
func (q *Queue) remove(alert *Alert) {
q.mu.Lock()
defer q.mu.Unlock()
@@ -488,7 +534,9 @@ func (q *Queue) remove(alert *Alert) {
}
// send posts alert to the webhook as JSON, with WebhookHeaders, and
// returns an error unless the webhook answers with a 2xx status.
// returns an error unless the webhook answers with a 2xx status: one that
// wraps errRefused for a 4xx status other than 408 and 429. No error
// names the webhook's URL, whose path or query can carry a secret.
func (q *Queue) send(ctx context.Context, alert *Alert) error {
body, err := json.Marshal(alert)
if err != nil {
@@ -509,6 +557,11 @@ func (q *Queue) send(ctx context.Context, alert *Alert) error {
res, err := q.httpClient.Do(req)
if err != nil {
// The client's error names the URL: only what went wrong is kept.
if urlErr, ok := errors.AsType[*url.Error](err); ok {
return urlErr.Err
}
return err
}
@@ -519,9 +572,13 @@ func (q *Queue) send(ctx context.Context, alert *Alert) error {
// Read, so that the connection can be used again.
_, _ = io.Copy(io.Discard, io.LimitReader(res.Body, maxAnswerBytes))
if res.StatusCode < http.StatusOK || res.StatusCode >= http.StatusMultipleChoices {
switch status := res.StatusCode; {
case status >= http.StatusOK && status < http.StatusMultipleChoices:
return nil
case status >= http.StatusBadRequest && status < http.StatusInternalServerError &&
status != http.StatusRequestTimeout && status != http.StatusTooManyRequests:
return fmt.Errorf("%w %s", errRefused, res.Status)
default:
return fmt.Errorf("%w %s", errStatus, res.Status)
}
return nil
}
+190 -12
View File
@@ -184,6 +184,65 @@ func TestRepeatWithinTheCooldownIsHeldBackAndCountedInTheNext(t *testing.T) {
})
}
func TestFileErrorAndSourceFailureRepeatOnlyForTheSameFileOrSource(t *testing.T) {
t.Parallel()
synctest.Test(t, func(t *testing.T) {
params := newParams()
webhook, q := start(t, params)
fileError := func(file string) alerts.Alert {
return alerts.Alert{
Event: alerts.EventFileError,
Detail: map[string]any{"file": file, "error": "line 2: an error"},
}
}
sourceFailure := func(source string) alerts.Alert {
return alerts.Alert{
Event: alerts.EventSourceFailure, Detail: map[string]any{"source": source},
}
}
// Another file, or another source, is no repeat.
q.Raise(fileError("/rules.d/50-a.rules"))
q.Raise(fileError("/rules.d/50-b.rules"))
q.Raise(fileError("/rules.d/50-a.rules"))
q.Raise(sourceFailure("geojs"))
q.Raise(sourceFailure("abuseipdb"))
q.Raise(sourceFailure("geojs"))
synctest.Wait()
// Each alert is named by its file, or its source.
got := make([]string, 0, len(webhook.received()))
for _, request := range webhook.received() {
detail, _ := request.alert["detail"].(map[string]any)
file, _ := detail["file"].(string)
source, _ := detail["source"].(string)
got = append(got, file+source)
}
want := []string{
"/rules.d/50-a.rules", "/rules.d/50-b.rules", "geojs", "abuseipdb",
}
if !slices.Equal(got, want) {
t.Errorf("the webhook was sent alerts for %v, want %v", got, want)
}
wantCounts(t, q, 4, 0, 2, 0)
// alerts.json keeps each file's cooldown: a new queue holds back
// the next for the first file, and sends the one for a third.
after := alerts.New(params)
after.Load(roundTrip(t, q.Snapshot()))
after.Raise(fileError("/rules.d/50-a.rules"))
after.Raise(fileError("/rules.d/50-c.rules"))
waiting := after.Snapshot().Waiting
if len(waiting) != 1 || waiting[0].Detail["file"] != "/rules.d/50-c.rules" {
t.Errorf("after loading, alerts wait %+v, want the one for 50-c.rules", waiting)
}
})
}
func TestNoCooldownSendsEveryRepeat(t *testing.T) {
t.Parallel()
@@ -261,6 +320,50 @@ func TestAlertsPastTheHourlyLimitAreRolledIntoOneSummary(t *testing.T) {
})
}
func TestRepeatsBeforeAnAlertPastTheHourlyLimitAreGivenByTheNextSent(t *testing.T) {
t.Parallel()
synctest.Test(t, func(t *testing.T) {
params := newParams()
params.MaxPerHour = 1
webhook, q := start(t, params)
raise := func() {
q.Raise(alerts.Alert{Event: alerts.EventBan, Netblock: netblock(1)})
}
// The hour's one alert, and two repeats the cooldown holds back.
raise()
raise()
raise()
// Once the cooldown has run out, the next is past the hourly limit.
time.Sleep(cooldown)
raise()
// The next hour's first alert gives the two repeats, and the summary
// the alert past the limit.
time.Sleep(time.Hour - cooldown)
synctest.Wait()
raise()
synctest.Wait()
wantEvents(t, webhook, alerts.EventBan, alerts.EventSummary, alerts.EventBan)
got := webhook.received()
if len(got) == 3 {
detail, _ := got[1].alert["detail"].(map[string]any)
repeats := got[2].alert["suppressed_repeats"]
if detail["count"] != float64(1) || repeats != float64(2) {
t.Errorf("the summary counts %v alerts, and the last alert gives %v "+
"repeats, want 1 and 2", detail["count"], repeats)
}
}
wantCounts(t, q, 3, 0, 3, 0)
})
}
func TestFailedRequestIsSentAgainWithBackoff(t *testing.T) {
t.Parallel()
@@ -318,6 +421,82 @@ func TestFailedRequestIsSentAgainWithBackoff(t *testing.T) {
})
}
func TestRefusedAlertIsGivenUpAndTheNextSent(t *testing.T) {
t.Parallel()
synctest.Test(t, func(t *testing.T) {
params := newParams()
log := &lockedBuffer{}
params.ProcessLog = slog.New(slog.NewJSONHandler(log, nil))
webhook, q := start(t, params)
// 429 and 408 are failures, and the alert is sent again; 400 refuses
// it, and it is given up.
webhook.set(http.StatusTooManyRequests)
q.Raise(alerts.Alert{Event: alerts.EventBan, Netblock: netblock(1)})
synctest.Wait()
webhook.set(http.StatusRequestTimeout)
time.Sleep(time.Second)
synctest.Wait()
webhook.set(refusing)
time.Sleep(2 * time.Second)
synctest.Wait()
// The next alert is sent at once.
webhook.set(answering)
q.Raise(alerts.Alert{Event: alerts.EventBan, Netblock: netblock(2)})
time.Sleep(time.Minute)
synctest.Wait()
// Each request, by when it was sent, and the netblock of its alert.
got := make([]string, 0, len(webhook.received()))
for _, request := range webhook.received() {
block, _ := request.alert["netblock"].(string)
got = append(got, request.at.Sub(midnight()).String()+" "+block)
}
want := []string{
"0s " + netblock(1).String(), "1s " + netblock(1).String(),
"3s " + netblock(1).String(), "3s " + netblock(2).String(),
}
if !slices.Equal(got, want) {
t.Errorf("requests %v, want %v", got, want)
}
wantCounts(t, q, 1, 3, 0, 1)
if !strings.Contains(log.String(),
`"msg":"gave up an alert SWWAF_ALERT_WEBHOOK_URL refused"`) {
t.Errorf("process log %q names no alert given up", log.String())
}
})
}
func TestFailedRequestIsLoggedWithoutTheURL(t *testing.T) {
t.Parallel()
synctest.Test(t, func(t *testing.T) {
params := newParams()
log := &lockedBuffer{}
params.ProcessLog = slog.New(slog.NewJSONHandler(log, nil))
webhook, q := start(t, params)
webhook.set(hanging)
// The request is abandoned after 10 seconds, with an error from the
// HTTP client, which names the URL.
q.Raise(alerts.Alert{Event: alerts.EventBan, Netblock: netblock(1)})
time.Sleep(11 * time.Second)
synctest.Wait()
logged := log.String()
if !strings.Contains(logged,
`"msg":"sending an alert to SWWAF_ALERT_WEBHOOK_URL failed"`) ||
strings.Contains(logged, "alerts.example") || strings.Contains(logged, "team=ops") {
t.Errorf("process log %q names no failure, or names the URL", logged)
}
})
}
func TestFullQueueDropsTheOldestAndRaiseNeverWaits(t *testing.T) {
t.Parallel()
@@ -419,11 +598,13 @@ func TestStateLoadedIntoANewQueueCarriesOn(t *testing.T) {
})
}
// How the stand-in for the webhook answers.
// How the stand-in for the webhook answers: with a status, or, hanging,
// not at all, until the request is abandoned.
const (
answering = iota // with 204
failing // with 503
hanging // not at all, until the request is abandoned
answering = http.StatusNoContent
failing = http.StatusServiceUnavailable
refusing = http.StatusBadRequest
hanging = 0
)
// standIn is a stand-in for the webhook. It notes each request it is
@@ -479,17 +660,14 @@ func (s *standIn) ServeHTTP(w http.ResponseWriter, r *http.Request) {
})
s.mu.Unlock()
switch answers {
case failing:
w.WriteHeader(http.StatusServiceUnavailable)
case hanging:
if answers == hanging {
<-r.Context().Done()
default:
w.WriteHeader(http.StatusNoContent)
} else {
w.WriteHeader(answers)
}
}
// set sets how the stand-in answers.
// set sets how the stand-in answers: with the status answers, or hanging.
func (s *standIn) set(answers int) {
s.mu.Lock()
defer s.mu.Unlock()
@@ -553,7 +731,7 @@ func newParams() alerts.Params {
func start(t *testing.T, params alerts.Params) (*standIn, *alerts.Queue) {
t.Helper()
webhook := &standIn{}
webhook := &standIn{answers: answering}
q := alerts.New(params)
q.SetTransport(webhook)
+2 -2
View File
@@ -134,7 +134,7 @@ func TestLiftedBanForAnAttackRefusesNothingAndMakesNoBanLonger(t *testing.T) {
now := midnight().Add(2 * time.Hour)
_, banned := ledger.Find(netblock.Addr(), now)
_, banned, _ := ledger.Find(netblock.Addr(), now)
if banned {
t.Error("the lifted ban refuses")
}
@@ -220,7 +220,7 @@ func TestAdminsBanIsMadeWhileAnotherLasts(t *testing.T) {
}
// It refuses once the ban for the limit has ended.
ban, banned := ledger.Find(netblock.Addr(), midnight().Add(2*time.Hour))
ban, banned, _ := ledger.Find(netblock.Addr(), midnight().Add(2*time.Hour))
if !banned || ban != want {
t.Errorf("after the limit's ban the netblock is under %+v (%t), want %+v",
ban, banned, want)
+41 -10
View File
@@ -218,17 +218,19 @@ func (l *Ledger) Check(client netip.Addr, now time.Time) (Ban, bool, bool) {
}
// Find is Check without counting the request among those the ban
// refused: in observe mode a ban refuses nothing.
func (l *Ledger) Find(client netip.Addr, now time.Time) (Ban, bool) {
// refused, and without making the ban permanent: in observe mode a ban
// refuses nothing. The last result reports whether Check would have made
// the ban permanent.
func (l *Ledger) Find(client netip.Addr, now time.Time) (Ban, bool, bool) {
l.mu.Lock()
defer l.mu.Unlock()
ban := l.active(client, now)
if ban == nil {
return Ban{}, false
return Ban{}, false, false
}
return *ban, true
return *ban, true, ban.Cause == CauseAttack && !ban.Permanent()
}
// activeBan returns the ban in bans, a netblock's bans oldest first, that
@@ -258,10 +260,15 @@ func activeBan(bans []Ban, now time.Time) *Ban {
func (l *Ledger) BanForLimit(
netblock netip.Prefix, now time.Time, notes Notes,
) (Ban, bool) {
reason := fmt.Sprintf("requests per %s over the limit of %d",
notes.Window, notes.Limit)
return l.ban(netblock, now, CauseLimit, limitReason(notes), notes, true)
}
return l.ban(netblock, now, CauseLimit, reason, notes)
// WouldBanForLimit returns what BanForLimit would, without making the ban:
// what observe mode would have done.
func (l *Ledger) WouldBanForLimit(
netblock netip.Prefix, now time.Time, notes Notes,
) (Ban, bool) {
return l.ban(netblock, now, CauseLimit, limitReason(notes), notes, false)
}
// BanForAttack bans netblock at now for a clear sign of attack, with
@@ -272,7 +279,26 @@ func (l *Ledger) BanForLimit(
func (l *Ledger) BanForAttack(
netblock netip.Prefix, now time.Time, notes Notes,
) (Ban, bool) {
return l.ban(netblock, now, CauseAttack, "matched the rule "+notes.RuleID, notes)
return l.ban(netblock, now, CauseAttack, attackReason(notes), notes, true)
}
// WouldBanForAttack returns what BanForAttack would, without making the
// ban: what observe mode would have done.
func (l *Ledger) WouldBanForAttack(
netblock netip.Prefix, now time.Time, notes Notes,
) (Ban, bool) {
return l.ban(netblock, now, CauseAttack, attackReason(notes), notes, false)
}
// limitReason is the reason of a ban for a broken limit, with notes.
func limitReason(notes Notes) string {
return fmt.Sprintf("requests per %s over the limit of %d", notes.Window, notes.Limit)
}
// attackReason is the reason of a ban for a clear sign of attack, with
// notes.
func attackReason(notes Notes) string {
return "matched the rule " + notes.RuleID
}
// BanForAdmin bans netblock at now for an admin, with reason, until
@@ -491,9 +517,10 @@ func (l *Ledger) holds(netblock netip.Prefix, start time.Time) bool {
// ban bans netblock at now for cause, with reason and notes, as
// BanForLimit and BanForAttack describe, and returns the ban, and whether
// it made it.
// it made it. Unless keep is true, the ban is not made, only returned: it
// is the ban that would have been made.
func (l *Ledger) ban(
netblock netip.Prefix, now time.Time, cause, reason string, notes Notes,
netblock netip.Prefix, now time.Time, cause, reason string, notes Notes, keep bool,
) (Ban, bool) {
l.mu.Lock()
defer l.mu.Unlock()
@@ -521,6 +548,10 @@ func (l *Ledger) ban(
ban.Expires = l.limitExpiry(held, now)
}
if !keep {
return ban, true
}
l.add(ban)
l.made[cause]++
l.markChanged()
+54 -6
View File
@@ -181,12 +181,12 @@ func TestFindCountsNothing(t *testing.T) {
netblock := netip.MustParsePrefix("203.0.113.9/32")
ban, _ := ledger.BanForLimit(netblock, midnight(), bans.Notes{Requests: 5})
got, banned := ledger.Find(netblock.Addr(), ban.Expires.Add(-time.Nanosecond))
got, banned, _ := ledger.Find(netblock.Addr(), ban.Expires.Add(-time.Nanosecond))
if !banned || got != ban {
t.Errorf("find during the ban gives %+v and %t, want %+v", got, banned, ban)
}
_, banned = ledger.Find(netblock.Addr(), ban.Expires)
_, banned, _ = ledger.Find(netblock.Addr(), ban.Expires)
if banned {
t.Error("the ban did not end")
}
@@ -272,12 +272,16 @@ func TestRequestDuringAnAttackBanMakesItPermanent(t *testing.T) {
wantChanged(t, ledger, true)
// In observe mode the ban refuses nothing, and stays as it is.
got, _ := ledger.Find(netblock.Addr(), midnight().Add(time.Hour))
if got.Permanent() {
t.Fatal("a request found under the ban made it permanent")
// In observe mode the ban refuses nothing, and stays as it is, while
// Find tells that the request would have made it permanent.
got, _, wouldMakePermanent := ledger.Find(netblock.Addr(), midnight().Add(time.Hour))
if got.Permanent() || ledger.Bans(netblock)[0].Permanent() || !wouldMakePermanent {
t.Fatalf("a request found under the ban left it %+v, would have made it "+
"permanent %t, want it as it was, and true", got, wouldMakePermanent)
}
wantChanged(t, ledger, false)
// A request it refuses makes it permanent, says so, and makes
// bans.json due.
got, _, madePermanent := ledger.Check(netblock.Addr(), midnight().Add(time.Hour))
@@ -328,6 +332,50 @@ func TestAttackAfterAnAttackBanHasEndedBansPermanently(t *testing.T) {
}
}
func TestWouldBanGivesTheBanWithoutMakingIt(t *testing.T) {
t.Parallel()
ledger := bans.New(defaultRules())
netblock := netip.MustParsePrefix("203.0.113.9/32")
first, _ := ledger.BanForLimit(netblock, midnight(), bans.Notes{})
wantChanged(t, ledger, true)
// While the first ban lasts, none would be made.
during, would := ledger.WouldBanForAttack(netblock, midnight(), bans.Notes{})
if would || during != first {
t.Errorf("during the first ban, would ban %t with %+v, want false with %+v",
would, during, first)
}
// As it ends, a clear sign of attack would ban for seven days, and a
// limit broken again for three hours, but neither is made.
limitNotes := bans.Notes{Limit: 1, Window: "minute"}
attack, wouldAttack := ledger.WouldBanForAttack(netblock, first.Expires,
bans.Notes{RuleID: "git-dir"})
limit, wouldLimit := ledger.WouldBanForLimit(netblock, first.Expires, limitNotes)
if !wouldAttack || !attack.Expires.Equal(first.Expires.Add(7*day)) ||
attack.Reason != "matched the rule git-dir" || !wouldLimit ||
!limit.Expires.Equal(first.Expires.Add(3*time.Hour)) ||
limit.Reason != "requests per minute over the limit of 1" {
t.Errorf("would ban with %+v and %+v, want seven days for the attack and "+
"three hours for the limit", attack, limit)
}
if len(ledger.Bans(netblock)) != 1 || ledger.Made(bans.CauseLimit) != 1 ||
ledger.Made(bans.CauseAttack) != 0 {
t.Errorf("the ledger holds %+v, want the first ban alone", ledger.Bans(netblock))
}
wantChanged(t, ledger, false)
// The ban made is the one that would have been.
made, _ := ledger.BanForLimit(netblock, first.Expires, limitNotes)
if made != limit {
t.Errorf("the ban made is %+v, want %+v", made, limit)
}
}
func TestAttackBanDoesNotLengthenTheNextBanForALimit(t *testing.T) {
t.Parallel()
+1 -1
View File
@@ -150,7 +150,7 @@ func TestPermanentBanStartedBeforeAnEndedOneRefuses(t *testing.T) {
now := midnight().Add(2 * time.Hour)
client := netip.MustParseAddr("203.0.113.9")
ban, banned := ledger.Find(client, now)
ban, banned, _ := ledger.Find(client, now)
if !banned || !ban.Permanent() {
t.Errorf("find gives %+v and %t, want the permanent ban", ban, banned)
}
+24 -13
View File
@@ -190,7 +190,8 @@ const (
ipv4Bits = 32
// minTokenLength is the fewest characters a token may have.
minTokenLength = 32
// masked is what the log shows for a token that is set.
// masked is what the log shows for a token that is set, and in place of
// a secret in another setting.
masked = "********"
// defaultListenAddr and defaultUpstreamURL are the defaults of
// SWWAF_LISTEN_ADDR and SWWAF_UPSTREAM_URL.
@@ -667,14 +668,13 @@ func (e *environment) appName(name, instanceName string, sending bool) string {
}
// webhookURL reads the setting that is where each alert is posted. Unset
// or empty, it is nil, and no alert is sent.
// or empty, it is nil, and no alert is sent. The log shows ******** in
// place of its path and query, and an error shows none of it, since many
// webhooks carry their secret there.
func (e *environment) webhookURL(name string) *url.URL {
value := e.value(name, "")
if value == "" {
return nil
}
webhook, err := parseWebhookURL(value)
value, _ := e.lookup(name)
webhook, logged, err := parseWebhookURL(value)
e.settings = append(e.settings, slog.String(name, logged))
e.check(name, err)
return webhook
@@ -1126,11 +1126,17 @@ func parseFacility(value string) (int, error) {
// parseWebhookURL reads where each alert is posted: http or https, a
// host, and an optional port from 1 to 65535, path and query, without a
// user or a fragment.
func parseWebhookURL(value string) (*url.URL, error) {
// user or a fragment. It returns the URL, and how the log shows it: its
// scheme and host, and ******** in place of its path and query, if it has
// either. An error shows no part of the value. An empty value is no URL.
func parseWebhookURL(value string) (*url.URL, string, error) {
if value == "" {
return nil, "", nil
}
webhook, err := url.Parse(value)
if err != nil {
return nil, fmt.Errorf("%q %w", value, errNotWebhookURL)
return nil, "", errNotWebhookURL
}
port, err := strconv.ParseUint(webhook.Port(), 10, 16)
@@ -1139,10 +1145,15 @@ func parseWebhookURL(value string) (*url.URL, error) {
webhook.Hostname() != "" && (webhook.Port() == "" || (err == nil && port != 0)) &&
webhook.User == nil && webhook.Opaque == "" && webhook.Fragment == ""
if !valid {
return nil, fmt.Errorf("%q %w", value, errNotWebhookURL)
return nil, "", errNotWebhookURL
}
return webhook, nil
logged := webhook.Scheme + "://" + webhook.Host
if webhook.Path != "" || webhook.RawQuery != "" {
logged += "/" + masked
}
return webhook, logged, nil
}
// parseWebhookHeaders reads a comma-separated list of headers, each its
+38
View File
@@ -598,6 +598,44 @@ func TestWebhookHeadersAreLoggedMaskedAndNeverShown(t *testing.T) {
}
}
func TestWebhookURLIsLoggedWithoutItsPathOrQueryAndNeverShown(t *testing.T) {
t.Parallel()
const secret = "T0123/B4567/abcdef"
for value, want := range map[string]string{
"https://hooks.example/services/" + secret: "https://hooks.example/********",
"https://hooks.example:8443?token=" + secret: "https://hooks.example:8443/********",
"http://[2001:db8::1]:8080": "http://[2001:db8::1]:8080",
} {
cfg := fromEnvironment(t, environment{alertWebhookURL: value})
var out bytes.Buffer
slog.New(slog.NewJSONHandler(&out, nil)).Info("starting", "settings", cfg)
logged := out.String()
if strings.Contains(logged, secret) ||
!strings.Contains(logged, `"`+alertWebhookURL+`":"`+want+`"`) {
t.Errorf("%s is not logged as %s: %s", value, want, logged)
}
}
// A value that is not such a URL is not shown either.
for _, value := range []string{
"ftp://hooks.example/services/" + secret,
"https://hooks.example/services/%zz" + secret,
} {
_, err := config.FromEnvironment(environment{alertWebhookURL: value}.lookupEnv)
want := alertWebhookURL + ": is not an http or https URL without a user or " +
"a fragment, such as https://alerts.example/smallwebwaf"
if err == nil || err.Error() != want {
t.Errorf("error %v, want %s", err, want)
}
}
}
func TestCodeOnBothCountryListsStopsTheStart(t *testing.T) {
t.Parallel()
+3 -2
View File
@@ -257,8 +257,9 @@ func (m *Metrics) AddAlerts(queue *alerts.Queue) {
return float64(queue.Suppressed())
}),
prometheus.NewCounterFunc(prometheus.CounterOpts{
Name: "smallwebwaf_alerts_dropped_total",
Help: "Alerts dropped, the oldest first, from a full queue.",
Name: "smallwebwaf_alerts_dropped_total",
Help: "Alerts dropped, the oldest first, from a full queue, and alerts " +
"given up as the destination refused them.",
ConstLabels: webhook,
}, func() float64 {
return float64(queue.Dropped())
+76 -25
View File
@@ -39,19 +39,10 @@ func TestBanForABrokenLimitRaisesABanAlertWithItsNotes(t *testing.T) {
clk.advance(time.Minute)
s.get(client, http.StatusForbidden, requestlog.ActionBanned)
wantAlerts(t, queue, alerts.Alert{
Instance: alertInstance,
Time: start,
Event: alerts.EventBan,
Client: netip.MustParseAddr(client),
Netblock: netblock,
Reason: "requests per minute over the limit of 1",
Detail: map[string]any{
"cause": bans.CauseLimit,
"ban_expires": requestlog.FormatTime(start.Add(time.Hour)),
"notes": ban.Notes,
},
})
wantAlerts(t, queue, banAlert(alerts.EventBan, start, client, bans.Ban{
Netblock: netblock, Cause: bans.CauseLimit,
Reason: "requests per minute over the limit of 1", Notes: ban.Notes,
}, requestlog.FormatTime(start.Add(time.Hour))))
if ban.Notes.Limit != 1 || ban.Notes.Request.Path != "/" {
t.Errorf("the alert's notes are %+v, want those of the broken limit", ban.Notes)
@@ -101,20 +92,69 @@ func TestAttackBanRaisesABanAlertThenAPermanentBanAlert(t *testing.T) {
)
}
func TestObserveModeRaisesNoBanAlert(t *testing.T) {
func TestObserveModeRaisesTheBanAlertsItWouldHave(t *testing.T) {
t.Parallel()
s, _, _, queue := startWithAlerts(t, map[string]string{
mode: "observe",
rateLimitPerMinute: "1",
s, clk, server, queue := startWithAlerts(t, map[string]string{
mode: observe,
rateLimitPerMinute: "2",
rulesDir: writeRules(t, testRules),
})
start := clk.Now()
// A ban for a clear sign of attack, which a request under it would make
// permanent.
group := netip.MustParsePrefix(ipv6Group)
attackBan, _ := server.Ledger.BanForAttack(group, start, bans.Notes{RuleID: "probe"})
// The third request breaks the limit, and so does the fourth, a repeat
// the cooldown holds back. The probe is a clear sign of attack.
for range 4 {
s.get(client, http.StatusOK, requestlog.ActionForward)
}
s.get(client, http.StatusOK, requestlog.ActionForward)
s.get(client, http.StatusOK, requestlog.ActionForward)
s.request(otherClient, "/.env", http.StatusOK, requestlog.ActionForward)
line := s.get(ipv6Client, http.StatusOK, requestlog.ActionForward)
wantAlerts(t, queue)
// No ban is made, and none made permanent.
if held := server.Ledger.Snapshot(); len(held) != 1 || held[0] != attackBan ||
line.BanExpires != requestlog.FormatTime(attackBan.Expires) {
t.Errorf("the ledger holds %+v, and the log line gives %s, want the ban "+
"for the attack alone, as it was", held, line.BanExpires)
}
waiting := queue.Snapshot().Waiting
if len(waiting) != 3 || queue.Suppressed() != 1 {
t.Fatalf("%d alerts wait and %d are held back, want 3 and 1: %+v",
len(waiting), queue.Suppressed(), waiting)
}
limitNotes, _ := waiting[0].Detail["notes"].(bans.Notes)
attackNotes, _ := waiting[1].Detail["notes"].(bans.Notes)
if limitNotes.Limit != 2 || limitNotes.Request.Path != "/" ||
attackNotes.Request.Path != "/.env" {
t.Errorf("the notes are %+v and %+v, want those of the broken limit and "+
"of the probe", limitNotes, attackNotes)
}
// Each alert is the one enforce mode would have raised, with mode
// observe in its detail.
want := []alerts.Alert{
banAlert(alerts.EventBan, start, client, bans.Ban{
Netblock: netip.MustParsePrefix(client + "/32"), Cause: bans.CauseLimit,
Reason: "requests per minute over the limit of 2", Notes: limitNotes,
}, requestlog.FormatTime(start.Add(time.Hour))),
attackAlert(alerts.EventBan, start, otherClient, bans.Ban{
Netblock: netip.MustParsePrefix(otherClient + "/32"), Notes: attackNotes,
}, requestlog.FormatTime(start.Add(7*24*time.Hour))),
attackAlert(alerts.EventPermanentBan, start, ipv6Client, attackBan, permanent),
}
for _, alert := range want {
alert.Detail["mode"] = observe
}
wantAlerts(t, queue, want...)
}
// startWithAlerts is startWithClock with alerts to a webhook, which is
@@ -138,10 +178,10 @@ func startWithAlerts(
return &sender{t: t, addr: addr, out: out}, clk, server, queue
}
// attackAlert returns the alert for event, raised by a request from client
// at the time raised, for ban, a ban for the probe rule of testRules,
// banAlert returns the alert for event, raised by a request from client at
// the time raised, for ban, with its netblock, cause, reason and notes,
// which ends at expires, as the log line gives it.
func attackAlert(
func banAlert(
event string, raised time.Time, client string, ban bans.Ban, expires string,
) alerts.Alert {
return alerts.Alert{
@@ -150,13 +190,24 @@ func attackAlert(
Event: event,
Client: netip.MustParseAddr(client),
Netblock: ban.Netblock,
Reason: "matched the rule probe",
Reason: ban.Reason,
Detail: map[string]any{
"cause": bans.CauseAttack, "ban_expires": expires, "notes": ban.Notes,
"cause": ban.Cause, "ban_expires": expires, "notes": ban.Notes,
},
}
}
// attackAlert is banAlert for a ban for the probe rule of testRules, with
// the netblock and the notes of ban.
func attackAlert(
event string, raised time.Time, client string, ban bans.Ban, expires string,
) alerts.Alert {
return banAlert(event, raised, client, bans.Ban{
Netblock: ban.Netblock, Cause: bans.CauseAttack, Reason: "matched the rule probe",
Notes: ban.Notes,
}, expires)
}
// wantAlerts checks the alerts waiting in queue, in order.
func wantAlerts(t *testing.T, queue *alerts.Queue, want ...alerts.Alert) {
t.Helper()
+54 -30
View File
@@ -18,28 +18,24 @@ func (rq *request) banResponse(action string) *refusal {
// banned reports whether a ban on a netblock the client is in covers the
// request at now, and notes for the log line when that ban ends. A
// request that makes the ban permanent raises the alert for it.
// request that makes the ban permanent, or in observe mode would have,
// raises the alert for it.
func (rq *request) banned(now time.Time) bool {
var (
ban bans.Ban
banned bool
madePermanent bool
)
check := rq.h.ledger.Check
if rq.h.config.Observe {
ban, banned = rq.h.ledger.Find(rq.client, now) // the ban refuses nothing
} else {
ban, banned, madePermanent = rq.h.ledger.Check(rq.client, now)
check = rq.h.ledger.Find // the ban refuses nothing, and stays as it is
}
ban, banned, madePermanent := check(rq.client, now)
if banned {
rq.line.BanExpires = banExpires(ban)
}
if madePermanent {
ban.Expires = time.Time{} // the ban made permanent, which Find leaves as it is
rq.alertBan(ban)
}
if banned {
rq.line.BanExpires = banExpires(ban)
}
return banned
}
@@ -47,7 +43,8 @@ func (rq *request) banned(now time.Time) bool {
// client's counts for the log line, and reports whether the request takes
// the client over a limit. In enforce mode such a request bans the
// client's netblock, and sets the client's counters back to zero; in
// observe mode it does neither.
// observe mode it does neither, and raises the alert for the ban it would
// have made.
func (rq *request) limitBroken(now time.Time) bool {
group := clientGroup(rq.client)
@@ -61,19 +58,26 @@ func (rq *request) limitBroken(now time.Time) bool {
rq.line.LimitHit = hit.Window
rq.line.Offence = requestlog.OffenceLimit
if rq.h.config.Observe {
return true
}
netblock := rq.h.netblock(rq.client)
ban, made := rq.h.ledger.BanForLimit(netblock, now, bans.Notes{
notes := bans.Notes{
Country: rq.line.Country,
Limit: hit.Limit,
Window: hit.Window,
Count: hit.Requests,
Request: rq.noted(now),
Requests: rq.netblockRequests(netblock),
})
}
if rq.h.config.Observe {
ban, wouldBan := rq.h.ledger.WouldBanForLimit(netblock, now, notes)
if wouldBan {
rq.alertBan(ban)
}
return true
}
ban, made := rq.h.ledger.BanForLimit(netblock, now, notes)
rq.h.limiter.Reset(group)
rq.line.BanExpires = banExpires(ban)
@@ -85,16 +89,28 @@ func (rq *request) limitBroken(now time.Time) bool {
}
// banForAttack bans the client's netblock at now for a clear sign of
// attack, the match of rule, a ban rule.
// attack, the match of rule, a ban rule. In observe mode it makes no ban,
// and raises the alert for the ban it would have made.
func (rq *request) banForAttack(now time.Time, rule rules.Rule) {
netblock := rq.h.netblock(rq.client)
ban, made := rq.h.ledger.BanForAttack(netblock, now, bans.Notes{
notes := bans.Notes{
Country: rq.line.Country,
RuleID: rule.ID,
Target: rule.Target,
Request: rq.noted(now),
Requests: rq.netblockRequests(netblock),
})
}
if rq.h.config.Observe {
ban, wouldBan := rq.h.ledger.WouldBanForAttack(netblock, now, notes)
if wouldBan {
rq.alertBan(ban)
}
return
}
ban, made := rq.h.ledger.BanForAttack(netblock, now, notes)
rq.line.BanExpires = banExpires(ban)
if made {
@@ -104,27 +120,35 @@ func (rq *request) banForAttack(now time.Time, rule rules.Rule) {
// alertBan raises the alert for ban, which the request made, or made
// permanent: permanent_ban for a permanent ban, ban for another. Its
// detail gives the ban's cause, when it ends, and its notes.
// detail gives the ban's cause, when it ends, and its notes, and in
// observe mode, where ban is the ban that would have been made, or made
// permanent, mode, observe.
func (rq *request) alertBan(ban bans.Ban) {
event := alerts.EventBan
if ban.Permanent() {
event = alerts.EventPermanentBan
}
detail := map[string]any{
"cause": ban.Cause, "ban_expires": banExpires(ban), "notes": ban.Notes,
}
if rq.h.config.Observe {
detail["mode"] = "observe"
}
rq.h.alerts.Raise(alerts.Alert{
Event: event,
Client: rq.client,
Netblock: ban.Netblock,
Country: ban.Notes.Country,
Reason: ban.Reason,
Detail: map[string]any{
"cause": ban.Cause, "ban_expires": banExpires(ban), "notes": ban.Notes,
},
Detail: detail,
})
}
// noted is the request, refused at now with SWWAF_BAN_RESPONSE, as the
// notes of the ban it makes keep it.
// noted is the request, refused at now with SWWAF_BAN_RESPONSE, or in
// observe mode as it would have been, as the notes of the ban it makes
// keep it.
func (rq *request) noted(now time.Time) bans.Request {
return bans.Request{
Time: now,
+4 -5
View File
@@ -10,8 +10,9 @@ import (
// checkRules checks the request against the rules of the rule files at
// now, notes the ids of those it matches in the log line, and returns the
// action of the rule that refuses it, ActionRuleBlocked for a block rule
// and ActionBanned for a ban rule, or "" when none does. In enforce mode
// a ban rule bans the client's netblock for a clear sign of attack.
// and ActionBanned for a ban rule, or "" when none does. 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.
func (rq *request) checkRules(now time.Time) string {
matched := rq.h.rules.Match(rq.in)
@@ -29,9 +30,7 @@ func (rq *request) checkRules(now time.Time) string {
case rules.ActionBlock:
return requestlog.ActionRuleBlocked
case rules.ActionBan:
if !rq.h.config.Observe {
rq.banForAttack(now, last)
}
rq.banForAttack(now, last)
return requestlog.ActionBanned
default:
+15 -12
View File
@@ -129,7 +129,7 @@ func Load(params Params) (*Files, error) {
return f, nil
}
rules, err := read(params.Dir)
rules, _, err := read(params.Dir)
if err != nil {
return nil, err
}
@@ -227,9 +227,9 @@ func (f *Files) readAfterChanges(
// readAgain reads the rule files again, in place of the rules loaded, or
// logs the error that keeps the rules as they were, and raises a
// file_error alert for it.
// file_error alert for it, for the file it is in.
func (f *Files) readAgain() {
rules, err := read(f.params.Dir)
rules, path, err := read(f.params.Dir)
if err != nil {
const kept = "a rule file has an error, and the rules stay as they were"
@@ -238,7 +238,7 @@ func (f *Files) readAgain() {
f.params.Alerts.Raise(alerts.Alert{
Event: alerts.EventFileError,
Reason: kept,
Detail: map[string]any{"error": err.Error()},
Detail: map[string]any{"file": path, "error": err.Error()},
})
f.params.ProcessLog.Error(kept, "error", err.Error())
@@ -257,13 +257,14 @@ func (f *Files) logRead(count int) {
}
// read returns the rules of every rule file in dir, in the order of the
// files' names, and then of their lines. A file whose name starts with a
// dot, such as an editor's lock file .#50-app.rules, is not a rule file,
// as a shell's *.rules would not match it.
func read(dir string) ([]Rule, error) {
// files' names, and then of their lines, or an error, with the path of the
// rule file it is in, or dir. A file whose name starts with a dot, such as
// an editor's lock file .#50-app.rules, is not a rule file, as a shell's
// *.rules would not match it.
func read(dir string) ([]Rule, string, error) {
entries, err := os.ReadDir(dir)
if err != nil {
return nil, fmt.Errorf("SWWAF_RULES_DIR cannot be read: %w", err)
return nil, dir, fmt.Errorf("SWWAF_RULES_DIR cannot be read: %w", err)
}
var rules []Rule
@@ -277,13 +278,15 @@ func read(dir string) ([]Rule, error) {
continue
}
rules, err = readFile(filepath.Join(dir, name), rules, places)
path := filepath.Join(dir, name)
rules, err = readFile(path, rules, places)
if err != nil {
return nil, err
return nil, path, err
}
}
return rules, nil
return rules, "", nil
}
// readFile appends the rules of the rule file at path to rules. places
+3 -2
View File
@@ -383,13 +383,14 @@ func TestBrokenEditKeepsTheRulesAsTheyWere(t *testing.T) {
t.Errorf("logged %v, want an error %q", line, want)
}
// The error is raised as a file_error alert too.
// The error is raised as a file_error alert too, for the file.
wantFileError := func() {
t.Helper()
waiting := queue.Snapshot().Waiting
if len(waiting) != 1 || waiting[0].Event != alerts.EventFileError ||
waiting[0].Reason != hasError || waiting[0].Detail["error"] != want {
waiting[0].Reason != hasError || waiting[0].Detail["error"] != want ||
waiting[0].Detail["file"] != filepath.Join(dir, firstFile) {
t.Errorf("alerts waiting %+v, want one file_error alert for %q", waiting, want)
}
}
+10 -6
View File
@@ -197,9 +197,11 @@ func (f *Files) Run(ctx context.Context) {
case <-bansDue:
bansDue = nil
f.logFailure(f.writeFile(bansJSON))
f.logFailure(bansJSON, f.writeFile(bansJSON))
case <-interval.C:
f.logFailure(f.WriteAll())
for _, name := range []string{bansJSON, clientsJSON, lookupsJSON, alertsJSON} {
f.logFailure(name, f.writeFile(name))
}
}
}
}
@@ -253,9 +255,9 @@ func (f *Files) Watch(ctx context.Context) {
}
}
// logFailure logs a write that failed, and raises a file_error alert for
// it.
func (f *Files) logFailure(err error) {
// logFailure logs a write of the state file name that failed, and raises
// a file_error alert for it.
func (f *Files) logFailure(name string, err error) {
if err != nil {
const failed = "writing the state files failed"
@@ -264,7 +266,9 @@ func (f *Files) logFailure(err error) {
f.params.Alerts.Raise(alerts.Alert{
Event: alerts.EventFileError,
Reason: failed,
Detail: map[string]any{"error": err.Error()},
Detail: map[string]any{
"file": filepath.Join(f.params.Dir, name), "error": err.Error(),
},
})
f.params.ProcessLog.Error(failed, "error", err.Error())
}
+10 -11
View File
@@ -96,12 +96,7 @@ const filledAlertsJSON = `{
{
"event": "file_error",
"netblock": "",
"sent": "2026-10-06T00:00:00Z",
"suppressed_repeats": 0
},
{
"event": "source_failure",
"netblock": "",
"file": "/var/lib/smallwebwaf/bans.json",
"sent": "2026-10-06T00:00:00Z",
"suppressed_repeats": 0
},
@@ -146,7 +141,8 @@ const filledAlertsJSON = `{
"country": "",
"reason": "writing the state files failed",
"detail": {
"error": "no space left on device"
"error": "no space left on device",
"file": "/var/lib/smallwebwaf/bans.json"
},
"suppressed_repeats": 0
}
@@ -610,9 +606,10 @@ func TestWriteThatFailsWhileRunningRaisesAFileErrorAlertOncePerCooldown(t *testi
if waiting[0].Event != alerts.EventFileError ||
waiting[0].Reason != "writing the state files failed" ||
waiting[0].Detail["file"] != filepath.Join(dir, bansJSON) ||
!strings.Contains(message, bansJSON+".tmp") {
t.Fatalf("alerts waiting %+v, want a file_error alert naming bans.json's "+
"temporary file", waiting)
t.Fatalf("alerts waiting %+v, want a file_error alert for bans.json, naming "+
"its temporary file", waiting)
}
// The next write fails too, within the cooldown, which holds it back.
@@ -1012,7 +1009,7 @@ func TestBanLiftedByAnEditWhileRunning(t *testing.T) {
netblock := netip.MustParsePrefix(liftedClient + "/32")
params.Ledger.BanForLimit(netblock, midnight(), bans.Notes{})
_, banned := params.Ledger.Find(netblock.Addr(), afterLifting())
_, banned, _ := params.Ledger.Find(netblock.Addr(), afterLifting())
if !banned {
t.Fatal("the ban does not refuse before it is lifted")
}
@@ -1277,7 +1274,9 @@ func fill(params state.Params) {
params.Alerts.Raise(ban)
params.Alerts.Raise(alerts.Alert{
Event: alerts.EventFileError, Reason: "writing the state files failed",
Detail: map[string]any{"error": "no space left on device"},
Detail: map[string]any{
"file": "/var/lib/smallwebwaf/bans.json", "error": "no space left on device",
},
})
params.Alerts.Raise(alerts.Alert{
Event: alerts.EventSourceFailure, Reason: "asking GeoJS failed",