Files
minstrel/internal/server/requestlog.go
T
bvandeusen 4b088e6b6f feat(server): slog request log + log dropped Lidarr ping errors
Two debuggability gaps surfaced by the /api/admin route shadowing
investigation:

1. handleTestLidarrConnection swallowed client.Ping's error — only the
   bucket code (lidarr_unreachable) reached the response, the underlying
   *net.DNSError / *net.OpError / TLS error never reached the logs.
   Operators couldn't tell a typo'd hostname from a wrong port from a
   refused TLS handshake. Now logged at Warn (expected-when-misconfigured)
   with the base_url for diagnostic context. The api_key is never logged.

2. The chi router had no access-log middleware — every 4xx/5xx was silent,
   making it impossible to tell whether a request even reached the server.
   chi's middleware.Logger writes to the standard log package not slog,
   so a small slog wrapper handles it instead. /healthz is skipped (the
   compose healthcheck hits it every 5s; would be ~17k log lines/day of
   noise). Severity is keyed off response status: 5xx -> Error,
   4xx -> Warn, else Info — so 4xx/5xx surface even when the operator's
   logger level is set above Info.

Tests cover both the severity routing and the /healthz skip.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-05-01 22:10:04 -04:00

51 lines
1.4 KiB
Go

package server
import (
"log/slog"
"net/http"
"time"
"github.com/go-chi/chi/v5/middleware"
)
// requestLog is an slog-based access log middleware. chi ships
// middleware.Logger but it writes to the standard library's log package,
// not slog, so output ordering and formatting drift from the rest of the
// server's logs. We use a thin wrapper instead.
//
// The /healthz path is skipped because the docker-compose healthcheck
// hits it every 5s and would otherwise drown real signals (~17k lines/day).
//
// Severity is keyed off the response status so 4xx/5xx surface even when
// the operator's logger level is set above Info.
func requestLog(logger *slog.Logger) func(http.Handler) http.Handler {
return func(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
if r.URL.Path == "/healthz" {
next.ServeHTTP(w, r)
return
}
start := time.Now()
ww := middleware.NewWrapResponseWriter(w, r.ProtoMajor)
next.ServeHTTP(ww, r)
status := ww.Status()
attrs := []any{
"method", r.Method,
"path", r.URL.Path,
"status", status,
"duration_ms", time.Since(start).Milliseconds(),
"request_id", middleware.GetReqID(r.Context()),
"remote", r.RemoteAddr,
}
switch {
case status >= 500:
logger.Error("http", attrs...)
case status >= 400:
logger.Warn("http", attrs...)
default:
logger.Info("http", attrs...)
}
})
}
}