fix(backend): cut request log fields to the log bound (closes #60)

The request log wrote the URL, User-Agent, Referer and other
request-supplied strings with no length limit, and the server accepts
headers up to 1 MiB, so one request could put about 1 MiB per field
into a log line. Every string the request log takes from the request,
including the request ID chi copies from X-Request-Id, is now cut to
the 128-byte bound the report handler already used. That bound and
its helper moved from the handlers package to the logger package so
both use the one copy.

Model: opus-5-5

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) {