Files
pulse/internal/api/middleware.go
T
rcourtman 14a82e7684 fix(api): log routine authorization refusals at debug, warn on the rate
A refusal is the access control working, not a fault, but every one of them
warned twice: once in RequireAuth/RequireAdmin/RequirePermission, and again in
the middleware, which warned on every 4xx unconditionally. A correctly
configured instance therefore could not produce a quiet log, and #1601's rc.9
reporter read that stream as an RBAC regression.

Gating clients one at a time does not fix this. The previous commit stopped six
endpoints being polled by a non-admin UI, and /api/updates/status,
/api/updates/plan and /api/availability-targets still warned, as would every
caller nobody has audited yet.

Refusals now route through logAuthDenial, which records them at debug and counts
them per caller. Attribution prefers the authenticated username so a principal
stays tracked across rotating addresses, falling back to the client IP. Crossing
20 refusals in a minute emits exactly one warn for that window, which is the
shape that separates probing from a UI mounting a surface its session cannot
read; a closed window re-arms it. The tracked set is bounded with oldest-window
eviction so spoofed forwarded-for values cannot grow it. The middleware now
warns only on 5xx.

Enforcement is untouched: every route returns the same status to the same
callers, and the contract test pins that pairing so a future attempt to quiet
the log by relaxing enforcement fails rather than passes. Verified live on a
proxy-auth instance - /api/connections, /api/updates/status and
/api/system/settings still 403 for a viewer and 200 for an admin; 19 refusals
produce no warn, the 20th produces one, and 30 more produce none; an idle
non-admin browser session logged zero warn lines across 90 seconds.
2026-08-07 21:38:47 +01:00

208 lines
5.6 KiB
Go

package api
import (
"bufio"
"encoding/json"
"fmt"
"net"
"net/http"
"runtime/debug"
"strings"
"time"
"github.com/rcourtman/pulse-go-rewrite/internal/logging"
"github.com/rs/zerolog/log"
)
// APIError represents a structured API error response
type APIError struct {
ErrorMessage string `json:"error"`
Code string `json:"code,omitempty"`
StatusCode int `json:"status_code"`
Timestamp int64 `json:"timestamp"`
RequestID string `json:"request_id,omitempty"`
Details map[string]string `json:"details"`
}
const maxIncomingRequestIDLength = 128
func EmptyAPIError() APIError {
return APIError{}.NormalizeCollections()
}
func (e APIError) NormalizeCollections() APIError {
if e.Details == nil {
e.Details = map[string]string{}
}
return e
}
// Error implements the error interface
func (e *APIError) Error() string {
return e.ErrorMessage
}
// ErrorHandler is a middleware that handles panics and errors
func ErrorHandler(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
// Fix for issue #334: Normalize empty path to "/" before ServeMux processes it
// This prevents the automatic redirect from "" to "./"
if r.URL.Path == "" {
r.URL.Path = "/"
}
// Skip error handling for WebSocket endpoints
if r.Header.Get("Upgrade") == "websocket" {
next.ServeHTTP(w, r)
return
}
// Add request ID to context, honoring only a bounded safe header value.
incomingID := sanitizeIncomingRequestID(r.Header.Get("X-Request-ID"))
ctxWithID, requestID := logging.WithRequestID(r.Context(), incomingID)
r = r.WithContext(ctxWithID)
// Create a custom response writer to capture status codes
rw := &responseWriter{ResponseWriter: w, statusCode: http.StatusOK}
rw.Header().Set("X-Request-ID", requestID)
start := time.Now()
routeLabel := normalizeRoute(r.URL.Path)
method := r.Method
defer func() {
elapsed := time.Since(start)
recordAPIRequest(method, routeLabel, rw.StatusCode(), elapsed)
}()
// Recover from panics
defer func() {
if err := recover(); err != nil {
log.Error().
Interface("error", err).
Str("path", r.URL.Path).
Str("method", r.Method).
Str("request_id", requestID).
Bytes("stack", debug.Stack()).
Msg("Panic recovered in API handler")
writeErrorResponse(rw, http.StatusInternalServerError, "internal_error",
"An unexpected error occurred", nil)
}
}()
// Call the next handler
next.ServeHTTP(rw, r)
// A 5xx is ours to explain, so it warns. A 4xx is the client being told
// no — an unauthenticated bootstrap request, an RBAC refusal, a probe for
// an endpoint this build does not serve — and warning on each one meant a
// correctly behaving instance could never produce a quiet log. Those go to
// debug; logAuthDenial carries the escalation for refusals that arrive at
// a rate worth an operator's attention.
if rw.statusCode >= 400 {
event := log.Debug()
if rw.statusCode >= 500 {
event = log.Warn()
}
event.
Str("path", r.URL.Path).
Str("method", r.Method).
Int("status", rw.statusCode).
Str("request_id", requestID).
Msg("Request failed")
}
})
}
// writeErrorResponse writes a consistent error response
func writeErrorResponse(w http.ResponseWriter, statusCode int, code, message string, details map[string]string) {
w.Header().Set("Content-Type", "application/json")
w.WriteHeader(statusCode)
resp := EmptyAPIError()
resp.ErrorMessage = message
resp.Code = code
resp.StatusCode = statusCode
resp.Timestamp = time.Now().Unix()
resp.Details = details
resp = resp.NormalizeCollections()
if err := json.NewEncoder(w).Encode(resp); err != nil {
log.Error().Err(err).Msg("Failed to encode error response")
}
}
func sanitizeIncomingRequestID(raw string) string {
requestID := strings.TrimSpace(raw)
if requestID == "" || len(requestID) > maxIncomingRequestIDLength {
return ""
}
for i := 0; i < len(requestID); i++ {
b := requestID[i]
if (b >= 'a' && b <= 'z') ||
(b >= 'A' && b <= 'Z') ||
(b >= '0' && b <= '9') ||
b == '-' || b == '_' || b == '.' || b == ':' {
continue
}
return ""
}
return requestID
}
// sanitizeErrorForClient returns a generic, safe message for an internal error.
// The raw error is logged server-side; the client only sees the generic message.
// Use this instead of passing err.Error() to http.Error or writeErrorResponse.
func sanitizeErrorForClient(err error, genericMsg string) string {
if err != nil {
log.Error().Err(err).Msg(genericMsg)
}
return genericMsg
}
// responseWriter wraps http.ResponseWriter to capture status codes
type responseWriter struct {
http.ResponseWriter
statusCode int
written bool
}
func (rw *responseWriter) WriteHeader(code int) {
if !rw.written {
rw.statusCode = code
rw.ResponseWriter.WriteHeader(code)
rw.written = true
}
}
func (rw *responseWriter) Write(b []byte) (int, error) {
if !rw.written {
rw.WriteHeader(http.StatusOK)
}
return rw.ResponseWriter.Write(b)
}
func (rw *responseWriter) StatusCode() int {
if rw == nil {
return http.StatusInternalServerError
}
return rw.statusCode
}
// Hijack implements http.Hijacker interface
func (rw *responseWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) {
hijacker, ok := rw.ResponseWriter.(http.Hijacker)
if !ok {
return nil, nil, fmt.Errorf("ResponseWriter does not implement http.Hijacker")
}
return hijacker.Hijack()
}
// Flush implements http.Flusher when the underlying writer supports it.
func (rw *responseWriter) Flush() {
if flusher, ok := rw.ResponseWriter.(http.Flusher); ok {
flusher.Flush()
}
}