Route GORM's logger through slog and bound it (closes #178)

GORM's default logger printed the fully interpolated SQL to standard
output on every statement that returned an error, including a plain
record-not-found. On /webhook/{uuid} and on the login form the
interpolated parameter is client-chosen and unbounded, so an
unauthenticated client sized the operator's log, one line per request,
at no level the operator could turn down.

Every gorm.Open in the service now installs internal/gormlog, a
gormlogger.Interface over the service's *slog.Logger. Its lines take
the level the operator set and the handler internal/logger selected; a
record-not-found is not logged as an error, since it is the expected
outcome on both of those paths and each handler already records its
own miss at DEBUG without the SQL; slow statements are kept at WARN
above the same 200ms threshold GORM used; and every value it emits is
spent through internal/logfield, the same encoded-byte budget the
access log spends. MaxAccessLogLineBytes bounds a GORM line too, and
internal/gormlog asserts each line against the constant directly.

Trace orders its cases exactly as GORM's own Trace orders them --
error-that-is-not-a-miss, then slow, then routine -- so a statement
that both missed and ran slow is still reported as slow. Ordering the
drop first would have made this adapter strictly less observant than
the IgnoreRecordNotFoundError option it was chosen over, on the two
lookups the issue is about, and a miss is the statement most likely to
be slow.

The third gorm.Open, in the archive writer, was not named in the issue
and had the same default. All three sites are pinned independently:
internal/handlers covers the main and per-webhook databases,
internal/delivery covers the archive writer, whose type is unexported.
Reverting any one of the three to a bare &gorm.Config{} fails the
suite.

The flood test's per-line and volume assertions were vacuous, because
the replaced default logger wrote only to a buffer while everything
else went to the captured stdout. It now tees to stdout as GORM's real
default does, so a reverted call site lands in the same capture and
those assertions measure the whole writer set.

internal/logfield gains the zero-headroom budget assertion and the
rune-splitting case: a value built from one rune must keep exactly
MaxBytes/EncodedBytes(r) of them, which a raw-byte budget fails and a
LessOrEqual on the budget cannot catch.

README: the ceiling now covers GORM, and the writers it does not cover
are re-derived by measuring rather than by reading. fx's console
logger and the Go runtime write to standard error. net/http's nil
ErrorLog is not a separate writer at all -- slog.SetDefault redirects
the log package's default logger into internal/logger's handler, so
those lines arrive on standard output at INFO. A handler panic reaches
that same path because chi's Recoverer crashes before writing, filed
as #187, and is the widest
line the service can write: measured at roughly 2,770 bytes against
the stated 2,560, a width that moves with the goroutine number and the
source paths in the stack, so only the fact that it exceeds the
ceiling is stated as invariant.

README.md

@@ -1141,10 +1141,11 @@ the figure has headroom. `internal/middleware/accesslog_test.go`
 asserts it against 8 KB of client-chosen text in the path, in the
 query, and in each of `User-Agent`, `Referer` and `X-Request-Id`,
 including cases built from the characters the handlers escape, and
-against the widest line the service can be made to write: a 5xx that
+against the widest access log line the service can be made to write: a
-keeps its concrete path while all three header fields are also at their
+5xx that keeps its concrete path while all three header fields are also
-budget. Every case runs through both handlers `internal/logger` can
+at their budget. Every case runs through both handlers
-select — the JSON one and the text one it installs on a tty — since the
+`internal/logger` can select — the JSON one and the text one it
+installs on a tty — since the
 two do not escape alike and the ceiling is quoted unqualified. Measured
 over a real connection, the widest line is 1,972 bytes.
 
@@ -1213,6 +1214,33 @@ against what the handlers really emit, over roughly 3,000 code points on
 each, so an undercharged rune fails a test rather than quietly
 falsifying the ceiling.
 
+**It covers GORM's statement logging as well.** GORM's own default
+logger printed the fully interpolated SQL — parameters and all — to
+standard output on every statement that returned an error, including a
+plain record-not-found, at a level no operator setting reached. Two of
+this service's lookups miss by design on unauthenticated routes: the
+entrypoint lookup behind `/webhook/{uuid}` and the user lookup behind
+the login form, whose path segment and submitted username the client
+picks outright. Every
+`gorm.Open` in the service now installs the adapter in
+`internal/gormlog` instead. It writes through the same `slog` logger as
+everything else, so its lines take the level the operator set and the
+handler `internal/logger` selected, and every value it emits is spent
+through the same `internal/logfield` budget. A record-not-found is not
+logged as an error: it is the expected outcome on both of those paths,
+and each handler already records its own miss at `DEBUG` — bounded, per
+the table above — without the SQL. Slow statements are kept, at `WARN`,
+above the same 200 ms threshold GORM used and with the statement
+bounded, because that report is the one thing GORM's logger gave an
+operator that nothing else here does. The adapter orders its cases
+exactly as GORM's own `Trace` orders them, so a statement that both
+missed and ran slow is still reported as slow, and dropping the miss
+costs an operator no report `IgnoreRecordNotFoundError` would have
+kept. A GORM line spends at most two of those budgets — the statement
+and the driver error — against a smaller fixed portion than the access
+log's, and `internal/gormlog/gormlog_test.go` asserts each line against
+`MaxAccessLogLineBytes` directly rather than leaving it as arithmetic.
+
 What that ceiling does **not** cover, stated here so the figure is not
 read as more than it is:
 
@@ -1236,16 +1264,39 @@ read as more than it is:
   that type on a specific webhook, and each line it writes is bounded
   per event by the 1 MB receiver body cap. Adding one is a decision to
   spend log volume on that webhook's payloads.
-- **GORM's default logger**, which prints the fully interpolated SQL to
+- **Two writers that do not go through `internal/logger` at all**, both
-  stdout on every record-not-found — including the client-chosen path
+  on standard error. `fx` prints the dependency graph and the lifecycle
-  on `/webhook/{uuid}` and the submitted username on the login form.
+  hooks through its default console logger at startup and shutdown —
-  This one is not deliberate and not yet fixed; it does not go through
+  nothing calls `fx.WithLogger`, and `fx.New` builds that logger over
-  `internal/logger` at all, so no level the operator sets and no budget
+  `os.Stderr`. The Go runtime writes a panic or a fatal error itself; a
-  above applies to it. Tracked at
+  panic in a background worker rather than in a request handler is the
-  <https://git.eeqj.de/sneak/webhooker/issues/178>. Until it is fixed,
+  case that reaches it, since nothing recovers those. Neither carries a
-  an unauthenticated flood can still write text of its own choosing and
+  client-chosen value at a client-chosen length: the five `panic` calls
-  its own length to the operator's stdout, and the ceiling above
+  in this service are invariant guards over constants and over
-  describes only the `slog` half of the picture.
+  `crypto/rand`.
+- **`net/http`'s own faults**, which are _not_ a separate writer.
+  `internal/server/http.go` builds its server with a nil `ErrorLog`, so
+  `net/http` falls back to the `log` package's default logger — and
+  `internal/logger` calls `slog.SetDefault`, which redirects that logger
+  into whichever handler it installed. Those lines therefore arrive on
+  standard output, shaped like every other line, at `INFO`. They are not
+  truncated and they are not bounded by the ceiling: a handler panic
+  arrives as one record carrying a whole goroutine stack, above the
+  ceiling's 2,560 bytes — measured at roughly 2,770 in one checkout. The
+  exact width is not an invariant, since it moves with the goroutine
+  number and with the source paths baked into the stack; that it exceeds
+  the ceiling does not move. The value is the runtime's, not a client's.
+- **A handler panic reaches that path** rather than the one it looks
+  like it should. `internal/server/routes.go` installs chi's
+  `middleware.Recoverer` in front of every route, which is meant to
+  print the panic and its stack to standard error and answer 500. On the
+  Go version this service builds against it does neither: chi v1.5.5's
+  stack pretty-printer looks for a `panic(0x` frame that the runtime no
+  longer emits, walks past the end of its own slice, and panics before
+  writing a byte. That second panic escapes to `net/http`, which drops
+  the connection and reports it through the nil `ErrorLog` above.
+  Tracked separately in
+  <https://git.eeqj.de/sneak/webhooker/issues/187>.
 
 Every limiter here — receiver, login, and password change — identifies
 the client the same way, through one shared key function: the
@@ -1485,6 +1536,10 @@ webhooker/
 │   │   └── webhook_db_manager.go  # Per-webhook DB lifecycle manager
 │   ├── globals/
 │   │   └── globals.go         # Build-time variables (appname, version, arch)
+│   ├── gormlog/
+│   │   └── gormlog.go         # GORM's logger.Interface on top of slog, bounded
+│   ├── logfield/
+│   │   └── logfield.go        # Encoded-byte budget for client-supplied log values
 │   ├── delivery/
 │   │   ├── engine.go          # Event-driven delivery engine (channel + timer based)
 │   │   ├── circuit_breaker.go # Per-target circuit breaker for http/slack targets with retries

internal/database/database.go

@@ -17,6 +17,7 @@ import (
 	"gorm.io/gorm"
 	_ "modernc.org/sqlite" // Pure Go SQLite driver
 	"sneak.berlin/go/webhooker/internal/config"
+	"sneak.berlin/go/webhooker/internal/gormlog"
 	"sneak.berlin/go/webhooker/internal/logger"
 )
 
@@ -155,7 +156,10 @@ func (d *Database) connect() error {
 	// Then use it with GORM
 	db, err := gorm.Open(sqlite.Dialector{
 		Conn: sqlDB,
-	}, &gorm.Config{})
+	}, &gorm.Config{
+		// Never leave this at GORM's default. See internal/gormlog.
+		Logger: gormlog.New(d.log),
+	})
 	if err != nil {
 		d.log.Error(
 			"failed to connect to database",

internal/database/webhook_db_manager.go

@@ -14,6 +14,7 @@ import (
 	"gorm.io/driver/sqlite"
 	"gorm.io/gorm"
 	"sneak.berlin/go/webhooker/internal/config"
+	"sneak.berlin/go/webhooker/internal/gormlog"
 	"sneak.berlin/go/webhooker/internal/logger"
 )
 
@@ -248,7 +249,10 @@ func (m *WebhookDBManager) openDB(
 
 	db, err := gorm.Open(sqlite.Dialector{
 		Conn: sqlDB,
-	}, &gorm.Config{})
+	}, &gorm.Config{
+		// Never leave this at GORM's default. See internal/gormlog.
+		Logger: gormlog.New(m.log),
+	})
 	if err != nil {
 		_ = sqlDB.Close()
 

internal/delivery/target_database_archive.go

@@ -12,6 +12,7 @@ import (
 
 	"gorm.io/driver/sqlite"
 	"gorm.io/gorm"
+	"sneak.berlin/go/webhooker/internal/gormlog"
 )
 
 // archiveExpiryNever is the expiry sentinel (and default) that
@@ -282,7 +283,11 @@ func (w *archiveWriter) openMode(
 	}
 
 	gdb, err := gorm.Open(
-		sqlite.Dialector{Conn: sqlDB}, &gorm.Config{},
+		sqlite.Dialector{Conn: sqlDB}, &gorm.Config{
+			// Never leave this at GORM's default. See
+			// internal/gormlog.
+			Logger: gormlog.New(w.log),
+		},
 	)
 	if err != nil {
 		_ = sqlDB.Close()

internal/delivery/target_database_archive_gormlog_test.go

@@ -0,0 +1,155 @@
+package delivery_test
+
+import (
+	"bytes"
+	"log"
+	"log/slog"
+	"path/filepath"
+	"strings"
+	"sync"
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"gorm.io/gorm"
+	gormlogger "gorm.io/gorm/logger"
+	"sneak.berlin/go/webhooker/internal/delivery"
+	"sneak.berlin/go/webhooker/internal/middleware"
+)
+
+// archiveGORMTailMarker sits at the far end of the value this file
+// drives into an archive lookup. Its presence in a log line means the
+// whole value reached the log, so nothing truncated it.
+const archiveGORMTailMarker = "ENDOFCLIENTVALUE"
+
+// archiveGORMFillBytes is how much text the lookup carries. It is far
+// past every budget in play.
+const archiveGORMFillBytes = 8 << 10
+
+// gormDefaultBuf collects what GORM's package-level default logger
+// writes, if anything reaches it.
+type gormDefaultBuf struct {
+	mu sync.Mutex
+	b  bytes.Buffer
+}
+
+func (g *gormDefaultBuf) Write(p []byte) (int, error) {
+	g.mu.Lock()
+	defer g.mu.Unlock()
+
+	return g.b.Write(p)
+}
+
+func (g *gormDefaultBuf) String() string {
+	g.mu.Lock()
+	defer g.mu.Unlock()
+
+	return g.b.String()
+}
+
+// captureArchiveGORMDefault replaces GORM's package-level default
+// logger with one configured exactly as GORM configures its own,
+// writing to a buffer.
+//
+// This duplicates the detector in internal/handlers rather than
+// sharing it: a test helper cannot cross a package's test boundary
+// without exporting production code to carry it, and a logging
+// detector is not worth a production symbol. What it detects is the
+// third gorm.Open in this service, at
+// internal/delivery/target_database_archive.go — the archive writer,
+// whose type is unexported, so nothing outside this package can drive
+// it.
+func captureArchiveGORMDefault(t *testing.T) *gormDefaultBuf {
+	t.Helper()
+
+	buf := &gormDefaultBuf{}
+	orig := gormlogger.Default
+
+	gormlogger.Default = gormlogger.New(
+		log.New(buf, "", log.LstdFlags),
+		gormlogger.Config{
+			SlowThreshold:             200 * time.Millisecond,
+			LogLevel:                  gormlogger.Warn,
+			IgnoreRecordNotFoundError: false,
+			Colorful:                  false,
+		},
+	)
+
+	t.Cleanup(func() { gormlogger.Default = orig })
+
+	return buf
+}
+
+// TestArchiveWriter_NeverUsesGORMsDefaultLogger pins the archive
+// writer's gorm.Open to the adapter.
+//
+// Restore a bare &gorm.Config{} at
+// internal/delivery/target_database_archive.go and this fails: the
+// default logger prints the fully interpolated SELECT on every
+// ErrRecordNotFound, so the client-chosen event id below arrives whole
+// and unbounded on stdout, answering to no level the operator set.
+//
+// Not parallel: gormlogger.Default is process-global. Go runs every
+// non-parallel top-level test to completion before it resumes the
+// parallel ones.
+//
+//nolint:paralleltest // Deliberately sequential; see above.
+func TestArchiveWriter_NeverUsesGORMsDefaultLogger(t *testing.T) {
+	var captured bytes.Buffer
+
+	gormDefault := captureArchiveGORMDefault(t)
+
+	w := delivery.NewExportArchiveWriter(
+		filepath.Join(t.TempDir(), "archive.db"),
+		slog.New(slog.NewTextHandler(
+			&captured, &slog.HandlerOptions{Level: slog.LevelDebug},
+		)),
+		0,
+	)
+
+	require.NoError(t, w.Open(0))
+
+	t.Cleanup(w.Evict)
+
+	// A lookup that misses, carrying a value the size of an inbound
+	// event id. Under the default logger this is the line that gets
+	// interpolated and printed.
+	value := strings.Repeat("\x01", archiveGORMFillBytes) +
+		archiveGORMTailMarker
+
+	var row delivery.ExportArchivedEvent
+
+	err := w.DB().Where("event_id = ?", value).First(&row).Error
+	require.ErrorIs(t, err, gorm.ErrRecordNotFound)
+
+	got := gormDefault.String()
+	assert.Empty(
+		t, got,
+		"GORM's default logger wrote %d bytes, so the archive "+
+			"writer's gorm.Open is back on a bare &gorm.Config{}; "+
+			"the first of them: %s",
+		len(got), got[:min(len(got), 300)],
+	)
+
+	// The adapter drops a miss, so this should be silent too — and
+	// whatever it does write stays inside the stated ceiling.
+	out := captured.String()
+
+	assert.NotContains(
+		t, out, archiveGORMTailMarker,
+		"the far end of the client-chosen value reached the log",
+	)
+
+	for line := range strings.SplitSeq(strings.TrimRight(out, "\n"), "\n") {
+		if line == "" {
+			continue
+		}
+
+		assert.LessOrEqual(
+			t, len(line), middleware.MaxAccessLogLineBytes,
+			"log line exceeded its bound: %s",
+			line[:min(len(line), 300)],
+		)
+	}
+}

internal/gormlog/export_test.go

@@ -0,0 +1,17 @@
+package gormlog
+
+import (
+	"log/slog"
+	"time"
+)
+
+// ExportNewWithSlowThreshold builds a Logger whose slow-statement
+// threshold is d rather than DefaultSlowThreshold, so a test can pin
+// which arm of Trace it is exercising instead of racing the clock on a
+// loaded machine. The threshold is set at construction, like every
+// other field, so the type's concurrency guarantee still holds.
+func ExportNewWithSlowThreshold(
+	log *slog.Logger, d time.Duration,
+) *Logger {
+	return &Logger{log: log, slowThreshold: d}
+}

internal/gormlog/gormlog.go

@@ -0,0 +1,168 @@
+// Package gormlog adapts GORM's logger onto the service's slog
+// logger.
+//
+// GORM's own default logger is not usable here. It is built at package
+// init with log.New(os.Stdout, ...) at LogLevel Warn with
+// IgnoreRecordNotFoundError false, so it writes the fully interpolated
+// SQL — parameters and all — for every statement that returns an
+// error, including gorm.ErrRecordNotFound. Two of this service's
+// lookups miss by design on unauthenticated routes: the entrypoint
+// lookup on /webhook/{uuid}, whose path segment the client picks
+// outright, and the user lookup behind the login form, whose username
+// the client picks outright. Under the default logger each of those
+// misses printed an unbounded, attacker-chosen string, at no level the
+// operator can turn down, past every handler internal/logger installs.
+//
+// This adapter fixes all three properties at once: the lines get a
+// level the operator controls, they are shaped by whichever handler
+// internal/logger selected, and every value a client can influence is
+// spent through logfield.Truncate.
+package gormlog
+
+import (
+	"context"
+	"errors"
+	"fmt"
+	"log/slog"
+	"time"
+
+	gormlogger "gorm.io/gorm/logger"
+	"sneak.berlin/go/webhooker/internal/logfield"
+)
+
+// DefaultSlowThreshold is the duration at or above which a statement
+// is logged as slow. It is GORM's own default, kept deliberately: slow
+// SQL is the one thing GORM's logger reports that nothing else in this
+// service does, so silencing the logger outright would have cost real
+// observability to fix a log-volume defect.
+const DefaultSlowThreshold = 200 * time.Millisecond
+
+// Logger implements gormlogger.Interface on top of an *slog.Logger.
+//
+// It is safe for concurrent use: every field is set at construction
+// and never written again.
+type Logger struct {
+	log           *slog.Logger
+	slowThreshold time.Duration
+}
+
+// Interface compliance is asserted here rather than discovered at the
+// gorm.Open call sites.
+var _ gormlogger.Interface = (*Logger)(nil)
+
+// New returns a GORM logger that writes through log.
+func New(log *slog.Logger) *Logger {
+	return &Logger{
+		log:           log,
+		slowThreshold: DefaultSlowThreshold,
+	}
+}
+
+// LogMode returns the logger unchanged.
+//
+// GORM's LogLevel is deliberately not honoured. Level is the operator's
+// decision and it is expressed once, through LOG_LEVEL and the
+// slog.LevelVar internal/logger holds; a second level knob inside the
+// database layer could only disagree with it. The mapping from GORM's
+// four categories onto slog levels is fixed in Trace below.
+//
+//nolint:ireturn // The interface return is GORM's signature, not a choice.
+func (l *Logger) LogMode(gormlogger.LogLevel) gormlogger.Interface {
+	return l
+}
+
+// Info logs one of GORM's own informational messages.
+func (l *Logger) Info(
+	ctx context.Context, msg string, data ...any,
+) {
+	l.log.InfoContext(ctx, "gorm", "message", format(msg, data...))
+}
+
+// Warn logs one of GORM's own warnings.
+func (l *Logger) Warn(
+	ctx context.Context, msg string, data ...any,
+) {
+	l.log.WarnContext(ctx, "gorm", "message", format(msg, data...))
+}
+
+// Error logs one of GORM's own errors.
+func (l *Logger) Error(
+	ctx context.Context, msg string, data ...any,
+) {
+	l.log.ErrorContext(ctx, "gorm", "message", format(msg, data...))
+}
+
+// Trace reports the outcome of a single statement. GORM calls it for
+// every statement it runs, so the cheap paths stay cheap: fc()
+// renders the interpolated SQL and is called only on a branch that
+// will actually emit.
+//
+// The arms are ordered exactly as GORM's own Trace orders them —
+// non-record-not-found error, then slow, then the routine case — so
+// that a statement which both misses and runs slow is still reported
+// as slow. A miss is the likeliest statement to be slow, since it is
+// the one that scans without finding a row, and ordering the drop
+// ahead of the slow arm would have made this adapter less observant
+// than the IgnoreRecordNotFoundError option it was chosen over.
+func (l *Logger) Trace(
+	ctx context.Context,
+	begin time.Time,
+	fc func() (string, int64),
+	err error,
+) {
+	elapsed := time.Since(begin)
+
+	switch {
+	case err != nil && !errors.Is(err, gormlogger.ErrRecordNotFound):
+		sql, rows := fc()
+		l.log.ErrorContext(ctx, "sql statement failed",
+			"error", logfield.Truncate(err.Error(), logfield.MaxBytes),
+			"sql", logfield.Truncate(sql, logfield.MaxBytes),
+			"rows", rows,
+			"elapsed_ms", elapsed.Milliseconds(),
+		)
+
+	case l.slowThreshold > 0 && elapsed >= l.slowThreshold:
+		sql, rows := fc()
+		l.log.WarnContext(ctx, "slow sql statement",
+			"sql", logfield.Truncate(sql, logfield.MaxBytes),
+			"rows", rows,
+			"elapsed_ms", elapsed.Milliseconds(),
+			"threshold_ms", l.slowThreshold.Milliseconds(),
+		)
+
+	case err != nil:
+		// gorm.ErrRecordNotFound is not an error on the paths that
+		// produce it here: an invented entrypoint UUID and an unknown
+		// username are the expected outcome of an unauthenticated
+		// request, not a fault. This is the IgnoreRecordNotFoundError
+		// behaviour, and it is unconditional rather than configurable
+		// because no caller in this service wants the other one — the
+		// two handlers that care already record the miss themselves,
+		// at DEBUG, without the SQL. A miss that ran slow has already
+		// been reported by the arm above.
+		return
+
+	case l.log.Enabled(ctx, slog.LevelDebug):
+		sql, rows := fc()
+		l.log.DebugContext(ctx, "sql statement",
+			"sql", logfield.Truncate(sql, logfield.MaxBytes),
+			"rows", rows,
+			"elapsed_ms", elapsed.Milliseconds(),
+		)
+	}
+}
+
+// format renders one of GORM's printf-style internal messages and
+// bounds it. GORM builds these itself, but they can quote a value the
+// statement carried, so they are spent through the same budget as
+// everything else rather than trusted.
+func format(msg string, data ...any) string {
+	if len(data) == 0 {
+		return logfield.Truncate(msg, logfield.MaxBytes)
+	}
+
+	return logfield.Truncate(
+		fmt.Sprintf(msg, data...), logfield.MaxBytes,
+	)
+}

internal/gormlog/gormlog_test.go

@@ -0,0 +1,436 @@
+package gormlog_test
+
+import (
+	"bytes"
+	"context"
+	"database/sql"
+	"fmt"
+	"log/slog"
+	"path/filepath"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"gorm.io/driver/sqlite"
+	"gorm.io/gorm"
+	_ "modernc.org/sqlite" // Pure Go SQLite driver.
+	"sneak.berlin/go/webhooker/internal/gormlog"
+	"sneak.berlin/go/webhooker/internal/middleware"
+)
+
+// fillBytes is how much client-chosen text each case drives into the
+// statement. It is well past every budget in play, so a value that
+// arrives short arrived short because something cut it.
+const fillBytes = 8 << 10
+
+// tailMarker sits at the far end of every generated value. A line that
+// contains it carried the whole value, which means nothing cut it — so
+// a value that merely happened to be short cannot pass for a truncated
+// one.
+const tailMarker = "ENDOFCLIENTVALUE"
+
+// fills are the characters a client can drive into a SQL parameter,
+// chosen for what the log handlers charge for them rather than for
+// looking dangerous.
+//
+// The C0 control is the one that matters. Both handlers spell U+0001
+// as a six-byte escape for the single byte it costs a client to send,
+// which is the widest multiplier available in the basic multilingual
+// plane and the case a raw-byte budget breaks on first. The astral
+// non-printable costs ten under the text handler, four more than the
+// JSON handler ever spends.
+func fills() []struct {
+	name string
+	fill string
+} {
+	return []struct {
+		name string
+		fill string
+	}{
+		{"plain", "x"},
+		{"quote", `"`},
+		{"backslash", `\`},
+		{"tab", "\t"},
+		{"newline", "\n"},
+		{"c0_control", "\x01"},
+		{"astral_nonprintable", "\U0001000C"},
+	}
+}
+
+// clientValue builds a value of at least fillBytes raw bytes out of
+// fill, ending in tailMarker.
+func clientValue(fill string) string {
+	var b strings.Builder
+
+	for b.Len() < fillBytes {
+		b.WriteString(fill)
+	}
+
+	b.WriteString(tailMarker)
+
+	return b.String()
+}
+
+// handlers are the two slog handlers internal/logger can install. The
+// ceiling is quoted to operators unqualified, so every case is
+// asserted under both.
+func handlers() []struct {
+	name string
+	make func(*bytes.Buffer) slog.Handler
+} {
+	opts := &slog.HandlerOptions{Level: slog.LevelDebug}
+
+	return []struct {
+		name string
+		make func(*bytes.Buffer) slog.Handler
+	}{
+		{"json", func(b *bytes.Buffer) slog.Handler {
+			return slog.NewJSONHandler(b, opts)
+		}},
+		{"text", func(b *bytes.Buffer) slog.Handler {
+			return slog.NewTextHandler(b, opts)
+		}},
+	}
+}
+
+type thing struct {
+	ID   string `gorm:"primaryKey"`
+	Name string
+}
+
+// neverSlow is a slow-statement threshold no statement in this file
+// can reach. Cases that are about a non-slow arm of Trace set it, so
+// that a machine under load cannot turn a miss into a slow report and
+// decide the outcome for them.
+const neverSlow = time.Hour
+
+// alwaysSlow makes every statement count as slow, so the slow arm is
+// reached without the test waiting for it.
+const alwaysSlow = time.Nanosecond
+
+// openDB opens a real SQLite database behind the adapter under test,
+// so every assertion below is made against SQL that GORM actually
+// rendered rather than against a string a test wrote by hand. slow is
+// the adapter's slow-statement threshold.
+func openDB(
+	t *testing.T, buf *bytes.Buffer, h slog.Handler, slow time.Duration,
+) *gorm.DB {
+	t.Helper()
+
+	sqlDB, err := sql.Open("sqlite", fmt.Sprintf(
+		"file:%s?mode=rwc",
+		filepath.Join(t.TempDir(), "gormlog.db"),
+	))
+	require.NoError(t, err)
+
+	t.Cleanup(func() { _ = sqlDB.Close() })
+
+	gl := gormlog.ExportNewWithSlowThreshold(slog.New(h), slow)
+
+	gdb, err := gorm.Open(
+		sqlite.Dialector{Conn: sqlDB},
+		&gorm.Config{Logger: gl},
+	)
+	require.NoError(t, err)
+
+	require.NoError(t, gdb.AutoMigrate(&thing{}))
+
+	// Migration chatter is not what any of these cases is about.
+	buf.Reset()
+
+	return gdb
+}
+
+// assertBounded holds every line the adapter wrote to the stated
+// ceiling and proves each was cut rather than merely short.
+func assertBounded(t *testing.T, out string) {
+	t.Helper()
+
+	assert.NotContains(
+		t, out, tailMarker,
+		"the far end of the client value reached the log, so "+
+			"nothing truncated it",
+	)
+
+	for line := range strings.SplitSeq(
+		strings.TrimRight(out, "\n"), "\n",
+	) {
+		if line == "" {
+			continue
+		}
+
+		assert.LessOrEqual(
+			t, len(line), middleware.MaxAccessLogLineBytes,
+			"log line exceeded its bound: %s",
+			line[:min(len(line), 300)],
+		)
+	}
+}
+
+// TestRecordNotFound_WritesNothing is the defect itself. GORM's own
+// default logger prints the fully interpolated SELECT on every
+// ErrRecordNotFound, and on this service's two unauthenticated
+// lookups the interpolated parameter is whatever the client sent.
+func TestRecordNotFound_WritesNothing(t *testing.T) {
+	t.Parallel()
+
+	for _, h := range handlers() {
+		for _, f := range fills() {
+			t.Run(h.name+"/"+f.name, func(t *testing.T) {
+				t.Parallel()
+
+				var buf bytes.Buffer
+
+				gdb := openDB(t, &buf, h.make(&buf), neverSlow)
+
+				var got thing
+
+				err := gdb.Where(
+					"id = ?", clientValue(f.fill),
+				).First(&got).Error
+				require.ErrorIs(t, err, gorm.ErrRecordNotFound)
+
+				assert.Empty(
+					t, buf.String(),
+					"a miss on a client-chosen key must not "+
+						"write a log line",
+				)
+			})
+		}
+	}
+}
+
+// TestSlowRecordNotFound_IsStillReportedSlow pins the arm ordering in
+// Trace against the drop above.
+//
+// GORM's own Trace orders its cases error-that-is-not-a-miss, then
+// slow, then routine, so IgnoreRecordNotFoundError: true — the cheap
+// option this adapter was chosen over — still reports a miss that ran
+// slow. An adapter that dropped the miss first would be strictly less
+// observant than the option it replaced, on exactly the two lookups
+// this package exists for. A miss is also the statement most likely to
+// be slow, since it is the one that scans without finding a row.
+func TestSlowRecordNotFound_IsStillReportedSlow(t *testing.T) {
+	t.Parallel()
+
+	for _, h := range handlers() {
+		for _, f := range fills() {
+			t.Run(h.name+"/"+f.name, func(t *testing.T) {
+				t.Parallel()
+
+				var buf bytes.Buffer
+
+				gdb := openDB(t, &buf, h.make(&buf), alwaysSlow)
+
+				var got thing
+
+				err := gdb.Where(
+					"id = ?", clientValue(f.fill),
+				).First(&got).Error
+				require.ErrorIs(t, err, gorm.ErrRecordNotFound)
+
+				assert.Contains(
+					t, buf.String(), "slow sql statement",
+					"a slow statement that missed was not "+
+						"reported as slow",
+				)
+				assertBounded(t, buf.String())
+			})
+		}
+	}
+}
+
+// TestRecordNotFoundFlood_DoesNotGrowWithInput states the definition
+// of done directly: a flood of misses at two input sizes 64 times
+// apart must cost the same number of bytes of log.
+func TestRecordNotFoundFlood_DoesNotGrowWithInput(t *testing.T) {
+	t.Parallel()
+
+	const requests = 50
+
+	flood := func(t *testing.T, size int) int {
+		t.Helper()
+
+		var buf bytes.Buffer
+
+		gdb := openDB(
+			t, &buf,
+			slog.NewJSONHandler(&buf, &slog.HandlerOptions{
+				Level: slog.LevelDebug,
+			}),
+			neverSlow,
+		)
+
+		value := strings.Repeat("\x01", size)
+
+		for range requests {
+			var got thing
+
+			_ = gdb.Where("id = ?", value).First(&got).Error
+		}
+
+		return buf.Len()
+	}
+
+	small := flood(t, 128)
+	big := flood(t, 128*64)
+
+	assert.Equal(
+		t, small, big,
+		"log volume tracked the size of the client's input",
+	)
+}
+
+// TestStatementError_LineIsBounded covers the branch that does log.
+// A driver error is not ErrRecordNotFound, so the interpolated
+// statement is written — and on an insert the interpolated value is
+// still whatever the client supplied.
+func TestStatementError_LineIsBounded(t *testing.T) {
+	t.Parallel()
+
+	for _, h := range handlers() {
+		for _, f := range fills() {
+			t.Run(h.name+"/"+f.name, func(t *testing.T) {
+				t.Parallel()
+
+				var buf bytes.Buffer
+
+				gdb := openDB(t, &buf, h.make(&buf), neverSlow)
+
+				row := thing{ID: clientValue(f.fill), Name: "a"}
+
+				require.NoError(t, gdb.Create(&row).Error)
+
+				buf.Reset()
+
+				// The same primary key a second time: a UNIQUE
+				// constraint failure, which is an error GORM logs.
+				err := gdb.Create(&thing{
+					ID: row.ID, Name: "b",
+				}).Error
+				require.Error(t, err)
+
+				assert.Contains(
+					t, buf.String(), "sql statement failed",
+				)
+				assertBounded(t, buf.String())
+			})
+		}
+	}
+}
+
+// TestSucceedingStatement_LineIsBoundedOnEitherArm covers the two
+// arms a statement that returns no error can take, over the same
+// query, so neither can be bounded by accident of the other.
+//
+//   - slow. Silencing GORM outright would have been the cheaper fix
+//     and would have cost this report, which is the one thing GORM's
+//     logger gave an operator that nothing else in this service does.
+//   - routine. The branch an operator reaches by turning the level
+//     down to DEBUG: every statement is reported, so every
+//     statement's interpolated parameters have to be bounded too.
+func TestSucceedingStatement_LineIsBoundedOnEitherArm(t *testing.T) {
+	t.Parallel()
+
+	// "sql statement" is a substring of "slow sql statement", so the
+	// routine arm carries notWant as well: Contains alone cannot tell
+	// the two arms apart in that direction.
+	arms := []struct {
+		name    string
+		slow    time.Duration
+		want    string
+		notWant string
+	}{
+		{"slow", alwaysSlow, "slow sql statement", ""},
+		{"routine", neverSlow, "sql statement", "slow sql statement"},
+	}
+
+	for _, a := range arms {
+		for _, h := range handlers() {
+			for _, f := range fills() {
+				name := a.name + "/" + h.name + "/" + f.name
+
+				t.Run(name, func(t *testing.T) {
+					t.Parallel()
+
+					var buf bytes.Buffer
+
+					gdb := openDB(t, &buf, h.make(&buf), a.slow)
+
+					var got []thing
+
+					require.NoError(t, gdb.Where(
+						"name = ?", clientValue(f.fill),
+					).Find(&got).Error)
+
+					assert.Contains(t, buf.String(), a.want)
+
+					if a.notWant != "" {
+						assert.NotContains(
+							t, buf.String(), a.notWant,
+						)
+					}
+
+					assertBounded(t, buf.String())
+				})
+			}
+		}
+	}
+}
+
+// TestGORMOwnMessages_AreBounded covers the three printf-style
+// entry points. GORM builds these itself, but nothing stops one of
+// them quoting a value the statement carried.
+func TestGORMOwnMessages_AreBounded(t *testing.T) {
+	t.Parallel()
+
+	for _, h := range handlers() {
+		for _, f := range fills() {
+			t.Run(h.name+"/"+f.name, func(t *testing.T) {
+				t.Parallel()
+
+				var buf bytes.Buffer
+
+				gl := gormlog.New(slog.New(h.make(&buf)))
+				ctx := context.Background()
+				value := clientValue(f.fill)
+
+				gl.Info(ctx, "%s", value)
+				gl.Warn(ctx, "%s", value)
+				gl.Error(ctx, "%s", value)
+
+				// The no-argument form, which is how GORM reports
+				// most of its own conditions. Reached through a
+				// function value so the vet printf check does not
+				// read the message as a format string — which is
+				// also why the adapter does not.
+				noArgs := func(
+					f func(context.Context, string, ...any),
+					msg string,
+				) {
+					f(ctx, msg)
+				}
+				noArgs(gl.Info, value)
+
+				assertBounded(t, buf.String())
+			})
+		}
+	}
+}
+
+// TestLogMode_KeepsTheOperatorsLevel records that GORM's own level
+// knob is deliberately inert: level belongs to LOG_LEVEL, and a
+// second one inside the database layer could only disagree with it.
+func TestLogMode_KeepsTheOperatorsLevel(t *testing.T) {
+	t.Parallel()
+
+	var buf bytes.Buffer
+
+	gl := gormlog.New(slog.New(slog.NewJSONHandler(
+		&buf, &slog.HandlerOptions{Level: slog.LevelDebug},
+	)))
+
+	assert.Same(t, gl, gl.LogMode(0))
+}

internal/handlers/gormlogbound_test.go

@@ -0,0 +1,462 @@
+package handlers_test
+
+import (
+	"bytes"
+	"context"
+	"io"
+	"log"
+	"net/http"
+	"net/http/httptest"
+	"os"
+	"strconv"
+	"strings"
+	"sync"
+	"testing"
+	"time"
+
+	"github.com/go-chi/chi"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"gorm.io/gorm"
+	gormlogger "gorm.io/gorm/logger"
+	"sneak.berlin/go/webhooker/internal/database"
+	"sneak.berlin/go/webhooker/internal/handlers"
+	"sneak.berlin/go/webhooker/internal/middleware"
+)
+
+// gormBoundTailMarker sits at the far end of every client-chosen value
+// this file sends. Its presence in the log means the whole value
+// reached the log, so a value that merely happened to be short cannot
+// pass for a truncated one.
+const gormBoundTailMarker = "ENDOFCLIENTVALUE"
+
+// gormBoundFills are the characters a client can drive through the
+// receiver path segment and the login username, chosen for what a log
+// handler charges for them.
+//
+// The bare C0 control is the one that matters: both handlers spell
+// U+0001 as a six-byte escape for the one byte it costs to send, the
+// widest multiplier available below U+10000 and the case a raw-byte
+// budget breaks on first. GORM's default logger applies no budget at
+// all, so under the mutation every one of these arrives whole.
+func gormBoundFills() []struct {
+	name string
+	fill string
+} {
+	return []struct {
+		name string
+		fill string
+	}{
+		{"plain", "x"},
+		{"quote", `"`},
+		{"backslash", `\`},
+		{"tab", "\t"},
+		{"newline", "\n"},
+		{"c0_control", "\x01"},
+		{"astral_nonprintable", "\U0001000C"},
+	}
+}
+
+// syncBuf collects captured output from the goroutine draining the
+// pipe.
+type syncBuf struct {
+	mu sync.Mutex
+	b  bytes.Buffer
+}
+
+func (s *syncBuf) Write(p []byte) (int, error) {
+	s.mu.Lock()
+	defer s.mu.Unlock()
+
+	return s.b.Write(p)
+}
+
+func (s *syncBuf) String() string {
+	s.mu.Lock()
+	defer s.mu.Unlock()
+
+	return s.b.String()
+}
+
+func (s *syncBuf) reset() {
+	s.mu.Lock()
+	defer s.mu.Unlock()
+
+	s.b.Reset()
+}
+
+// stdoutCapture redirects os.Stdout for the duration of a test.
+//
+// internal/logger builds its handler over os.Stdout at construction
+// time, so redirecting the variable before the application is built
+// captures everything the service logger — and therefore the GORM
+// adapter, which writes through it — emits.
+type stdoutCapture struct {
+	buf  *syncBuf
+	r    *os.File
+	w    *os.File
+	orig *os.File
+	done chan struct{}
+	seq  int
+}
+
+func captureStdout(t *testing.T) *stdoutCapture {
+	t.Helper()
+
+	r, w, err := os.Pipe()
+	require.NoError(t, err)
+
+	c := &stdoutCapture{
+		buf:  &syncBuf{},
+		r:    r,
+		w:    w,
+		orig: os.Stdout,
+		done: make(chan struct{}),
+	}
+
+	os.Stdout = w
+
+	go func() {
+		defer close(c.done)
+
+		_, _ = io.Copy(c.buf, r)
+	}()
+
+	t.Cleanup(func() {
+		os.Stdout = c.orig
+		_ = w.Close()
+
+		<-c.done
+
+		_ = r.Close()
+	})
+
+	return c
+}
+
+// drain returns everything written since the previous drain and
+// clears the buffer.
+//
+// A sentinel is pushed through the same pipe and waited for, so the
+// draining goroutine is known to have caught up before the buffer is
+// read. Without it the comparison below would race the reader rather
+// than measure the writers.
+func (c *stdoutCapture) drain(t *testing.T) string {
+	t.Helper()
+
+	c.seq++
+
+	sentinel := "\n<<drain-" + strconv.Itoa(c.seq) + ">>\n"
+
+	_, err := c.w.WriteString(sentinel)
+	require.NoError(t, err)
+
+	deadline := time.Now().Add(10 * time.Second)
+	for !strings.Contains(c.buf.String(), sentinel) {
+		require.False(
+			t, time.Now().After(deadline),
+			"timed out waiting for captured output",
+		)
+		time.Sleep(time.Millisecond)
+	}
+
+	out := strings.Replace(c.buf.String(), sentinel, "", 1)
+
+	c.buf.reset()
+
+	return out
+}
+
+// teeStdout writes to a buffer and to whatever os.Stdout is at the
+// moment of the write.
+//
+// The second half is the point. GORM's package-level default logger
+// resolves os.Stdout once, at package init, so a logger built over the
+// variable would keep writing to the real terminal no matter what a
+// test redirects. Resolving it per write puts the bytes a defaulted
+// gorm.Config would cost in production into the same capture as
+// everything else internal/logger emits, which is what lets the volume
+// assertions below measure the whole writer set rather than one member
+// of it.
+type teeStdout struct {
+	buf *syncBuf
+}
+
+func (w teeStdout) Write(p []byte) (int, error) {
+	_, _ = os.Stdout.Write(p)
+
+	return w.buf.Write(p)
+}
+
+// captureGORMDefault replaces GORM's package-level default logger with
+// one configured exactly as GORM configures its own, writing to a
+// buffer and to os.Stdout.
+//
+// This is the mutation detector. gormlogger.Default is what a bare
+// &gorm.Config{} installs, and its config here is GORM's verbatim —
+// Warn, IgnoreRecordNotFoundError false — so a reverted call site
+// behaves as it would in production rather than as a test dialed it.
+// With every gorm.Open in this service naming its own logger, nothing
+// consults this value and the buffer stays empty; revert any one of
+// the three and the interpolated SQL lands here.
+func captureGORMDefault(t *testing.T) *syncBuf {
+	t.Helper()
+
+	buf := &syncBuf{}
+	orig := gormlogger.Default
+
+	gormlogger.Default = gormlogger.New(
+		log.New(teeStdout{buf: buf}, "", log.LstdFlags),
+		gormlogger.Config{
+			SlowThreshold:             200 * time.Millisecond,
+			LogLevel:                  gormlogger.Warn,
+			IgnoreRecordNotFoundError: false,
+			Colorful:                  false,
+		},
+	)
+
+	t.Cleanup(func() { gormlogger.Default = orig })
+
+	return buf
+}
+
+// floodUnauthenticated drives reps requests at each of the two
+// unauthenticated lookups that miss by design, for every fill, with a
+// client-chosen value of size raw bytes.
+func floodUnauthenticated(
+	t *testing.T, h *handlers.Handlers, size, reps int,
+) int {
+	t.Helper()
+
+	requests := 0
+
+	for _, f := range gormBoundFills() {
+		var b strings.Builder
+
+		for b.Len() < size {
+			b.WriteString(f.fill)
+		}
+
+		b.WriteString(gormBoundTailMarker)
+
+		value := b.String()
+
+		for range reps {
+			postWebhook(t, h, value)
+			postUnknownLogin(t, h, value)
+
+			requests += 2
+		}
+	}
+
+	return requests
+}
+
+// floodPerWebhook drives the same client-chosen values at the second
+// gorm.Open site, the per-webhook database internal/database's
+// WebhookDBManager opens.
+//
+// That site is behind authentication in production, so this is not
+// part of the unauthenticated flood above and is counted separately.
+// It is here because the ceiling the README states covers every
+// writer, and the manager is one of them: with nothing driving it, a
+// bare &gorm.Config{} could be restored at
+// internal/database/webhook_db_manager.go and the whole suite would
+// stay green.
+func floodPerWebhook(
+	t *testing.T, mgr *database.WebhookDBManager, size, reps int,
+) int {
+	t.Helper()
+
+	requests := 0
+
+	for _, f := range gormBoundFills() {
+		var b strings.Builder
+
+		for b.Len() < size {
+			b.WriteString(f.fill)
+		}
+
+		b.WriteString(gormBoundTailMarker)
+
+		value := b.String()
+
+		db, err := mgr.GetDB("pin-" + f.name)
+		require.NoError(t, err)
+
+		for range reps {
+			var got database.Event
+
+			err = db.Where("id = ?", value).First(&got).Error
+			require.ErrorIs(t, err, gorm.ErrRecordNotFound)
+
+			requests++
+		}
+	}
+
+	return requests
+}
+
+// postWebhook drives the receiver with an invented entrypoint path.
+// The route pattern matches any single segment, so every byte of the
+// value is the client's, and the lookup behind it misses by design.
+func postWebhook(
+	t *testing.T, h *handlers.Handlers, entrypoint string,
+) {
+	t.Helper()
+
+	req := httptest.NewRequestWithContext(
+		context.Background(), http.MethodPost, "/webhook/x",
+		strings.NewReader("{}"),
+	)
+
+	rctx := chi.NewRouteContext()
+	rctx.URLParams.Add("uuid", entrypoint)
+
+	req = req.WithContext(context.WithValue(
+		req.Context(), chi.RouteCtxKey, rctx,
+	))
+
+	w := httptest.NewRecorder()
+	h.HandleWebhook().ServeHTTP(w, req)
+
+	require.Equal(t, http.StatusNotFound, w.Code)
+}
+
+// postUnknownLogin submits the login form with an unknown username,
+// through the postLogin helper in logbound_test.go. The field is
+// bounded only by the 1 MB body cap, and the lookup behind it misses
+// by design.
+func postUnknownLogin(
+	t *testing.T, h *handlers.Handlers, username string,
+) {
+	t.Helper()
+
+	// 401 while the client still has failure budget against this
+	// username, 429 once the login guard has taken it away. Both
+	// outcomes sit behind the user lookup, which is the query this
+	// test is here to drive.
+	require.Contains(
+		t,
+		[]int{http.StatusUnauthorized, http.StatusTooManyRequests},
+		postLogin(t, h, username),
+	)
+}
+
+// assertFloodBounded holds every captured line to the stated ceiling
+// and proves nothing carried a whole client value.
+func assertFloodBounded(t *testing.T, label, out string) {
+	t.Helper()
+
+	assert.NotContains(
+		t, out, gormBoundTailMarker,
+		"%s: the far end of a client-chosen value reached the "+
+			"log, so nothing truncated it", label,
+	)
+
+	for line := range strings.SplitSeq(
+		strings.TrimRight(out, "\n"), "\n",
+	) {
+		if line == "" {
+			continue
+		}
+
+		assert.LessOrEqual(
+			t, len(line), middleware.MaxAccessLogLineBytes,
+			"%s: log line exceeded its bound: %s",
+			label, line[:min(len(line), 300)],
+		)
+	}
+}
+
+// TestFlood_NoWriterGrowsWithTheInput is the definition of done for
+// the GORM logger defect, stated over every writer at once, for two of
+// this service's three gorm.Open sites: the main database behind the
+// two unauthenticated lookups, and the per-webhook database the
+// WebhookDBManager opens. The third, the archive writer, is pinned in
+// internal/delivery, where its type lives.
+//
+// What each assertion is worth, since two of the three would pass
+// against a service that had never been fixed if the capture were set
+// up differently:
+//
+//   - The gormDefault check is the sharp one. It fires the moment any
+//     gorm.Open in this service goes back to a bare &gorm.Config{}.
+//   - The volume and per-line checks bite only because the replaced
+//     default logger tees into os.Stdout, so a reverted call site
+//     shows up in the same capture as everything internal/logger
+//     writes — the way it would in production. Without that tee both
+//     were vacuous: at INFO the two handler misses log at DEBUG and
+//     the adapter drops the record-not-found, so the capture holds
+//     nothing but fixed-string warnings.
+//
+// The level is left where newTestApp leaves it, at INFO: the level an
+// operator runs at by default, and the one the defect was visible at.
+// The handlers' own miss lines sit at DEBUG and spend the same
+// logfield budget as everything else, so they are not what makes
+// either assertion above bite at any level.
+//
+// It is deliberately not parallel: it redirects os.Stdout and replaces
+// gormlogger.Default, both of which are process-global. Go runs every
+// non-parallel top-level test to completion before it resumes the
+// parallel ones, so nothing else in this package is running while the
+// capture is installed.
+//
+//nolint:paralleltest // Deliberately sequential; see above.
+func TestFlood_NoWriterGrowsWithTheInput(t *testing.T) {
+	const (
+		smallBytes = 128
+		bigBytes   = 8 << 10
+		reps       = 5
+	)
+
+	gormDefault := captureGORMDefault(t)
+	capture := captureStdout(t)
+
+	var (
+		h   *handlers.Handlers
+		mgr *database.WebhookDBManager
+	)
+
+	app := newTestApp(t, &h, &mgr)
+	app.RequireStart()
+
+	t.Cleanup(app.RequireStop)
+
+	// Startup chatter is not what this test measures.
+	capture.drain(t)
+
+	floodUnauthenticated(t, h, smallBytes, reps)
+	floodPerWebhook(t, mgr, smallBytes, reps)
+
+	small := capture.drain(t)
+
+	requests := floodUnauthenticated(t, h, bigBytes, reps)
+	requests += floodPerWebhook(t, mgr, bigBytes, reps)
+	big := capture.drain(t)
+
+	assertFloodBounded(t, "small flood", small)
+	assertFloodBounded(t, "big flood", big)
+
+	// GORM's default logger is what the defect was. Nothing in this
+	// service may reach it.
+	got := gormDefault.String()
+	assert.Empty(
+		t, got,
+		"GORM's default logger wrote %d bytes; the first of them: %s",
+		len(got), got[:min(len(got), 300)],
+	)
+
+	// The same flood, with 64 times the client-chosen input, must not
+	// buy 64 times the log. A few bytes of slack covers a latency
+	// field changing width; the input grew by roughly half a megabyte.
+	const slackPerRequest = 64
+
+	assert.LessOrEqual(
+		t, len(big), len(small)+slackPerRequest*requests,
+		"log volume tracked the size of the client's input: "+
+			"%d bytes at %d bytes of input per request, %d bytes "+
+			"at %d",
+		len(small), smallBytes, len(big), bigBytes,
+	)
+}

internal/logfield/logfield_test.go

@@ -219,3 +219,103 @@ func TestTruncate_DropsInvalidUTF8(t *testing.T) {
 	assert.Equal(t, "abc", got)
 	assert.True(t, utf8.ValidString(got))
 }
+
+// encodedCost is what a whole string costs on a line, by the same
+// accounting Truncate spends its budget with.
+func encodedCost(s string) int {
+	total := 0
+	for _, r := range s {
+		total += logfield.EncodedBytes(r)
+	}
+
+	return total
+}
+
+// TestTruncate_SpendsEncodedBytesNotRawBytes is the zero-headroom
+// version of TestTruncate_SpendsNoMoreThanTheBudget above, and of the
+// line-length assertions elsewhere.
+//
+// A line ceiling has slack in it by construction, and a LessOrEqual
+// against the budget cannot tell a budget spent exactly from one
+// spent under. Here the budget is checked against exactly what it
+// bought: a value built from a single rune must keep exactly
+// MaxBytes/EncodedBytes(r) of them, with nothing spare. A raw-byte
+// budget — cost := utf8.RuneLen(r) — fails this for every rune the
+// handlers escape.
+func TestTruncate_SpendsEncodedBytesNotRawBytes(t *testing.T) {
+	t.Parallel()
+
+	for name, r := range map[string]rune{
+		"plain":           'x',
+		"quote":           '"',
+		"backslash":       '\\',
+		"tab":             '\t',
+		"newline":         '\n',
+		"carriage_return": '\r',
+		"c0_control":      '\x01',
+		"del":             '\x7f',
+		// U+2028 LINE SEPARATOR, which only the JSON handler
+		// escapes.
+		"line_separator":      '
',
+		"astral_nonprintable": '\U0001000C',
+		"multibyte_printable": 'é',
+		// U+20AC, a three-byte printable rune, charged its own
+		// UTF-8 bytes rather than an escape.
+		"three_byte_printable": '€',
+		"emoji_printable":      '\U0001F600',
+	} {
+		t.Run(name, func(t *testing.T) {
+			t.Parallel()
+
+			cost := logfield.EncodedBytes(r)
+			want := logfield.MaxBytes / cost
+
+			// Far past the budget under either accounting.
+			in := strings.Repeat(string(r), logfield.MaxBytes*2)
+
+			got := logfield.Truncate(in, logfield.MaxBytes)
+
+			require.True(
+				t, strings.HasSuffix(
+					got, logfield.TruncationMarker,
+				),
+				"a value past the budget must be marked",
+			)
+
+			kept := strings.TrimSuffix(
+				got, logfield.TruncationMarker,
+			)
+
+			assert.Equal(
+				t, want, utf8.RuneCountInString(kept),
+				"budget bought the wrong number of runes at "+
+					"%d encoded bytes each", cost,
+			)
+			assert.LessOrEqual(
+				t, encodedCost(kept), logfield.MaxBytes,
+			)
+		})
+	}
+}
+
+// TestTruncate_NeverSplitsARune covers a cut landing inside a
+// multi-byte encoding rather than between two of them.
+func TestTruncate_NeverSplitsARune(t *testing.T) {
+	t.Parallel()
+
+	// U+20AC, three bytes and printable, so a small budget lands
+	// inside an encoding rather than on a boundary.
+	in := strings.Repeat("€", logfield.MaxBytes)
+
+	for b := 1; b <= 16; b++ {
+		got := strings.TrimSuffix(
+			logfield.Truncate(in, b), logfield.TruncationMarker,
+		)
+
+		assert.True(
+			t, utf8.ValidString(got),
+			"budget %d produced invalid UTF-8", b,
+		)
+		assert.LessOrEqual(t, encodedCost(got), b)
+	}
+}

internal/middleware/middleware.go

@@ -67,6 +67,9 @@ const (
 	//	                                        ----
 	//	                                        2087
 	//
+	// The 512 is logfield.MaxBytes; the 11 is the truncation marker,
+	// charged on top of each budget rather than inside it.
+	//
 	// The fixed portion is the JSON punctuation, the field names, the
 	// level and the message, both timestamps at their longest, an IPv6
 	// remoteIP with a zone, a three-digit status and a full-width int64
@@ -104,6 +107,17 @@ const (
 	// a caller on a parameterised route would supply, which is the
 	// only way those caps can be pinned at all.
 	//
+	// One writer in that set is not a handler's own slog call. The
+	// GORM adapter in internal/gormlog logs the statement with the
+	// client-chosen parameter already interpolated into it, which on
+	// the receiver and login lookups is exactly the value the budgets
+	// above exist for. Its widest line spends two logfield.MaxBytes
+	// budgets — the statement and the driver error — against a fixed
+	// portion smaller than this one's, and
+	// internal/gormlog/gormlog_test.go asserts every line it emits
+	// against this constant directly rather than leaving it as
+	// arithmetic.
+	//
 	// What it does NOT cover, so that the figure above is not read as
 	// more than it is:
 	//
@@ -119,10 +133,16 @@ const (
 	//   - The "log" delivery target, which exists to write the whole
 	//     inbound event to the log. Deliberate; see
 	//     internal/delivery/target_log.go.
-	//   - GORM's default logger, which prints the interpolated SQL to
+	//   - The widest line the service can write, which is neither an
-	//     stdout on a record-not-found and so is unbounded on the
+	//     access log line nor client-chosen. A handler panic arrives
-	//     receiver and login lookups. NOT deliberate; filed as
+	//     through net/http's nil ErrorLog as one record carrying a
-	//     https://git.eeqj.de/sneak/webhooker/issues/178.
+	//     whole goroutine stack, above this figure — measured at
+	//     roughly 2,770 bytes. The exact width is not an invariant: it
+	//     moves with the goroutine number and with the source paths
+	//     baked into the stack. That it exceeds this ceiling does not
+	//     move. The value is the runtime's, not a client's; see
+	//     README.md and
+	//     https://git.eeqj.de/sneak/webhooker/issues/187.
 	MaxAccessLogLineBytes = 2560
 )