package api import ( "context" "crypto/rand" "encoding/hex" "log/slog" "net/http" "runtime/debug" "time" ) type requestIDKey struct{} // RequestIDFrom returns the id assigned by WithRequestID, or "". func RequestIDFrom(ctx context.Context) string { id, _ := ctx.Value(requestIDKey{}).(string) return id } // WithRequestID tags each request so a log line can be tied to a client report. // Honours an inbound X-Request-Id so a self-hosted bot can correlate its own // logs with the backend's. func WithRequestID(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { id := r.Header.Get("X-Request-Id") if id == "" || len(id) > 64 { var b [8]byte if _, err := rand.Read(b[:]); err == nil { id = hex.EncodeToString(b[:]) } } w.Header().Set("X-Request-Id", id) next.ServeHTTP(w, r.WithContext(context.WithValue(r.Context(), requestIDKey{}, id))) }) } // statusRecorder captures the status code, which http.ResponseWriter does not // expose after the fact. type statusRecorder struct { http.ResponseWriter status int bytes int } func (s *statusRecorder) WriteHeader(code int) { s.status = code s.ResponseWriter.WriteHeader(code) } func (s *statusRecorder) Write(b []byte) (int, error) { if s.status == 0 { s.status = http.StatusOK } n, err := s.ResponseWriter.Write(b) s.bytes += n return n, err } // WithLogging records one line per request. // // Deliberately does NOT log the Authorization header, the query string or the // body. Logs get shipped, grepped and retained far longer than anyone intends, // and the query string is where callsigns and grid squares live. func WithLogging(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) { start := time.Now() rec := &statusRecorder{ResponseWriter: w} next.ServeHTTP(rec, r) if rec.status == 0 { rec.status = http.StatusOK } attrs := []any{ "method", r.Method, "path", r.URL.Path, "status", rec.status, "bytes", rec.bytes, "duration_ms", time.Since(start).Milliseconds(), "request_id", RequestIDFrom(r.Context()), } // Key id rather than the key, and only once authentication has // resolved one. if p := PrincipalFrom(r.Context()); p != nil { attrs = append(attrs, "key_id", p.KeyID, "owner_id", p.OwnerID) } level := slog.LevelInfo if rec.status >= 500 { level = slog.LevelError } logger.Log(r.Context(), level, "request", attrs...) }) } } // WithRecovery turns a panic in a handler into a 500 rather than a dead // process. Go's default is to kill the whole server on an unrecovered panic in // a handler goroutine. func WithRecovery(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) { defer func() { rec := recover() if rec == nil { return } // A closed connection surfaces as a panic with this value and // is not a bug; re-panic so net/http handles it as it expects. if rec == http.ErrAbortHandler { panic(rec) } logger.Error("panic in handler", "err", rec, "path", r.URL.Path, "request_id", RequestIDFrom(r.Context()), "stack", string(debug.Stack())) WriteError(w, http.StatusInternalServerError, CodeInternal, "Something went wrong. The incident has been logged.") }() next.ServeHTTP(w, r) }) } } // Chain applies middleware so that the first argument is the outermost, which // reads in the order requests actually traverse them. func Chain(h http.Handler, mw ...func(http.Handler) http.Handler) http.Handler { for i := len(mw) - 1; i >= 0; i-- { h = mw[i](h) } return h }