fix(dpop): log the nonce-bootstrap challenge instead of returning a bare 401
The `None` arm of the nonce match returns a challenge — the client sent
a valid proof but carried no nonce, so it gets 401 + `DPoP-Nonce` and
retries. It was the only one of the three challenge paths that logged
nothing.
The result was an unexplainable line in the access log:
WARN http::api: client_error status=401 latency_ms=0 …
with no audit line saying why, and no sign of the successful retry —
`main.rs` defaults the access log to `http=warn`, so the 200 that
follows is never printed. It came up as "any clue why I have 401?" while
reading an e2e run, which is the cost of a silent rejection.
AGENTS.md is explicit that every rejection emits a structured audit line
before returning the error; this path simply missed it.
The line pays off immediately: it names `htu`, and the first run with it
showed the caller was `GET /api/admin/plugins/{id}/logs/stream` — the
admin log tail, an `EventSource`, whose proof is minted by the service
worker rather than by `apiFetch`. `service-worker.ts` documents exactly
this: the nonce cache is per-scope, so the page module and the SW EACH
pay one round-trip challenge and then catch up from `DPoP-Nonce`
response headers. The SW absorbs the 401 and retries, so `EventSource`
never sees it. Hence "once per client SCOPE" rather than per session —
and again whenever the browser terminates and restarts the worker, which
is normal and is why one run shows several.
Deliberately NOT `dpop.verify_failed`. The proof verified cleanly —
nothing failed — and folding a routine bootstrap into the event
operators watch for attacks would bury real signal. `nonce_stale` above
keeps that event name because it is long-standing and aggregators key
off it; this path is new, so it gets the accurate one:
`dpop.nonce_challenged` / `reason = "nonce_missing"`. No new counter —
`nonce_challenge_response` already counts every challenge centrally, so
adding one here would double-count.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
@@ -237,6 +237,34 @@ pub async fn require_dpop_layer(
|
||||
// window at the verifier means this one still
|
||||
// succeeded, but we still want the client onto
|
||||
// the nonce path immediately.
|
||||
//
|
||||
// Logged because this returns a 401, and every
|
||||
// rejection owes the operator a line saying why —
|
||||
// otherwise the access log shows a bare
|
||||
// `client_error status=401` with nothing to
|
||||
// explain it, while the client's successful retry
|
||||
// stays invisible under the default `http=warn`
|
||||
// access-log filter. That combination reads like a
|
||||
// real auth failure and is not one.
|
||||
//
|
||||
// NOT `dpop.verify_failed`: the proof verified
|
||||
// cleanly, and counting a routine bootstrap as a
|
||||
// verification failure would put a per-session
|
||||
// event into the metric operators watch for
|
||||
// attacks. `nonce_stale` above keeps that event
|
||||
// name — it is long-standing and log aggregators
|
||||
// key off it — but this path is new, so it gets
|
||||
// the accurate one. The challenge itself is
|
||||
// already counted centrally by
|
||||
// `nonce_challenge_response`.
|
||||
tracing::info!(
|
||||
target: "audit",
|
||||
event = "dpop.nonce_challenged",
|
||||
reason = "nonce_missing",
|
||||
method = %method,
|
||||
htu = %htu,
|
||||
"👮🏻♂️ DPoP proof carried no nonce — issuing challenge (expected once per client scope; the client harvests the nonce and retries)",
|
||||
);
|
||||
return nonce_challenge_response(&nonce_service);
|
||||
}
|
||||
Some(n) => n,
|
||||
|
||||
Reference in New Issue
Block a user