TODO.md

@@ -23,6 +23,12 @@ latest run passes.
 
 # Completed Steps
 
+- 2026-09-29: the request log is bounded (issue #60): the method, URL, protocol,
+  `User-Agent`, `Referer`, request ID (which chi takes from the client's
+  `X-Request-Id` header) and client address it writes are each cut to 128 bytes,
+  the bound the report handler already used, so one request can no longer put
+  about 1 MiB per field into a log line. That bound and its helper now live in
+  the `logger` package, shared by both
 - 2026-09-29: nginx takes the client address from `X-Forwarded-For` only on
   requests from the reverse proxies named in the container's `TRUSTED_PROXIES`
   (issue #64), and by default from none, where it trusted every RFC1918 address

backend/internal/handlers/export_test.go

@@ -2,9 +2,6 @@ package handlers
 
 import "log/slog"
 
-// MaxLoggedFieldBytes exposes the log bound to the external tests.
-const MaxLoggedFieldBytes = maxLoggedFieldBytes
-
 // NewForTest builds a Handlers around a report sink and logger,
 // bypassing the fx graph so handler behaviour (including the
 // storage failure path) is exercisable in unit tests.

backend/internal/handlers/report.go

@@ -5,14 +5,10 @@ import (
 	"errors"
 	"net/http"
 
+	"sneak.berlin/go/netwatch/internal/logger"
 	"sneak.berlin/go/netwatch/internal/reportbuf"
 )
 
-// maxLoggedFieldBytes bounds untrusted text (string fields,
-// decode error text) before it is logged, so a caller cannot
-// inflate log volume with an oversized value.
-const maxLoggedFieldBytes = 128
-
 type reportSample struct {
 	T       int64   `json:"t"`
 	Latency *int    `json:"latency"`
@@ -83,7 +79,7 @@ func (s *Handlers) decodeErrorStatus(err error) int {
 	// The decoder's error text can quote request bytes (a whole
 	// oversized number, for example), so it is bounded too.
 	s.log.Error("failed to decode report",
-		"error", boundedForLog(err.Error()),
+		"error", logger.BoundedForLog(err.Error()),
 	)
 
 	return http.StatusBadRequest
@@ -115,20 +111,10 @@ func (s *Handlers) logReportReceived(rpt report) {
 	}
 
 	s.log.Info("report received",
-		"client_id", boundedForLog(rpt.ClientID),
-		"timestamp", boundedForLog(rpt.Timestamp),
+		"client_id", logger.BoundedForLog(rpt.ClientID),
+		"timestamp", logger.BoundedForLog(rpt.Timestamp),
 		"host_count", len(rpt.Hosts),
 		"total_samples", totalSamples,
 		"geo_bytes", len(rpt.Geo),
 	)
 }
-
-// boundedForLog truncates an untrusted string to a fixed byte
-// bound so an attacker-controlled field cannot dominate the log.
-func boundedForLog(s string) string {
-	if len(s) > maxLoggedFieldBytes {
-		return s[:maxLoggedFieldBytes]
-	}
-
-	return s
-}

backend/internal/handlers/report_test.go

@@ -12,6 +12,7 @@ import (
 	"testing"
 
 	"sneak.berlin/go/netwatch/internal/handlers"
+	"sneak.berlin/go/netwatch/internal/logger"
 	"sneak.berlin/go/netwatch/internal/middleware"
 	"sneak.berlin/go/netwatch/internal/reportbuf"
 )
@@ -174,7 +175,7 @@ func TestHandleReportDoesNotLogRawGeo(t *testing.T) {
 func TestHandleReportLogsClientIDCutToBound(t *testing.T) {
 	t.Parallel()
 
-	long := strings.Repeat("c", 2*handlers.MaxLoggedFieldBytes)
+	long := strings.Repeat("c", 2*logger.MaxLoggedFieldBytes)
 
 	var logbuf bytes.Buffer
 
@@ -197,16 +198,16 @@ func TestHandleReportLogsClientIDCutToBound(t *testing.T) {
 		t.Fatalf("log line not JSON: %v (%q)", err, logbuf.String())
 	}
 
-	want := long[:handlers.MaxLoggedFieldBytes]
+	want := long[:logger.MaxLoggedFieldBytes]
 
 	if logged["client_id"] != want {
 		t.Fatalf("logged client_id not cut to %d bytes: %q",
-			handlers.MaxLoggedFieldBytes, logged["client_id"])
+			logger.MaxLoggedFieldBytes, logged["client_id"])
 	}
 
 	if logged["timestamp"] != want {
 		t.Fatalf("logged timestamp not cut to %d bytes: %q",
-			handlers.MaxLoggedFieldBytes, logged["timestamp"])
+			logger.MaxLoggedFieldBytes, logged["timestamp"])
 	}
 }
 
@@ -215,7 +216,7 @@ func TestHandleReportDecodeErrorLogIsBounded(t *testing.T) {
 
 	// A number too large for its int64 field makes the decoder's
 	// error text quote the whole number.
-	huge := strings.Repeat("9", 2*handlers.MaxLoggedFieldBytes)
+	huge := strings.Repeat("9", 2*logger.MaxLoggedFieldBytes)
 
 	var logbuf bytes.Buffer
 

backend/internal/logger/logger.go

@@ -11,6 +11,21 @@ import (
 	"go.uber.org/fx"
 )
 
+// MaxLoggedFieldBytes bounds untrusted text (request fields,
+// header values, decode error text) before it is logged, so a
+// caller cannot inflate log volume with an oversized value.
+const MaxLoggedFieldBytes = 128
+
+// BoundedForLog truncates an untrusted string to a fixed byte
+// bound so an attacker-controlled field cannot dominate the log.
+func BoundedForLog(s string) string {
+	if len(s) > MaxLoggedFieldBytes {
+		return s[:MaxLoggedFieldBytes]
+	}
+
+	return s
+}
+
 // Params defines the dependencies for Logger.
 type Params struct {
 	fx.In

backend/internal/middleware/middleware.go

@@ -189,7 +189,10 @@ func addrInAny(s string, trusted []netip.Prefix) bool {
 }
 
 // Logging returns middleware that logs each request with
-// timing, status code, and client information.
+// timing, status code, and client information. Every string
+// taken from the request is cut to logger.MaxLoggedFieldBytes,
+// including the request ID, which chi takes from the client's
+// X-Request-Id header when one is sent.
 func (s *Middleware) Logging() func(http.Handler) http.Handler {
 	return func(next http.Handler) http.Handler {
 		return http.HandlerFunc(
@@ -202,21 +205,19 @@ func (s *Middleware) Logging() func(http.Handler) http.Handler {
 					latency := time.Since(start)
 					s.log.InfoContext(ctx, "request",
 						"request_start", start,
-						"method", r.Method,
-						"url", r.URL.String(),
-						"useragent", r.UserAgent(),
+						"method", logger.BoundedForLog(r.Method),
+						"url", logger.BoundedForLog(r.URL.String()),
+						"useragent", logger.BoundedForLog(r.UserAgent()),
 						"request_id",
-						ctx.Value(
-							middleware.RequestIDKey,
-						),
-						"referer", r.Referer(),
-						"proto", r.Proto,
+						logger.BoundedForLog(middleware.GetReqID(ctx)),
+						"referer", logger.BoundedForLog(r.Referer()),
+						"proto", logger.BoundedForLog(r.Proto),
 						"remote_ip",
-						clientIP(
+						logger.BoundedForLog(clientIP(
 							r.RemoteAddr,
 							r.Header,
 							s.trustedProxies,
-						),
+						)),
 						"status", lrw.statusCode,
 						"latency_ms",
 						latency.Milliseconds(),

backend/internal/middleware/middleware_test.go

@@ -13,7 +13,10 @@ import (
 	"testing/synctest"
 	"time"
 
+	"sneak.berlin/go/netwatch/internal/logger"
 	"sneak.berlin/go/netwatch/internal/middleware"
+
+	chimiddleware "github.com/go-chi/chi/v5/middleware"
 )
 
 const (
@@ -320,6 +323,52 @@ func TestRecovererRepanicsOnAbortHandler(t *testing.T) {
 	}
 }
 
+// TestLoggingCutsRequestStringsToBound sends an over-long URL and
+// over-long header values, and checks the request log writes each
+// one cut to logger.MaxLoggedFieldBytes.
+func TestLoggingCutsRequestStringsToBound(t *testing.T) {
+	t.Parallel()
+
+	long := strings.Repeat("a", 2*logger.MaxLoggedFieldBytes)
+
+	var logbuf bytes.Buffer
+
+	mw := middleware.NewWithLogger(
+		slog.New(slog.NewJSONHandler(&logbuf, nil)),
+	)
+
+	handler := chimiddleware.RequestID(mw.Logging()(okHandler()))
+
+	req := httptest.NewRequestWithContext(t.Context(),
+		http.MethodGet, "/"+long, http.NoBody)
+	req.Header.Set("User-Agent", long)
+	req.Header.Set("Referer", long)
+	req.Header.Set("X-Request-Id", long)
+
+	handler.ServeHTTP(httptest.NewRecorder(), req)
+
+	var logged map[string]any
+
+	err := json.Unmarshal(logbuf.Bytes(), &logged)
+	if err != nil {
+		t.Fatalf("log line not JSON: %v (%q)", err, logbuf.String())
+	}
+
+	want := map[string]string{
+		"url":        ("/" + long)[:logger.MaxLoggedFieldBytes],
+		"useragent":  long[:logger.MaxLoggedFieldBytes],
+		"referer":    long[:logger.MaxLoggedFieldBytes],
+		"request_id": long[:logger.MaxLoggedFieldBytes],
+	}
+
+	for field, value := range want {
+		if logged[field] != value {
+			t.Errorf("logged %s = %q, want it cut to %d bytes",
+				field, logged[field], logger.MaxLoggedFieldBytes)
+		}
+	}
+}
+
 // okHandler stands in for the route a middleware guards.
 func okHandler() http.Handler {
 	return http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {