Read SWWAF_IPV6_GROUP_PREFIX, SWWAF_MAX_TRACKED_CLIENTS and SWWAF_LOG_LEVEL (closes #112)

The IPv6 group that is one client, the size of the table of clients and
the level of the process's own lines become settings. clientGroup reads
the group length from them, so limits, bans, history, lookups, AbuseIPDB
scores and per-client anomaly counters all follow it; ratelimit.New
takes the table size; the process logger takes the level once the
settings are read, and request lines, written apart from it, are never
held back.

Judgement call: SWWAF_IPV6_GROUP_PREFIX accepts 32 to 128, the issue's example range.

Model: opus-5-5

internal/proxy/admin.go

@@ -282,7 +282,7 @@ func (rq *request) showClient() {
 
 	answer := clientAnswer{Bans: state.BanEntries(rq.h.ledger.Covering(addr))}
 
-	client, seen := rq.h.limiter.Client(clientGroup(addr))
+	client, seen := rq.h.limiter.Client(rq.h.clientGroup(addr))
 	if seen {
 		answer.Client = &client
 	}

internal/proxy/bans.go

@@ -45,7 +45,7 @@ func (rq *request) banned(now time.Time) bool {
 // the client over a rate limit, as its limit percentage lowers it, which
 // breaks it.
 func (rq *request) limitBroken(now time.Time) bool {
-	counts, hit, over := rq.h.limiter.Count(clientGroup(rq.client), now,
+	counts, hit, over := rq.h.limiter.Count(rq.h.clientGroup(rq.client), now,
 		rq.limitPercent.percent)
 	rq.line.Counts = counts
 
@@ -71,7 +71,7 @@ func (rq *request) countBytes() {
 
 	now := rq.h.now()
 
-	counts, hit, over := rq.h.limiter.CountBytes(clientGroup(rq.client), now,
+	counts, hit, over := rq.h.limiter.CountBytes(rq.h.clientGroup(rq.client), now,
 		rq.countedBytes(), rq.bytesPercent.percent)
 	rq.line.Counts.MinuteBytes = counts.MinuteBytes
 	rq.line.Counts.HourBytes = counts.HourBytes
@@ -155,7 +155,7 @@ func (rq *request) banForLimit(now time.Time, hit ratelimit.Hit, status int) {
 	}
 
 	ban, made := rq.h.ledger.BanForLimit(netblock, now, notes)
-	rq.h.limiter.Reset(clientGroup(rq.client))
+	rq.h.limiter.Reset(rq.h.clientGroup(rq.client))
 	rq.line.BanExpires = banExpires(ban)
 
 	if made {
@@ -276,7 +276,7 @@ func (h *handler) netblock(client netip.Addr) netip.Prefix {
 		return netip.PrefixFrom(addr, h.config.BanScopeV4Prefix).Masked()
 	}
 
-	return clientGroup(addr)
+	return h.clientGroup(addr)
 }
 
 // banExpires is when ban ends, as the log line gives it: a time, or

internal/proxy/bans_test.go

@@ -165,9 +165,14 @@ func TestBanCoversTheClientsNetblock(t *testing.T) {
 			[]string{otherClient, exempt}, []string{"203.0.112.9", allowed},
 		},
 		{
-			"an IPv6 /64", nil, "2001:db8:5::1",
+			"an IPv6 /64, by default", nil, "2001:db8:5::1",
 			[]string{"2001:db8:5::ffff:1"}, []string{"2001:db8:5:1::1"},
 		},
+		{
+			"the IPv6 netblock SWWAF_IPV6_GROUP_PREFIX sets",
+			map[string]string{ipv6GroupPrefix: "48"}, "2001:db8:7::1",
+			[]string{"2001:db8:7:ffff::1"}, []string{"2001:db8:8::1"},
+		},
 	} {
 		t.Run(tc.name, func(t *testing.T) {
 			t.Parallel()

internal/proxy/client.go

@@ -76,16 +76,14 @@ func scheme(r *http.Request, peerTrusted bool) string {
 	return proto
 }
 
-// ipv6GroupPrefix is the length of the IPv6 netblock that is one client.
-const ipv6GroupPrefix = 64
-
 // clientGroup is the client a request is counted toward: its IPv4
-// address, or the /64 its IPv6 address is in, since one abuser usually
-// holds a whole /64. An IPv4 address in IPv6 form counts as IPv4.
-func clientGroup(addr netip.Addr) netip.Prefix {
+// address, or its IPv6 group, the netblock its IPv6 address is in of the
+// length SWWAF_IPV6_GROUP_PREFIX sets, a /64 by default, since one abuser
+// usually holds a whole /64. An IPv4 address in IPv6 form counts as IPv4.
+func (h *handler) clientGroup(addr netip.Addr) netip.Prefix {
 	addr = addr.Unmap()
 	if addr.Is6() {
-		return netip.PrefixFrom(addr, ipv6GroupPrefix).Masked()
+		return netip.PrefixFrom(addr, h.config.IPv6GroupPrefix).Masked()
 	}
 
 	return netip.PrefixFrom(addr, addr.BitLen())

internal/proxy/history_test.go

@@ -56,6 +56,24 @@ func TestHistoryKeepsEachRequestOfTheClient(t *testing.T) {
 	}
 }
 
+func TestTableOfClientsHoldsAtMostMaxTrackedClients(t *testing.T) {
+	t.Parallel()
+
+	s, _, server := startWithClock(t, "", map[string]string{maxTrackedClients: "2"})
+
+	// The third client drops the least recently seen, the first, with its
+	// history.
+	for _, from := range []string{"192.0.2.1", "192.0.2.2", "192.0.2.3"} {
+		s.get(from, http.StatusOK, requestlog.ActionForward)
+	}
+
+	_, held := server.Limiter.Client(netip.MustParsePrefix("192.0.2.1/32"))
+	if server.Limiter.Len() != 2 || held {
+		t.Errorf("the table holds %d clients, the first among them: %t; want 2, "+
+			"without it", server.Limiter.Len(), held)
+	}
+}
+
 func TestHistoryCountsTheBodiesEachWay(t *testing.T) {
 	t.Parallel()
 

internal/proxy/lookup.go

@@ -31,9 +31,9 @@ func (rq *request) lookUp(ctx context.Context) {
 	}
 
 	if rq.h.config.LookupSource == "file" {
-		rq.lookupAnswer = rq.h.lookupFile.LookUp(clientGroup(rq.client))
+		rq.lookupAnswer = rq.h.lookupFile.LookUp(rq.h.clientGroup(rq.client))
 	} else {
-		rq.lookupAnswer = rq.h.geojs.LookUp(ctx, clientGroup(rq.client))
+		rq.lookupAnswer = rq.h.geojs.LookUp(ctx, rq.h.clientGroup(rq.client))
 	}
 
 	rq.lookedUp = true

internal/proxy/passthrough_test.go

@@ -320,7 +320,7 @@ func TestServerHasTheDefaultLimits(t *testing.T) {
 	server := proxy.New(proxy.Params{
 		Config:     cfg,
 		RequestLog: io.Discard,
-		ProcessLog: requestlog.NewProcessLogger(io.Discard, cfg.InstanceName),
+		ProcessLog: requestlog.NewProcessLogger(io.Discard, cfg.InstanceName, cfg.LogLevel),
 	})
 
 	if server.Addr != ":8080" || server.MaxHeaderBytes != 28<<10 ||
@@ -399,6 +399,25 @@ func TestAnswers502WhenTheAppCannotBeReached(t *testing.T) {
 	}
 }
 
+func TestLogLevelHoldsBackNoRequestLine(t *testing.T) {
+	t.Parallel()
+
+	// At error the warning that the request to the app failed is held back,
+	// and is written before the answer is.
+	addr, out := startProxy(t, "http://"+localhost+":1", map[string]string{
+		"SWWAF_LOG_LEVEL": "error",
+	})
+
+	wantStatus(t, get(t, addr, "/"), http.StatusBadGateway)
+	wantLine(t, out.requestLine(t), http.StatusBadGateway, requestlog.ActionUpstreamError)
+
+	for _, line := range out.lines(t) {
+		if line["type"] == "process" {
+			t.Errorf("process line %v, want none at error", line)
+		}
+	}
+}
+
 func TestLogsAnAnswerThatBrokeOff(t *testing.T) {
 	t.Parallel()
 

internal/proxy/proxy.go

@@ -124,7 +124,7 @@ func New(params Params) *Server {
 			BytesPerMinute: params.Config.BytesLimitPerMinute,
 			BytesPerHour:   params.Config.BytesLimitPerHour,
 			BytesPerDay:    params.Config.BytesLimitPerDay,
-		}),
+		}, params.Config.MaxTrackedClients),
 		ledger: bans.New(bans.Rules{
 			LimitBanDuration:     params.Config.LimitBanDuration,
 			LimitBanRepeatWindow: params.Config.LimitBanRepeatWindow,

internal/proxy/proxy_test.go

@@ -61,6 +61,8 @@ const (
 	requestMaxBytes         = "SWWAF_REQUEST_MAX_BYTES"
 	responseMaxBytes        = "SWWAF_RESPONSE_MAX_BYTES"
 	trustedProxies          = "SWWAF_TRUSTED_PROXIES"
+	ipv6GroupPrefix         = "SWWAF_IPV6_GROUP_PREFIX"
+	maxTrackedClients       = "SWWAF_MAX_TRACKED_CLIENTS"
 	allowNets               = "SWWAF_ALLOW_NETS"
 	rateLimitExemptNets     = "SWWAF_RATE_LIMIT_EXEMPT_NETS"
 	denyNets                = "SWWAF_DENY_NETS"
@@ -295,7 +297,7 @@ func newProxy(
 	}
 
 	out := &output{}
-	processLog := requestlog.NewProcessLogger(out, cfg.InstanceName)
+	processLog := requestlog.NewProcessLogger(out, cfg.InstanceName, cfg.LogLevel)
 
 	ruleFiles, err := rules.Load(rules.Params{
 		Dir: cfg.RulesDir, Enabled: cfg.RulesEnabled, ProcessLog: processLog,

internal/proxy/ratelimits_test.go

@@ -72,6 +72,49 @@ func TestRateLimitRefusesBeforeTheApp(t *testing.T) {
 	}
 }
 
+func TestIPv6GroupPrefixSetsTheClientTheLimitsCount(t *testing.T) {
+	t.Parallel()
+
+	// With SWWAF_IPV6_GROUP_PREFIX at 48, the first two addresses, in two
+	// /64s of one /48, are one client, and the second's request breaks the
+	// limit; the third, in the next /48, is another client.
+	const (
+		first  = "2001:db8:9::1"
+		second = "2001:db8:9:1::1"
+		other  = "2001:db8:a::1"
+	)
+
+	for _, tc := range []struct {
+		setting, value string
+		// status and action are those of the request that breaks the
+		// limit: a rate limit refuses it, a byte limit passes it on.
+		status int
+		action string
+	}{
+		{rateLimitPerMinute, "1", http.StatusForbidden, requestlog.ActionRateLimited},
+		{bytesLimitPerMinute, byteLimit, http.StatusOK, requestlog.ActionForward},
+	} {
+		t.Run(tc.setting, func(t *testing.T) {
+			t.Parallel()
+
+			s, _ := startWithAnswers(t, map[string]string{
+				ipv6GroupPrefix: "48", tc.setting: tc.value,
+			})
+
+			s.get(first, http.StatusOK, requestlog.ActionForward)
+
+			line := s.get(second, tc.status, tc.action)
+			if line.ClientGroup != "2001:db8:9::/48" ||
+				line.Offence != requestlog.OffenceLimit {
+				t.Errorf("log line has client_group %q and offence %q, "+
+					"want 2001:db8:9::/48 and limit", line.ClientGroup, line.Offence)
+			}
+
+			s.get(other, http.StatusOK, requestlog.ActionForward)
+		})
+	}
+}
+
 func TestRateLimitExemptPathsAreNeitherCountedNorRefused(t *testing.T) {
 	t.Parallel()
 

internal/proxy/reputation.go

@@ -52,7 +52,7 @@ func (rq *request) abuseIPDBDenied(ctx context.Context) bool {
 		return false
 	}
 
-	client := clientGroup(rq.client)
+	client := rq.h.clientGroup(rq.client)
 	held, _ := rq.h.limiter.Client(client)
 	offender := held.History.Offences != ratelimit.Offences{}
 
@@ -88,7 +88,7 @@ func (rq *request) noteHit(source, reason string, detail map[string]any) {
 	rq.h.alerts.Raise(alerts.Alert{
 		Event:    alerts.EventReputationHit,
 		Client:   rq.client,
-		Netblock: clientGroup(rq.client),
+		Netblock: rq.h.clientGroup(rq.client),
 		ASN:      rq.line.ASN,
 		ASName:   rq.line.ASName,
 		Country:  rq.line.Country,

internal/proxy/request.go

@@ -140,7 +140,7 @@ func (h *handler) newRequest(w http.ResponseWriter, r *http.Request) *request {
 			RequestID:        requestID(r, peerTrusted),
 			PeerIP:           peer.String(),
 			ForwardedFor:     strings.Join(forwardedFor, ", "),
-			ClientGroup:      clientGroup(client).String(),
+			ClientGroup:      h.clientGroup(client).String(),
 			ContentType:      r.Header.Get("Content-Type"),
 			RequestHeaders:   requestHeaders(r, h.config.LogRequestHeaders),
 			HasAuthorization: len(r.Header.Values("Authorization")) > 0,
@@ -539,7 +539,7 @@ func timing(start, end time.Time) *float64 {
 func (rq *request) addToHistory() {
 	forwarded := !rq.upstreamStart.IsZero()
 
-	rq.h.limiter.AddToHistory(clientGroup(rq.client), rq.h.now(), ratelimit.Request{
+	rq.h.limiter.AddToHistory(rq.h.clientGroup(rq.client), rq.h.now(), ratelimit.Request{
 		Forwarded:     forwarded,
 		Refused:       !forwarded && rq.refused.Load() != nil,
 		Status:        rq.out.status,
@@ -572,7 +572,7 @@ func (rq *request) countAnomalies() {
 
 	rq.h.anomalies.Count(rq.h.now(), anomaly.Request{
 		Client:      rq.client,
-		ClientGroup: clientGroup(rq.client),
+		ClientGroup: rq.h.clientGroup(rq.client),
 		ASN:         answer.ASN,
 		ASName:      answer.ASName,
 		Country:     answer.Country,
@@ -601,7 +601,7 @@ func (rq *request) answerAtTheEnd() (lookup.Answer, bool) {
 		return rq.lookupAnswer, true
 	}
 
-	return rq.h.geojs.Kept(clientGroup(rq.client))
+	return rq.h.geojs.Kept(rq.h.clientGroup(rq.client))
 }
 
 // requestBytes is how many bytes of the request's body have been read.