feat(auth): audit-log rejections + 503 on Dex outage (gitea-mcp#9, #6)

BearerMiddleware now emits a structured slog line on every rejection with the
reason (no_token / static_token_mismatch / jwt_invalid / jwt_dex_unavailable),
client IP (X-Forwarded-For aware), presented token type (jwt/opaque), and a
truncated SHA-256 fingerprint — never the raw token, so no secret material
reaches stdout/log aggregation.

Validate now tags a JWKS/Dex fetch failure with the exported ErrUnavailable
sentinel (distinct from a present-but-invalid token). BearerMiddleware maps it
to HTTP 503 with `WWW-Authenticate: Bearer error="temporarily_unavailable"`, so
a transient Dex outage is distinguishable from a bad token instead of a silent
generic 401.

No signature change — logging goes through slog.Default(); existing consumers
are unaffected until they set a default logger. Behavior reaches a consumer only
when it bumps the chassis version.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

README.md

@@ -48,7 +48,7 @@ import (
 	"net/http"
 	"os"
 
-	"gitea.d-ma.be/mathias/mcp-chassis/auth"
+	"git.d-ma.be/mathias/mcp-chassis/auth"
 )
 
 func main() {
@@ -82,7 +82,7 @@ func mcpHandler() http.Handler { /* per-domain */ return nil }
 ## Versioning
 
 Trunk-based development on `main`. Tagged with semver. Consumers pin
-specific tags (`go.mod` `require gitea.d-ma.be/mathias/mcp-chassis v0.x.y`)
+specific tags (`go.mod` `require git.d-ma.be/mathias/mcp-chassis v0.x.y`)
 and bump deliberately.
 
 Migrations are documented per-consumer in the consumer's CHANGELOG / commits.

auth/bearer.go

@@ -1,7 +1,12 @@
 package auth
 
 import (
+	"crypto/sha256"
 	"crypto/subtle"
+	"encoding/hex"
+	"errors"
+	"log/slog"
+	"net"
 	"net/http"
 	"strings"
 )
@@ -44,7 +49,7 @@ func BearerMiddleware(
 	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		rawToken, ok := strings.CutPrefix(r.Header.Get("Authorization"), "Bearer ")
 		if !ok || rawToken == "" {
-			unauthorized(w, realm, resourceMetadataURL)
+			deny(w, r, realm, resourceMetadataURL, http.StatusUnauthorized, "no_token", rawToken)
 			return
 		}
 
@@ -57,21 +62,89 @@ func BearerMiddleware(
 
 		// 2. Then Dex JWT, if configured.
 		if validator != nil {
-			if _, err := validator.Validate(r.Context(), rawToken); err == nil {
+			switch _, err := validator.Validate(r.Context(), rawToken); {
+			case err == nil:
 				next.ServeHTTP(w, r)
 				return
+			case errors.Is(err, ErrUnavailable):
+				// Dex/JWKS is down — the token might be fine, we just can't
+				// check. Answer 503 so the caller retries rather than treating
+				// it as a hard auth failure (gitea-mcp#6).
+				deny(w, r, realm, resourceMetadataURL, http.StatusServiceUnavailable, "jwt_dex_unavailable", rawToken)
+				return
+			default:
+				deny(w, r, realm, resourceMetadataURL, http.StatusUnauthorized, "jwt_invalid", rawToken)
+				return
 			}
 		}
 
-		// 3. Reject with an OAuth resource-metadata challenge if configured.
-		unauthorized(w, realm, resourceMetadataURL)
+		// 3. Static token was wrong and no JWT validator is configured.
+		deny(w, r, realm, resourceMetadataURL, http.StatusUnauthorized, "static_token_mismatch", rawToken)
 	})
 }
 
-func unauthorized(w http.ResponseWriter, realm, resourceMetadataURL string) {
+// deny writes the auth rejection and emits a structured audit log line
+// (gitea-mcp#9). The log records the reason, client IP, presented token type,
+// and a non-reversible token fingerprint — never the raw token, so nothing
+// secret lands in stdout/log aggregation. slog adds the timestamp.
+func deny(w http.ResponseWriter, r *http.Request, realm, resourceMetadataURL string, status int, reason, rawToken string) {
+	slog.Warn("mcp auth rejected",
+		"reason", reason,
+		"status", status,
+		"remote", clientIP(r),
+		"token_type", tokenType(rawToken),
+		"token_fp", fingerprint(rawToken),
+		"path", r.URL.Path,
+	)
+
+	if status == http.StatusServiceUnavailable {
+		// RFC 6750 §3.1: temporarily_unavailable signals a transient failure.
+		w.Header().Set("WWW-Authenticate", `Bearer realm="`+realm+`", error="temporarily_unavailable"`)
+		http.Error(w, "temporarily unavailable", http.StatusServiceUnavailable)
+		return
+	}
+
 	if resourceMetadataURL != "" {
 		w.Header().Set("WWW-Authenticate",
 			`Bearer realm="`+realm+`", resource_metadata="`+resourceMetadataURL+`"`)
 	}
 	http.Error(w, "unauthorized", http.StatusUnauthorized)
 }
+
+// clientIP prefers the left-most X-Forwarded-For entry (the original client
+// behind the reverse proxy) and falls back to the transport peer.
+func clientIP(r *http.Request) string {
+	if xff := r.Header.Get("X-Forwarded-For"); xff != "" {
+		if i := strings.IndexByte(xff, ','); i > 0 {
+			return strings.TrimSpace(xff[:i])
+		}
+		return strings.TrimSpace(xff)
+	}
+	if host, _, err := net.SplitHostPort(r.RemoteAddr); err == nil {
+		return host
+	}
+	return r.RemoteAddr
+}
+
+// tokenType classifies the presented credential without revealing it: a
+// three-segment dotted value is a JWT, anything else an opaque/static token.
+func tokenType(raw string) string {
+	switch {
+	case raw == "":
+		return "none"
+	case strings.Count(raw, ".") == 2:
+		return "jwt"
+	default:
+		return "opaque"
+	}
+}
+
+// fingerprint is a short, non-reversible correlator (truncated SHA-256) so ops
+// can group repeated attempts from one client without ever logging token bytes.
+func fingerprint(raw string) string {
+	if raw == "" {
+		return ""
+	}
+	sum := sha256.Sum256([]byte(raw))
+	return hex.EncodeToString(sum[:])[:12]
+}

auth/bearer_test.go

@@ -1,13 +1,78 @@
 package auth
 
 import (
+	"bytes"
+	"context"
+	"log/slog"
 	"net/http"
 	"net/http/httptest"
 	"testing"
 
+	"github.com/lestrrat-go/jwx/v2/jwk"
+	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 )
 
+// unavailableValidator returns a validator whose JWKS cache cannot be fetched,
+// so Validate fails with ErrUnavailable — simulating a Dex/JWKS outage.
+func unavailableValidator(t *testing.T) *JWTValidator {
+	t.Helper()
+	return &JWTValidator{
+		issuer:   "https://dex.example",
+		jwksURI:  "http://127.0.0.1:0/jwks", // unregistered in cache → Get fails
+		cache:    jwk.NewCache(context.Background()),
+		audience: "",
+	}
+}
+
+// #6: a JWKS/Dex outage at validation time is ErrUnavailable, distinct from a
+// present-but-invalid token.
+func TestValidate_JWKSUnreachable_IsUnavailable(t *testing.T) {
+	t.Parallel()
+	_, err := unavailableValidator(t).Validate(context.Background(), "some.jwt.token")
+	require.Error(t, err)
+	require.ErrorIs(t, err, ErrUnavailable)
+}
+
+// #6: when JWT validation can't complete because Dex is down, answer 503
+// temporarily_unavailable rather than a generic 401.
+func TestBearerMiddleware_DexDown_503(t *testing.T) {
+	t.Parallel()
+	h := BearerMiddleware("static-tok", unavailableValidator(t), "gitea", "",
+		http.HandlerFunc(func(http.ResponseWriter, *http.Request) {
+			t.Fatal("next must NOT be called when Dex is down")
+		}))
+	rec := httptest.NewRecorder()
+	req := httptest.NewRequest(http.MethodGet, "/", nil)
+	req.Header.Set("Authorization", "Bearer aaa.bbb.ccc") // not the static token → JWT path
+	h.ServeHTTP(rec, req)
+
+	require.Equal(t, http.StatusServiceUnavailable, rec.Code)
+	require.Contains(t, rec.Header().Get("WWW-Authenticate"), `error="temporarily_unavailable"`)
+}
+
+// #9: every rejection is audit-logged with reason, remote, token type, and a
+// non-reversible token fingerprint — never the raw token.
+func TestBearerMiddleware_AuditLogsRejection(t *testing.T) {
+	var buf bytes.Buffer
+	prev := slog.Default()
+	slog.SetDefault(slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo})))
+	defer slog.SetDefault(prev)
+
+	h := BearerMiddleware("expected-secret", nil, "gitea", "",
+		http.HandlerFunc(func(http.ResponseWriter, *http.Request) {}))
+	rec := httptest.NewRecorder()
+	req := httptest.NewRequest(http.MethodGet, "/", nil)
+	req.Header.Set("Authorization", "Bearer wrong-secret-value")
+	h.ServeHTTP(rec, req)
+
+	require.Equal(t, http.StatusUnauthorized, rec.Code)
+	logged := buf.String()
+	assert.Contains(t, logged, "static_token_mismatch")
+	assert.Contains(t, logged, "token_fp")
+	assert.NotContains(t, logged, "wrong-secret-value", "raw token must never be logged")
+}
+
 func TestBearerMiddleware_StaticTokenWins(t *testing.T) {
 	t.Parallel()
 

auth/jwt.go

@@ -12,6 +12,7 @@ package auth
 import (
 	"context"
 	"encoding/json"
+	"errors"
 	"fmt"
 	"net/http"
 	"time"
@@ -20,6 +21,13 @@ import (
 	"github.com/lestrrat-go/jwx/v2/jwt"
 )
 
+// ErrUnavailable indicates JWT validation could not be COMPLETED because the
+// JWKS / Dex endpoint was unreachable — a transient condition — as opposed to
+// the token being present and invalid. Callers (e.g. BearerMiddleware) map it
+// to HTTP 503 temporarily_unavailable rather than a generic 401, so a Dex
+// outage is distinguishable from a bad token (gitea-mcp#6).
+var ErrUnavailable = errors.New("jwt validation temporarily unavailable")
+
 // JWTValidator validates Bearer JWTs issued by a Dex (OIDC) authorization server.
 // Audience is optional; leave empty to skip audience validation.
 //
@@ -94,7 +102,9 @@ func (v *JWTValidator) Validate(ctx context.Context, rawToken string) (string, e
 
 	keySet, err := v.cache.Get(ctx, v.jwksURI)
 	if err != nil {
-		return "", fmt.Errorf("get jwks: %w", err)
+		// The JWKS could not be fetched — Dex/JWKS is unreachable, not a bad
+		// token. Tag it ErrUnavailable so the caller can answer 503, not 401.
+		return "", fmt.Errorf("%w: get jwks: %v", ErrUnavailable, err)
 	}
 
 	opts := []jwt.ParseOption{

go.mod

@@ -1,4 +1,4 @@
-module gitea.d-ma.be/mathias/mcp-chassis
+module git.d-ma.be/mathias/mcp-chassis
 
 go 1.26.1