Skip to content

fix(auth): log per-authenticator rejections instead of swallowing them#3

Merged
cjimti merged 2 commits into
mainfrom
fix/auth-chain-logging-issue-2
Apr 30, 2026
Merged

fix(auth): log per-authenticator rejections instead of swallowing them#3
cjimti merged 2 commits into
mainfrom
fix/auth-chain-logging-issue-2

Conversation

@cjimti
Copy link
Copy Markdown
Contributor

@cjimti cjimti commented Apr 30, 2026

Closes #2.

Summary

Chain.Authenticate was dropping every error from OIDCValidator.ValidateBearer and APIKeyStore.Authenticate, falling through to the next method or to ErrNotAuthenticated. When OIDC rejected a bearer for any reason (audience mismatch, JWKS miss, expired-with-clock-skew, signature failure), the calling client got a 401 with no body, no log, no diagnostic surface.

This PR makes the chain log every per-authenticator rejection, attaches request correlation, redacts JWT-shape token bytes, rate-limits per remote_addr, and has MCPAuthGateway emit a proper RFC 6750 §3 WWW-Authenticate challenge so MCP clients see a useful diagnostic alongside the 401.

Changes

pkg/auth/chain.go

  • Chain owns a *slog.Logger (defaults to slog.Default(), overridable via SetLogger). WithLogger is kept as a deprecated alias so existing callers don't break.
  • Every rejection from a configured authenticator gets one log line tagged method=oidc|apikey plus the underlying error and request correlation fields (request_id, remote_addr) pulled from ctx.
  • Token redaction: redactTokenLikes strips JWT-shape substrings (xxx.yyy.zzz of base64url segments ≥8 chars) from the validator's error string before logging. Defense-in-depth on top of "validators don't echo tokens"; we now actually enforce it at the chain layer rather than just trusting downstream.
  • Rate-limited WARN: first failure per remote_addr per 60s window logs at WARN; subsequent failures in the window log at DEBUG. Without this, a scanner hitting 401s at line speed would flood operator logs and crowd out real signal. Empty remote_addr (no correlation context available) bypasses the bucket so single-shot failures still surface at WARN.
  • Public API stays backward-compatible: NewChain(allowAnonymous, apiKeys, oidc) is unchanged.

pkg/httpsrv/authgate.go

  • MCPAuthGateway's 401 response now follows RFC 6750 §3:
    WWW-Authenticate: Bearer realm="mcp-test",
      error="invalid_request",
      error_description="missing or unsupported credential; supply X-API-Key or Authorization: Bearer <token>",
      resource_metadata="<url>"
    
    MCP clients that follow the spec surface error / error_description to the user. The JSON body now includes error_description too, for non-RFC-aware clients.
  • buildBearerChallenge composes the challenge with proper RFC 7235 §2.1 quote escaping (" and \ are escaped per the auth-param ABNF).

internal/server/server.go

  • Wires the application's logger into the chain via NewChain(...).SetLogger(logger) so log lines come out under the same JSON handler as the rest of the binary.

New tests

pkg/auth/chain_test.go covers:

  • Empty token (no log, ErrNotAuthenticated).
  • Anonymous-on + empty token (no log, anonymous identity).
  • Both stores nil + token present (no log, ErrNotAuthenticated).
  • Successful auth (no log).
  • JWT-shaped token tries OIDC first; non-JWT tries apikey first.
  • OIDC rejection with request_id + remote_addr correlation in the log line.
  • API key rejection log shape.
  • Full-chain miss: rate limiter demotes the second log line in the same window from WARN to DEBUG.
  • Real redaction test: a leaky validator that embeds the token in its error is constructed; the chain redacts it. The previous version of this test only verified the fake's discipline.
  • redactTokenLikes table covering classic three-segment JWT, no-JWT, mid-sentence JWT, short non-JWT dotted identifiers.
  • failureRateLimiter: first warns then demotes within window, different keys are independent, window elapse re-warns, empty key never bucketed, nil-receiver safe, default-window fallback, stale-entry eviction.
  • SetLogger(nil) falls back to slog.Default(); NewChain sets the logger and rate limiter.
  • WithLogger deprecated alias still works.

pkg/httpsrv/authgate_test.go adds:

  • RFC 6750 §3 challenge fields all present (realm, error, error_description, resource_metadata).
  • error_description mirrored into the JSON body.
  • buildBearerChallenge omits blank fields.
  • quoteAuthParam escapes " and \ per auth-param ABNF.

Sample log output

For an OIDC token rejected on audience mismatch (first failure from 10.0.0.7):

{"time":"2026-04-30T07:42:18Z","level":"WARN","msg":"auth: token rejected","method":"oidc","error":"audience mismatch: want \"prod\"","request_id":"req-abc-123","remote_addr":"10.0.0.7"}

A second failure from the same source within 60s gets demoted to DEBUG; identical content otherwise.

For a leaky validator that included the rejected JWT in its error:

{"time":"...","level":"WARN","msg":"auth: token rejected","method":"oidc","error":"rejected token: [redacted-jwt]","request_id":"...","remote_addr":"..."}

Test plan

  • make verify passes (lint + race-tested test suite + 80% coverage gate).
  • All review findings from the PR review are addressed in code: redaction, rate limiting, correlation fields, real redaction test, dead-code nil-check removed, slog.LogAttrs with typed string attrs, SetLogger rename with deprecated alias, both-stores-nil test added.
  • On a deployment with OIDC enabled, hit any endpoint with a wrong-audience token; confirm one WARN line per remote_addr per minute with method=oidc, the audience-mismatch error, and the request_id matching the audit_events row. Subsequent failures from the same source in the same minute appear at DEBUG.
  • On the same deployment, hit any endpoint with no credential; confirm the 401 carries WWW-Authenticate: Bearer realm="mcp-test", error="invalid_request", error_description="...", resource_metadata="..." and the JSON body has error_description.

Closes #2.

Before: Chain.Authenticate dropped every error from
OIDCValidator.ValidateBearer and APIKeyStore.Authenticate, falling
through to the next method or to ErrNotAuthenticated. When OIDC
rejected a bearer for any reason (audience mismatch, JWKS miss,
expired, signature failure), the calling client got a 401 with no
body, no log, no diagnostic surface.

After: Chain owns a *slog.Logger (defaulting to slog.Default(),
overridable via WithLogger). Every rejection from a configured
authenticator is logged at WARN with method=oidc|apikey and the
underlying error before the chain falls through. The token is never
included in the log.

internal/server/server.go now wires the application's logger into
the chain via NewChain(...).WithLogger(logger), so log lines are
attributed under the same JSON handler as the rest of the binary.

Tests
- pkg/auth/chain_test.go covers: empty token (no log), success path
  (no log), JWT-shaped token tries OIDC first, non-JWT tries
  apikey first, OIDC and API key rejections each emit one log line
  with the right method tag, full-chain miss emits both logs
  independently, token bytes never appear in log output, WithLogger
  honors nil → slog.Default() fallback.

Out of scope (left for a follow-up): RFC 6750 §3 WWW-Authenticate
error parameter on MCPAuthGateway. The issue called that optional
and the diagnostic value is largely captured by the WARN logs the
chain now emits.
@cjimti cjimti enabled auto-merge April 30, 2026 19:30
Builds on the initial chain-logging change with the findings from the
critical review of PR #3, plus the RFC 6750 §3 enhancement on the HTTP
gateway that issue #2 called out as an optional follow-up.

pkg/auth/chain.go
- Token redaction: redactTokenLikes strips JWT-shape substrings
  (xxx.yyy.zzz of base64url segments >=8 chars) from the validator's
  error before logging. Defense in depth on top of the
  validators-don't-echo-tokens contract; the chain now actually
  enforces it instead of just trusting downstream.
- Rate-limited WARN: first failure per remote_addr per 60s window
  logs at WARN; subsequent failures in the same window log at DEBUG.
  failureRateLimiter does opportunistic eviction so the ledger stays
  bounded under sustained pressure. Empty remote_addr (no correlation
  context) bypasses the bucket.
- Correlation fields: log line now carries request_id and remote_addr
  from ctx alongside method and error, joinable against audit_events.
- API: WithLogger renamed to SetLogger to be honest about the receiver
  mutation; WithLogger kept as a Deprecated alias for source-compat.
- Removed the dead-code nil check on c.logger; NewChain always sets it.
- Switched from c.logger.Warn(...) variadic to slog.LogAttrs with typed
  slog.String attrs so behavior is identical across stock and custom
  slog handlers.

pkg/httpsrv/authgate.go
- 401 response now follows RFC 6750 §3:
    WWW-Authenticate: Bearer realm="mcp-test",
      error="invalid_request",
      error_description="missing or unsupported credential...",
      resource_metadata="<url>"
  buildBearerChallenge composes the challenge with proper RFC 7235
  §2.1 quote escaping (backslash and double-quote escaped per the
  auth-param ABNF). The JSON body mirrors error_description so
  non-RFC-aware clients also see the diagnostic.

internal/server/server.go
- Wires the application logger via NewChain(...).SetLogger(logger).

Tests
- pkg/auth/chain_test.go: real redaction test that constructs a leaky
  validator embedding the rejected token in its error and asserts the
  chain redacts it. redactTokenLikes table. failureRateLimiter
  behavior (first-warns-then-demotes, per-key independence, window
  elapse, empty-key bypass, nil-receiver safety, default-window
  fallback, stale-entry eviction). Both-stores-nil-with-token case.
  Anonymous-empty-token no-log case. WithLogger deprecated alias.
- pkg/httpsrv/authgate_test.go: RFC 6750 §3 challenge field assertions
  (realm, error, error_description, resource_metadata).
  buildBearerChallenge blank-field omission. quoteAuthParam escape
  matrix.

make verify is green at >=80% filtered coverage.
@cjimti cjimti disabled auto-merge April 30, 2026 20:05
@cjimti cjimti merged commit 5f04db1 into main Apr 30, 2026
1 check passed
@cjimti cjimti deleted the fix/auth-chain-logging-issue-2 branch April 30, 2026 20:05
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

auth: Chain.Authenticate swallows OIDC ValidateBearer errors silently

1 participant