From 6257a2b0558205c9e018f4e7398137eac7612389 Mon Sep 17 00:00:00 2001 From: fylorn <249551762+fylorn@users.noreply.github.com> Date: Tue, 20 Oct 2026 22:37:38 +0800 Subject: [PATCH] fix(auth): answer database failures in auth middleware with a 503, not an empty 500 The parallel-install integration test failed now and then with an empty 500. The cause was not the install transaction: the test harness ground each login's proof of work inline on the current-thread runtime that also drives the in-process server. A slow grind froze an install already in flight, its connection-pool acquire outlived the 5 s acquire timeout (with idle connections in the pool), and the session check in require_auth mapped the error to a bare 500 without logging it. - auth_guard / api_key_auth: database errors in the session and API-key checks go through the same mapping as handlers (pool timeout -> 503 with a JSON body, other errors -> 500 with one) and are logged with the lookup that failed. - test-support: grind the proof of work on the blocking pool so the server keeps running while a client logs in. - mcp_store_concurrency: log every session in before firing the installs, so they actually race each other. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 11 +++ crates/server/src/middleware/api_key_auth.rs | 25 +++-- crates/server/src/middleware/auth_guard.rs | 99 +++++++++++++++---- crates/test-support/src/client.rs | 55 ++++++----- .../tests/mcp_store_concurrency.rs | 17 ++-- 5 files changed, 151 insertions(+), 56 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 8f8b8dc8..ada2f09f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -29,6 +29,17 @@ target. rules cannot be read, the link is built without limits as before. A new key has no limits of its own yet, so its link carries none. +### Fixed + +- **A database outage during authentication is a 503 with an error body, + not an empty 500.** When the session or API-key check could not reach + Postgres (most often a connection-pool timeout), the console and the + gateway answered `500 Internal Server Error` with no body and, for the + permission lookup, no log line. These lookups now answer like every + handler does: `503 Service Unavailable` with the usual JSON error when + the database is unavailable, `500` with it for any other database + error, and an error log naming the lookup that failed. + ## [3.8.3] — 2026-10-20 Tool-call inspection in streamed answers now decides only on arguments diff --git a/crates/server/src/middleware/api_key_auth.rs b/crates/server/src/middleware/api_key_auth.rs index 1016bba0..802e55c1 100644 --- a/crates/server/src/middleware/api_key_auth.rs +++ b/crates/server/src/middleware/api_key_auth.rs @@ -365,9 +365,16 @@ fn authenticate( .bind(&key_hash) .bind(global_inactivity_days) .fetch_optional(&state.db) - .await - .map_err(|_| StatusCode::INTERNAL_SERVER_ERROR)? - .ok_or(StatusCode::UNAUTHORIZED)?; + .await; + let row = match row { + Ok(row) => row.ok_or(StatusCode::UNAUTHORIZED)?, + Err(e) => { + return Ok(super::auth_guard::db_failure_response( + "Gateway API key lookup failed", + e, + )); + } + }; // Surface gate. Even a valid key gets rejected if its // `surfaces` list doesn't include the gateway being called. @@ -433,9 +440,15 @@ fn authenticate( // the aggregated `surface_constraints` JSON so the gateway // hot path has rate limits + budgets without further lookups. let (role_limits, user_roles, loaded_limits) = if let Some(uid) = row.user_id { - let limits = rbac::compute_user_resource_limits(&state.db, uid) - .await - .map_err(|_| StatusCode::INTERNAL_SERVER_ERROR)?; + let limits = match rbac::compute_user_resource_limits(&state.db, uid).await { + Ok(limits) => limits, + Err(e) => { + return Ok(super::auth_guard::db_failure_response( + "Loading the key owner's resource limits failed", + e, + )); + } + }; let names = rbac::load_user_role_names(&state.db, uid) .await .unwrap_or_default(); diff --git a/crates/server/src/middleware/auth_guard.rs b/crates/server/src/middleware/auth_guard.rs index c717c3b6..8d39340b 100644 --- a/crates/server/src/middleware/auth_guard.rs +++ b/crates/server/src/middleware/auth_guard.rs @@ -737,7 +737,7 @@ async fn forwarded_ip( async fn load_user_permissions_cached( state: &AppState, user_id: uuid::Uuid, -) -> Result<(Vec, Vec), anyhow::Error> { +) -> Result<(Vec, Vec), sqlx::Error> { use fred::interfaces::KeysInterface; let cache_key = format!("user_perms:{user_id}"); @@ -831,6 +831,15 @@ pub async fn invalidate_team_perms( } } +/// The response for a database failure inside an auth middleware: the +/// same mapping handlers use (`From for AppError`), so a +/// pool timeout is a 503 with a JSON body instead of a bare, empty 500. +/// `context` names the lookup that failed in the log line. +pub(crate) fn db_failure_response(context: &str, err: sqlx::Error) -> Response { + tracing::error!(error = %err, "{context}"); + AppError::from(err).into_response() +} + pub async fn require_auth( State(state): State, mut request: Request, @@ -931,16 +940,21 @@ pub async fn require_auth( // // The same lookup reads `totp_enabled` for the TOTP-requirement // gate further down, so enforcing it costs no extra query. - let user_row: Option<(bool, bool)> = sqlx::query_as( + let user_row: Option<(bool, bool)> = match sqlx::query_as( "SELECT is_active, totp_enabled FROM users WHERE id = $1 AND deleted_at IS NULL", ) .bind(claims.sub) .fetch_optional(&state.db) .await - .map_err(|e| { - tracing::error!(error = %e, "DB check for users.is_active failed"); - StatusCode::INTERNAL_SERVER_ERROR - })?; + { + Ok(row) => row, + Err(e) => { + return Ok(db_failure_response( + "DB check for users.is_active failed", + e, + )); + } + }; let Some((true, totp_enabled)) = user_row else { return Err(StatusCode::UNAUTHORIZED); }; @@ -959,9 +973,11 @@ pub async fn require_auth( .filter(|s| !s.is_empty()); // Load permissions from Redis cache (60s TTL) → DB fallback. - let (permissions, denied_permissions) = load_user_permissions_cached(&state, claims.sub) - .await - .map_err(|_| StatusCode::INTERNAL_SERVER_ERROR)?; + let (permissions, denied_permissions) = + match load_user_permissions_cached(&state, claims.sub).await { + Ok(loaded) => loaded, + Err(e) => return Ok(db_failure_response("Loading user permissions failed", e)), + }; if let Some(slot) = request .extensions() @@ -1066,9 +1082,11 @@ async fn auth_via_api_key( .bind(&key_hash) .bind(global_inactivity_days) .fetch_optional(&state.db) - .await - .map_err(|_| StatusCode::INTERNAL_SERVER_ERROR)? - .ok_or(StatusCode::UNAUTHORIZED)?; + .await; + let row = match row { + Ok(row) => row.ok_or(StatusCode::UNAUTHORIZED)?, + Err(e) => return Ok(db_failure_response("Console API key lookup failed", e)), + }; if !row.surfaces.iter().any(|s| s == "console") { return Err(StatusCode::FORBIDDEN); @@ -1104,21 +1122,32 @@ async fn auth_via_api_key( // Load current permissions from DB (not a snapshot like JWT claims). // This means permission changes take effect immediately for API key users. let all_perm_keys = crate::handlers::roles::all_permission_keys(); - let permissions = rbac::compute_user_permissions(&state.db, user_id, &all_perm_keys) - .await - .map_err(|_| StatusCode::INTERNAL_SERVER_ERROR)?; - let denied_permissions = rbac::compute_denied_permissions(&state.db, user_id, &permissions) - .await - .map_err(|_| StatusCode::INTERNAL_SERVER_ERROR)?; + let permissions = match rbac::compute_user_permissions(&state.db, user_id, &all_perm_keys).await + { + Ok(permissions) => permissions, + Err(e) => return Ok(db_failure_response("Loading user permissions failed", e)), + }; + let denied_permissions = + match rbac::compute_denied_permissions(&state.db, user_id, &permissions).await { + Ok(denied) => denied, + Err(e) => return Ok(db_failure_response("Loading user permissions failed", e)), + }; - let email = sqlx::query_scalar::<_, String>( + let email = match sqlx::query_scalar::<_, String>( "SELECT email FROM users WHERE id = $1 AND is_active = true AND deleted_at IS NULL", ) .bind(user_id) .fetch_optional(&state.db) .await - .map_err(|_| StatusCode::INTERNAL_SERVER_ERROR)? - .ok_or(StatusCode::UNAUTHORIZED)?; + { + Ok(email) => email.ok_or(StatusCode::UNAUTHORIZED)?, + Err(e) => { + return Ok(db_failure_response( + "Console API key owner lookup failed", + e, + )); + } + }; // Best-effort last_used_at update (same pattern as gateway path). let db = state.db.clone(); @@ -1233,3 +1262,31 @@ mod proxy_trust_tests { )); } } + +#[cfg(test)] +mod db_failure_tests { + use super::*; + + async fn status_and_body(err: sqlx::Error) -> (StatusCode, serde_json::Value) { + let resp = db_failure_response("lookup", err); + let status = resp.status(); + let bytes = axum::body::to_bytes(resp.into_body(), usize::MAX) + .await + .unwrap(); + (status, serde_json::from_slice(&bytes).unwrap()) + } + + #[tokio::test] + async fn a_pool_timeout_is_a_503_with_an_error_body() { + let (status, body) = status_and_body(sqlx::Error::PoolTimedOut).await; + assert_eq!(status, StatusCode::SERVICE_UNAVAILABLE); + assert_eq!(body["error"]["type"], "service_unavailable"); + } + + #[tokio::test] + async fn any_other_database_error_is_a_500_with_an_error_body() { + let (status, body) = status_and_body(sqlx::Error::RowNotFound).await; + assert_eq!(status, StatusCode::INTERNAL_SERVER_ERROR); + assert!(body["error"]["message"].is_string()); + } +} diff --git a/crates/test-support/src/client.rs b/crates/test-support/src/client.rs index 6a96c4d2..932042f9 100644 --- a/crates/test-support/src/client.rs +++ b/crates/test-support/src/client.rs @@ -199,7 +199,8 @@ impl TestClient { .to_owned(); let challenge_random = challenge["challenge_random"] .as_str() - .context("challenge_random missing")?; + .context("challenge_random missing")? + .to_owned(); let difficulty = challenge["difficulty"] .as_u64() .and_then(|n| u8::try_from(n).ok()) @@ -223,28 +224,38 @@ impl TestClient { "PoW difficulty {difficulty} is too high to grind in a test" ); let limit = 32u64 << difficulty; - let mut nonce: u64 = 0; - loop { - let nonce_str = nonce.to_string(); - if think_watch_auth::pow::verify_pow( - challenge_random, - &bound_email, - &nonce_str, - difficulty, - ) { - return Ok(serde_json::json!({ - "challenge_id": challenge_id, - "nonce": nonce_str, - })); - } - nonce += 1; - if nonce > limit { - anyhow::bail!( - "PoW grinder found no nonce in {limit} tries at difficulty {difficulty}; \ - the server and `verify_pow` disagree" - ); + // Grind on the blocking pool. Tests run on a current-thread + // runtime that also drives the in-process server; grinding + // inline (half a second on average, several seconds in the + // tail on a busy runner) froze every request in flight, long + // enough for their database pool acquires to time out. + let nonce_str = tokio::task::spawn_blocking(move || { + let mut nonce: u64 = 0; + loop { + let nonce_str = nonce.to_string(); + if think_watch_auth::pow::verify_pow( + &challenge_random, + &bound_email, + &nonce_str, + difficulty, + ) { + return Ok(nonce_str); + } + nonce += 1; + if nonce > limit { + anyhow::bail!( + "PoW grinder found no nonce in {limit} tries at difficulty {difficulty}; \ + the server and `verify_pow` disagree" + ); + } } - } + }) + .await + .context("PoW grinder task")??; + Ok(serde_json::json!({ + "challenge_id": challenge_id, + "nonce": nonce_str, + })) } pub async fn post_empty(&self, path: &str) -> Result { diff --git a/crates/test-support/tests/mcp_store_concurrency.rs b/crates/test-support/tests/mcp_store_concurrency.rs index 917fcc2a..a5c7e63f 100644 --- a/crates/test-support/tests/mcp_store_concurrency.rs +++ b/crates/test-support/tests/mcp_store_concurrency.rs @@ -55,15 +55,18 @@ async fn parallel_installs_same_template_keep_count_in_sync() { seed_template(&app.db, &slug_owned, "GitHub IT").await; const N: usize = 5; - let mut handles = Vec::with_capacity(N); + // Each parallel install runs in its own admin session (independent + // cookie jar). That's the closest test-harness analogue to N + // browser tabs hitting the public endpoint at once. Log every + // session in before firing any install, so the N installs race + // each other rather than trickling out one login apart. + let mut sessions = Vec::with_capacity(N); for _ in 0..N { - let app_ref = &app; + sessions.push(admin_session(&app).await); + } + let mut handles = Vec::with_capacity(N); + for con in sessions { let slug = slug_owned.clone(); - // Each parallel install runs in its own admin session - // (independent cookie jar) — same admin user, different - // logins. That's the closest test-harness analogue to N - // browser tabs hitting the public endpoint at once. - let con = admin_session(app_ref).await; handles.push(tokio::spawn(async move { con.post( "/api/mcp/servers",