From 9cf211930d85cc8cfe03e811d3551834f59ed553 Mon Sep 17 00:00:00 2001 From: GatewayJ <835269233@qq.com> Date: Sun, 5 Jul 2026 18:05:23 +0800 Subject: [PATCH] fix(iam): expand OIDC auth diagnostics (#4281) * fix(iam): expand OIDC auth diagnostics * fix(iam): accept RFC3339 OIDC timestamps * chore(iam): log OIDC policy mapping diagnostics * chore(iam): log OIDC claim and policy details * chore(iam): lower OIDC diagnostic log verbosity * fix(iam): gate OIDC diagnostics behind debug * chore: update yanked num-bigint lockfile --- Cargo.lock | 4 +- Cargo.toml | 2 +- crates/iam/src/oidc.rs | 519 ++++++++++++++++++++++++++++-- rustfs/src/admin/handlers/oidc.rs | 69 +++- rustfs/src/admin/handlers/sts.rs | 119 ++++++- 5 files changed, 666 insertions(+), 47 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index e252ba92c..a79e95684 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -6493,9 +6493,9 @@ dependencies = [ [[package]] name = "num-bigint" -version = "0.4.7" +version = "0.4.8" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c863e9ab5e7bf9c99ba75e1050f1e4d624ae87ed3532d6238ffbdc7b585dbbe6" +checksum = "c89e69e7e0f03bea5ef08013795c25018e101932225a656383bd384495ecc367" dependencies = [ "num-integer", "num-traits", diff --git a/Cargo.toml b/Cargo.toml index e232aa894..5ed5eb839 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -193,7 +193,7 @@ chacha20poly1305 = { version = "=0.11.0" } crc-fast = "1.10.0" hmac = { version = "0.13.0" } jsonwebtoken = { version = "10.4.0", features = ["aws_lc_rs"] } -openidconnect = { version = "4.0", default-features = false } +openidconnect = { version = "4.0", default-features = false, features = ["accept-rfc3339-timestamps"] } pbkdf2 = "0.13.0" rsa = { version = "=0.10.0-rc.18" } rustls = { version = "0.23.41", default-features = false, features = ["aws-lc-rs", "logging", "tls12", "prefer-post-quantum", "std"] } diff --git a/crates/iam/src/oidc.rs b/crates/iam/src/oidc.rs index 08fe0183a..562f14d25 100644 --- a/crates/iam/src/oidc.rs +++ b/crates/iam/src/oidc.rs @@ -43,6 +43,10 @@ use tokio::time::sleep; use tracing::{debug, error, warn}; use url::Url; +const LOG_COMPONENT_IAM: &str = "iam"; +const LOG_SUBSYSTEM_OIDC: &str = "oidc"; +const EVENT_OIDC_DIAGNOSTICS: &str = "oidc_diagnostics"; +const EVENT_OIDC_HTTP: &str = "oidc_http"; const OIDC_JWKS_REFRESH_INTERVAL: StdDuration = StdDuration::from_secs(24 * 60 * 60); const OIDC_DISCOVERY_TRANSPORT_RETRIES: usize = 3; const OIDC_DISCOVERY_TRANSPORT_RETRY_DELAY: StdDuration = StdDuration::from_millis(50); @@ -168,6 +172,79 @@ pub fn oidc_plugin_authn_metrics_snapshot() -> OidcPluginAuthnMetricsSnapshot { OIDC_PLUGIN_AUTHN_METRICS.snapshot() } +fn format_http_headers(headers: &http::HeaderMap) -> String { + headers + .iter() + .map(|(name, value)| { + let value = value.to_str().unwrap_or(""); + format!("{}={}", name.as_str(), value) + }) + .collect::>() + .join("; ") +} + +fn format_http_body(body: &[u8]) -> String { + String::from_utf8_lossy(body).into_owned() +} + +#[derive(Debug, Default)] +struct TokenResponseBodyShape { + json_object: bool, + json_keys: String, + has_access_token: bool, + has_id_token: bool, + has_token_type: bool, + has_expires_in: bool, + has_error: bool, + has_error_description: bool, + looks_like_html: bool, +} + +fn inspect_token_response_body(body: &[u8]) -> TokenResponseBodyShape { + let mut shape = TokenResponseBodyShape { + looks_like_html: body + .iter() + .copied() + .find(|byte| !byte.is_ascii_whitespace()) + .is_some_and(|byte| byte == b'<'), + ..Default::default() + }; + + let Ok(value) = serde_json::from_slice::(body) else { + return shape; + }; + let Some(object) = value.as_object() else { + return shape; + }; + + shape.json_object = true; + shape.has_access_token = object.contains_key("access_token"); + shape.has_id_token = object.contains_key("id_token"); + shape.has_token_type = object.contains_key("token_type"); + shape.has_expires_in = object.contains_key("expires_in"); + shape.has_error = object.contains_key("error"); + shape.has_error_description = object.contains_key("error_description"); + + let mut keys: Vec<&str> = object.keys().map(String::as_str).collect(); + keys.sort_unstable(); + keys.truncate(16); + shape.json_keys = keys.join(","); + + shape +} + +fn oidc_http_error_diagnostics(error: &OidcHttpError) -> (&'static str, String) { + match error { + OidcHttpError::Reqwest(err) if err.is_timeout() => ("timeout", String::new()), + OidcHttpError::Reqwest(err) if err.is_connect() => ("connect", String::new()), + OidcHttpError::Reqwest(err) if err.status().is_some() => { + ("http_status", err.status().map(|status| status.as_u16().to_string()).unwrap_or_default()) + } + OidcHttpError::Reqwest(_) => ("request", String::new()), + OidcHttpError::Http(_) => ("http_build", String::new()), + } +} + // ---- HTTP Client Adapter ---- /// Error type for the OIDC HTTP client adapter. @@ -245,10 +322,28 @@ impl<'c> AsyncHttpClient<'c> for ReqwestHttpClient { Box::pin(async move { let started_at = Instant::now(); let (parts, body) = request.into_parts(); + let method = parts.method.clone(); let uri = parts.uri.to_string(); + if tracing::enabled!(tracing::Level::DEBUG) { + let request_headers = format_http_headers(&parts.headers); + let request_body = format_http_body(&body); + debug!( + event = EVENT_OIDC_HTTP, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "request", + method = %method, + uri = %uri, + request_headers = %request_headers, + request_body_len = body.len(), + request_body = %request_body, + "oidc outbound http" + ); + } + let client = self.client_for_uri(&uri); let response = client - .request(parts.method, uri) + .request(parts.method, uri.clone()) .headers(parts.headers) .body(body) .send() @@ -258,11 +353,57 @@ impl<'c> AsyncHttpClient<'c> for ReqwestHttpClient { let succeeded = response.as_ref().is_ok_and(|resp| resp.status().is_success()); OIDC_PLUGIN_AUTHN_METRICS.record(elapsed_ms, succeeded); - let response = response.map_err(OidcHttpError::Reqwest)?; + let response = response.map_err(|err| { + error!( + event = EVENT_OIDC_HTTP, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "request_failed", + method = %method, + uri = %uri, + elapsed_ms, + error = %err, + "oidc outbound http" + ); + OidcHttpError::Reqwest(err) + })?; let status = response.status(); let headers = response.headers().clone(); - let body_bytes = response.bytes().await.map_err(OidcHttpError::Reqwest)?; + let body_bytes = response.bytes().await.map_err(|err| { + error!( + event = EVENT_OIDC_HTTP, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "response_body_failed", + method = %method, + uri = %uri, + status = status.as_u16(), + elapsed_ms, + error = %err, + "oidc outbound http" + ); + OidcHttpError::Reqwest(err) + })?; + if tracing::enabled!(tracing::Level::DEBUG) { + let response_headers = format_http_headers(&headers); + let response_body = format_http_body(&body_bytes); + debug!( + event = EVENT_OIDC_HTTP, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "response", + method = %method, + uri = %uri, + status = status.as_u16(), + status_success = status.is_success(), + elapsed_ms, + response_headers = %response_headers, + response_body_len = body_bytes.len(), + response_body = %response_body, + "oidc outbound http" + ); + } let mut http_response = http::Response::builder() .status(status) @@ -429,7 +570,20 @@ impl OidcSys { configs.insert(config.id.clone(), config); } Err(e) => { - error!(provider = %config.id, error = %e, "OIDC provider discovery failed"); + error!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "provider_discovery_failed", + provider_id = %config.id, + config_url = %config.config_url, + client_id = %config.client_id, + scopes = ?config.scopes, + redirect_uri = %config.redirect_uri.as_deref().unwrap_or(""), + redirect_uri_dynamic = config.redirect_uri_dynamic, + error = %e, + "oidc provider discovery failed" + ); } } } @@ -551,6 +705,12 @@ impl OidcSys { .get(&session.provider_id) .ok_or_else(|| format!("unknown provider: {}", session.provider_id))?; let provider_state = self.get_provider_state(&session.provider_id)?; + let issuer = provider_state.metadata.issuer().to_string(); + let token_endpoint = provider_state + .metadata + .token_endpoint() + .map(ToString::to_string) + .unwrap_or_default(); // Construct CoreClient on-the-fly with JWKS from discovery let client = CoreClient::from_provider_metadata( @@ -565,41 +725,230 @@ impl OidcSys { // Exchange code for tokens let token_response = client .exchange_code(AuthorizationCode::new(code.to_string())) - .map_err(|e| format!("token endpoint not configured: {e}"))? + .map_err(|e| { + error!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "token_endpoint_missing", + provider_id = %session.provider_id, + config_url = %config.config_url, + issuer = %issuer, + client_id = %config.client_id, + redirect_uri = %redirect_uri, + scopes = ?config.scopes, + error = %e, + "oidc token exchange failed" + ); + format!( + "token endpoint not configured: {e}: provider_id={}, config_url={}, issuer={}, redirect_uri={}, client_id={}", + session.provider_id, config.config_url, issuer, redirect_uri, config.client_id + ) + })? .set_pkce_verifier(PkceCodeVerifier::new(session.pkce_verifier.clone())) .set_redirect_uri(Cow::Owned(redirect)) .request_async(&self.http_client) .await .map_err(|e| match &e { - RequestTokenError::Parse(parse_err, body) => format!( - "token exchange failed: {e}: parse_error_path={}, response_body_len={}", - parse_err.path(), - body.len() - ), - _ => format!("token exchange failed: {e}"), + RequestTokenError::ServerResponse(response) => { + error!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "token_server_response", + provider_id = %session.provider_id, + config_url = %config.config_url, + issuer = %issuer, + token_endpoint = %token_endpoint, + client_id = %config.client_id, + client_secret_configured = config.client_secret.as_deref().is_some_and(|secret| !secret.is_empty()), + redirect_uri = %redirect_uri, + scopes = ?config.scopes, + oauth_error = %response.error(), + oauth_error_description = %response.error_description().map(String::as_str).unwrap_or(""), + oauth_error_uri = %response.error_uri().map(String::as_str).unwrap_or(""), + error = %e, + "oidc token exchange failed" + ); + format!( + "token exchange failed: {e}: stage=token_server_response, provider_id={}, config_url={}, issuer={}, token_endpoint={}, redirect_uri={}, client_id={}, oauth_error={}, oauth_error_description={}", + session.provider_id, + config.config_url, + issuer, + token_endpoint, + redirect_uri, + config.client_id, + response.error(), + response.error_description().map(String::as_str).unwrap_or("") + ) + } + RequestTokenError::Request(err) => { + let (request_error_kind, request_error_status) = oidc_http_error_diagnostics(err); + error!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "token_request_failed", + provider_id = %session.provider_id, + config_url = %config.config_url, + issuer = %issuer, + token_endpoint = %token_endpoint, + client_id = %config.client_id, + redirect_uri = %redirect_uri, + request_error_kind = %request_error_kind, + request_error_status = %request_error_status, + error = %e, + "oidc token exchange failed" + ); + format!( + "token exchange failed: {e}: stage=token_request_failed, provider_id={}, config_url={}, issuer={}, token_endpoint={}, redirect_uri={}, client_id={}, request_error_kind={}, request_error_status={}", + session.provider_id, + config.config_url, + issuer, + token_endpoint, + redirect_uri, + config.client_id, + request_error_kind, + request_error_status + ) + } + RequestTokenError::Parse(parse_err, body) => { + let shape = inspect_token_response_body(body); + let response_body = format_http_body(body); + error!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "token_response_parse_failed", + provider_id = %session.provider_id, + config_url = %config.config_url, + issuer = %issuer, + token_endpoint = %token_endpoint, + client_id = %config.client_id, + redirect_uri = %redirect_uri, + parse_error_path = %parse_err.path(), + response_body_len = body.len(), + response_json_object = shape.json_object, + response_json_keys = %shape.json_keys, + response_has_access_token = shape.has_access_token, + response_has_id_token = shape.has_id_token, + response_has_token_type = shape.has_token_type, + response_has_expires_in = shape.has_expires_in, + response_has_error = shape.has_error, + response_has_error_description = shape.has_error_description, + response_looks_like_html = shape.looks_like_html, + response_body = %response_body, + error = %e, + "oidc token exchange failed" + ); + format!( + "token exchange failed: {e}: stage=token_response_parse_failed, provider_id={}, config_url={}, issuer={}, token_endpoint={}, redirect_uri={}, client_id={}, parse_error_path={}, response_body_len={}, response_json_keys={}, response_has_id_token={}, response_has_error={}, response_looks_like_html={}, response_body={}", + session.provider_id, + config.config_url, + issuer, + token_endpoint, + redirect_uri, + config.client_id, + parse_err.path(), + body.len(), + shape.json_keys, + shape.has_id_token, + shape.has_error, + shape.looks_like_html, + response_body + ) + } + RequestTokenError::Other(message) => { + error!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "token_exchange_other_error", + provider_id = %session.provider_id, + config_url = %config.config_url, + issuer = %issuer, + token_endpoint = %token_endpoint, + client_id = %config.client_id, + redirect_uri = %redirect_uri, + error = %message, + "oidc token exchange failed" + ); + format!( + "token exchange failed: {e}: stage=token_exchange_other_error, provider_id={}, config_url={}, issuer={}, token_endpoint={}, redirect_uri={}, client_id={}", + session.provider_id, config.config_url, issuer, token_endpoint, redirect_uri, config.client_id + ) + } })?; // Verify the ID token (signature, issuer, audience, expiry, nonce) let id_token = token_response .extra_fields() .id_token() - .ok_or_else(|| "no id_token in token response".to_string())?; + .ok_or_else(|| { + error!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "token_response_missing_id_token", + provider_id = %session.provider_id, + config_url = %config.config_url, + issuer = %issuer, + token_endpoint = %token_endpoint, + client_id = %config.client_id, + redirect_uri = %redirect_uri, + scopes = ?config.scopes, + "oidc token exchange failed" + ); + format!( + "no id_token in token response: provider_id={}, config_url={}, issuer={}, token_endpoint={}, redirect_uri={}, client_id={}, scopes={}", + session.provider_id, + config.config_url, + issuer, + token_endpoint, + redirect_uri, + config.client_id, + config.scopes.join(",") + ) + })?; let verifier = client .id_token_verifier() .set_other_audience_verifier_fn(|aud| trusted_aud(&config.other_audiences, aud)); let verified = id_token.claims(&verifier, &Nonce::new(session.nonce.clone())); if let Err(e) = verified { + let verification_error = e.to_string(); + warn!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "id_token_verification_retry", + provider_id = %session.provider_id, + config_url = %config.config_url, + issuer = %issuer, + token_endpoint = %token_endpoint, + client_id = %config.client_id, + other_audiences = ?config.other_audiences, + error = %verification_error, + "oidc id token verification failed" + ); let refreshed_state = self .refresh_provider_state(&session.provider_id, config) .await .map_err(|refresh_err| { - format!("ID token verification failed: {e}; failed to refresh provider metadata: {refresh_err}") + format!( + "ID token verification failed: {verification_error}; failed to refresh provider metadata: {refresh_err}" + ) })?; warn!( - "OIDC provider '{}' JWKS metadata refreshed and verification retried after failure", - session.provider_id + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "jwks_metadata_refreshed", + provider_id = %session.provider_id, + config_url = %config.config_url, + issuer = %issuer, + "oidc provider metadata refreshed" ); let client = CoreClient::from_provider_metadata( @@ -614,7 +963,32 @@ impl OidcSys { .set_other_audience_verifier_fn(|aud| trusted_aud(&config.other_audiences, aud)); id_token .claims(&verifier, &Nonce::new(session.nonce.clone())) - .map_err(|retry_err| format!("ID token verification failed after JWKS refresh: {retry_err}"))?; + .map_err(|retry_err| { + error!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "id_token_verification_failed", + provider_id = %session.provider_id, + config_url = %config.config_url, + issuer = %issuer, + token_endpoint = %token_endpoint, + client_id = %config.client_id, + other_audiences = ?config.other_audiences, + original_error = %verification_error, + retry_error = %retry_err, + "oidc id token verification failed" + ); + format!( + "ID token verification failed after JWKS refresh: {retry_err}; original_error={verification_error}; provider_id={}, config_url={}, issuer={}, token_endpoint={}, client_id={}, other_audiences={}", + session.provider_id, + config.config_url, + issuer, + token_endpoint, + config.client_id, + config.other_audiences.join(",") + ) + })?; } // Extract raw claims from the verified JWT for custom claim support @@ -739,6 +1113,47 @@ impl OidcSys { groups.sort(); groups.dedup(); + let mut raw_claim_keys: Vec<&str> = claims.raw.keys().map(String::as_str).collect(); + raw_claim_keys.sort_unstable(); + let (claim_name_lookup, claim_name_raw_value) = claim_lookup_for_log(&claims.raw, &config.claim_name); + let (groups_claim_lookup, groups_claim_raw_value) = claim_lookup_for_log(&claims.raw, &config.groups_claim); + let (roles_claim_lookup, roles_claim_raw_value) = claim_lookup_for_log(&claims.raw, &config.roles_claim); + let claim_name_values = extract_groups_claim(&claims.raw, &config.claim_name); + let groups_claim_values = extract_groups_claim(&claims.raw, &config.groups_claim); + let roles_claim_values = extract_groups_claim(&claims.raw, &config.roles_claim); + + debug!( + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "claims_policy_mapped", + provider_id = %provider_id, + claim_name = %config.claim_name, + claim_prefix = %config.claim_prefix, + groups_claim = %config.groups_claim, + roles_claim = %config.roles_claim, + role_policy = %config.role_policy, + policy_count = policies.len(), + group_count = groups.len(), + policies = ?policies, + groups = ?groups, + raw_claim_keys = ?raw_claim_keys, + raw_claims = ?claims.raw, + claim_name_lookup = %claim_name_lookup, + claim_name_type = claim_value_type_for_log(claim_name_raw_value), + claim_name_value = ?claim_name_raw_value, + claim_name_values = ?claim_name_values, + groups_claim_lookup = %groups_claim_lookup, + groups_claim_type = claim_value_type_for_log(groups_claim_raw_value), + groups_claim_value = ?groups_claim_raw_value, + groups_claim_values = ?groups_claim_values, + roles_claim_lookup = %roles_claim_lookup, + roles_claim_type = claim_value_type_for_log(roles_claim_raw_value), + roles_claim_value = ?roles_claim_raw_value, + roles_claim_values = ?roles_claim_values, + "oidc claims mapped to policies" + ); + (policies, groups) } @@ -1181,12 +1596,17 @@ impl OidcSys { let should_retry = is_transient_transport && attempt + 1 < OIDC_DISCOVERY_TRANSPORT_RETRIES; if should_retry { warn!( - "OIDC provider '{}' discovery transport attempt {}/{} failed for issuer '{}': {}", - config.id, - attempt + 1, - OIDC_DISCOVERY_TRANSPORT_RETRIES, - candidate_issuer, - error + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "provider_discovery_transport_retry", + provider_id = %config.id, + config_url = %config.config_url, + issuer_candidate = %candidate_issuer, + attempt = attempt + 1, + max_attempts = OIDC_DISCOVERY_TRANSPORT_RETRIES, + error = %error, + "oidc provider discovery failed" ); sleep(OIDC_DISCOVERY_TRANSPORT_RETRY_DELAY).await; continue; @@ -1194,8 +1614,17 @@ impl OidcSys { last_errors.push(format!("issuer '{candidate_issuer}': {error}")); warn!( - "OIDC provider '{}' discovery attempt failed for issuer '{}': {}", - config.id, candidate_issuer, error + event = EVENT_OIDC_DIAGNOSTICS, + component = LOG_COMPONENT_IAM, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "provider_discovery_candidate_failed", + provider_id = %config.id, + config_url = %config.config_url, + issuer_candidate = %candidate_issuer, + attempt = attempt + 1, + max_attempts = OIDC_DISCOVERY_TRANSPORT_RETRIES, + error = %error, + "oidc provider discovery failed" ); break; } @@ -1382,6 +1811,29 @@ fn extract_canonical_group_values( groups } +fn claim_lookup_for_log<'a>( + claims: &'a HashMap, + key: &str, +) -> (&'static str, Option<&'a serde_json::Value>) { + match get_claim_case_insensitive(claims, key) { + ClaimLookup::Found(value) => ("found", Some(value)), + ClaimLookup::Missing => ("missing", None), + ClaimLookup::Ambiguous => ("ambiguous", None), + } +} + +fn claim_value_type_for_log(value: Option<&serde_json::Value>) -> &'static str { + match value { + Some(serde_json::Value::Null) => "null", + Some(serde_json::Value::Bool(_)) => "bool", + Some(serde_json::Value::Number(_)) => "number", + Some(serde_json::Value::String(_)) => "string", + Some(serde_json::Value::Array(_)) => "array", + Some(serde_json::Value::Object(_)) => "object", + None => "none", + } +} + #[cfg(test)] mod tests { use super::*; @@ -1825,6 +2277,25 @@ mod tests { assert!(decode_jwt_payload("").is_empty()); } + #[test] + fn test_core_token_response_accepts_rfc3339_updated_at() { + // Signature verification happens later; this test covers token response deserialization. + let id_token = "eyJhbGciOiJSUzI1NiJ9.eyJpc3MiOiJodHRwczovL2F1dGguZXhhbXBsZS5jb20vb2lkYyIsInN1YiI6InVzZXItMSIsImF1ZCI6InJ1c3RmcyIsImV4cCI6MTc4NDQzMjc2OSwiaWF0IjoxNzgzMjIzMTY5LCJ1cGRhdGVkX2F0IjoiMjAyNi0wNy0wM1QwNDo1MDo1MC44MTFaIn0.c2ln"; + let body = serde_json::json!({ + "scope": "openid roles profile email", + "token_type": "Bearer", + "access_token": "access-token", + "expires_in": 1209600, + "id_token": id_token, + }) + .to_string(); + + let response: openidconnect::core::CoreTokenResponse = + serde_json::from_str(&body).expect("RFC3339 updated_at should parse in token response"); + + assert!(response.extra_fields().id_token().is_some()); + } + #[test] fn test_map_claims_to_policies_no_provider() { let sys = OidcSys::empty().expect("failed to initialize empty OIDC system"); diff --git a/rustfs/src/admin/handlers/oidc.rs b/rustfs/src/admin/handlers/oidc.rs index 98b91c0aa..146b8de72 100644 --- a/rustfs/src/admin/handlers/oidc.rs +++ b/rustfs/src/admin/handlers/oidc.rs @@ -38,7 +38,7 @@ use s3s::{Body, S3Error, S3ErrorCode, S3Request, S3Response, S3Result, s3_error} use serde::de::DeserializeOwned; use serde::{Deserialize, Serialize}; use time::OffsetDateTime; -use tracing::{error, info, warn}; +use tracing::{debug, error, warn}; use url::Url; const LOG_COMPONENT_ADMIN: &str = "admin"; @@ -448,17 +448,34 @@ impl Operation for OidcAuthorizeHandler { // Optional: redirect_after query parameter (must be a safe relative path) let redirect_after = extract_safe_redirect_after(&req.uri)?; + let redirect_after_log = redirect_after.clone(); let auth_url = oidc_sys .authorize_url(provider_id, &redirect_uri, redirect_after) .await - .map_err(|e| S3Error::with_message(S3ErrorCode::InvalidRequest, format!("authorize failed: {e}")))?; + .map_err(|e| { + error!( + event = EVENT_ADMIN_OIDC_STATE, + component = LOG_COMPONENT_ADMIN, + subsystem = LOG_SUBSYSTEM_OIDC, + result = "authorize_url_failed", + provider_id = %provider_id, + redirect_uri = %redirect_uri, + redirect_after = ?redirect_after_log, + error = %e, + "admin oidc state" + ); + S3Error::with_message(S3ErrorCode::InvalidRequest, format!("authorize failed: {e}")) + })?; - info!( + debug!( event = EVENT_ADMIN_OIDC_STATE, component = LOG_COMPONENT_ADMIN, subsystem = LOG_SUBSYSTEM_OIDC, provider_id = %provider_id, + redirect_uri = %redirect_uri, + redirect_after = ?redirect_after_log, + auth_url = %auth_url, state = "authorize_redirect", "admin oidc state" ); @@ -490,20 +507,14 @@ impl Operation for OidcCallbackHandler { return Err(s3_error!(InvalidRequest, "invalid provider_id")); } - // Extract code and state from query parameters - let code = - extract_query_param(&req.uri, "code").ok_or_else(|| s3_error!(InvalidRequest, "missing 'code' query parameter"))?; - let state = - extract_query_param(&req.uri, "state").ok_or_else(|| s3_error!(InvalidRequest, "missing 'state' query parameter"))?; - // Check for error response from IdP - if let Some(error) = extract_query_param(&req.uri, "error") { - let desc = extract_query_param(&req.uri, "error_description").unwrap_or_default(); + if let Some((error, desc)) = extract_idp_callback_error(&req.uri) { warn!( event = EVENT_ADMIN_OIDC_STATE, component = LOG_COMPONENT_ADMIN, subsystem = LOG_SUBSYSTEM_OIDC, result = "idp_callback_error", + provider_id = %provider_id, error_code = %error, error_description = %desc, "admin oidc state" @@ -514,6 +525,12 @@ impl Operation for OidcCallbackHandler { )); } + // Extract code and state from query parameters + let code = + extract_query_param(&req.uri, "code").ok_or_else(|| s3_error!(InvalidRequest, "missing 'code' query parameter"))?; + let state = + extract_query_param(&req.uri, "state").ok_or_else(|| s3_error!(InvalidRequest, "missing 'state' query parameter"))?; + let oidc_sys = current_oidc_handle().ok_or_else(|| s3_error!(InternalError, "OIDC not initialized"))?; let redirect_uri = derive_callback_uri(&req, provider_id)?; @@ -526,13 +543,19 @@ impl Operation for OidcCallbackHandler { component = LOG_COMPONENT_ADMIN, subsystem = LOG_SUBSYSTEM_OIDC, result = "code_exchange_failed", + requested_provider_id = %provider_id, + redirect_uri = %redirect_uri, + code = %code, + state = %state, + code_len = code.len(), + state_len = state.len(), error = %e, "admin oidc state" ); S3Error::with_message(S3ErrorCode::AccessDenied, format!("code exchange failed: {e}")) })?; - info!( + debug!( event = EVENT_ADMIN_OIDC_STATE, component = LOG_COMPONENT_ADMIN, subsystem = LOG_SUBSYSTEM_OIDC, @@ -544,13 +567,15 @@ impl Operation for OidcCallbackHandler { // Map claims to policies and groups let (policies, groups) = oidc_sys.map_claims_to_policies(&actual_provider_id, &claims); - info!( + debug!( event = EVENT_ADMIN_OIDC_STATE, component = LOG_COMPONENT_ADMIN, subsystem = LOG_SUBSYSTEM_OIDC, provider_id = %actual_provider_id, policy_count = policies.len(), group_count = groups.len(), + policies = ?policies, + groups = ?groups, state = "claims_mapped", "admin oidc state" ); @@ -674,6 +699,12 @@ fn extract_query_param(uri: &http::Uri, key: &str) -> Option { }) } +fn extract_idp_callback_error(uri: &http::Uri) -> Option<(String, String)> { + let error = extract_query_param(uri, "error")?; + let desc = extract_query_param(uri, "error_description").unwrap_or_default(); + Some((error, desc)) +} + fn extract_safe_redirect_after(uri: &http::Uri) -> S3Result> { let redirect_after = extract_query_param(uri, "redirect_after"); match redirect_after { @@ -1172,6 +1203,18 @@ mod tests { assert_eq!(extract_query_param(&uri, "redirect_after"), Some("/dashboard".to_string())); } + #[test] + fn test_extract_idp_callback_error_without_code() { + let uri: http::Uri = "http://localhost/callback?error=access_denied&error_description=Denied%20by%20IdP&state=xyz789" + .parse() + .expect("valid callback URI should parse"); + + let (error, desc) = extract_idp_callback_error(&uri).expect("IdP callback error should be detected"); + assert_eq!(error, "access_denied"); + assert_eq!(desc, "Denied by IdP"); + assert_eq!(extract_query_param(&uri, "code"), None); + } + #[test] fn test_parse_host_authority_rejects_userinfo() { assert!(parse_host_authority("evil.com@victim.com").is_err()); diff --git a/rustfs/src/admin/handlers/sts.rs b/rustfs/src/admin/handlers/sts.rs index e4bda352b..e0c94101e 100644 --- a/rustfs/src/admin/handlers/sts.rs +++ b/rustfs/src/admin/handlers/sts.rs @@ -46,7 +46,7 @@ use s3s::{ use serde::Deserialize; use serde_json::Value; use serde_urlencoded::from_bytes; -use std::collections::HashMap; +use std::collections::{BTreeMap, HashMap}; use time::{Duration, OffsetDateTime}; use tracing::{debug, error, info, warn}; @@ -131,6 +131,85 @@ fn resolve_oidc_session_identity(claims: &OidcClaims) -> String { } } +async fn log_oidc_policy_diagnostics( + iam_store: &rustfs_iam::sys::IamSys, + provider_id: &str, + parent_user: &str, + policies: &[String], + groups: &[String], +) { + if policies.is_empty() { + let policy_documents = BTreeMap::::new(); + let missing_policies = Vec::::new(); + let combined_policy = Value::Null; + debug!( + provider_id = %provider_id, + parent_user = %parent_user, + policy_count = 0, + group_count = groups.len(), + policies = ?policies, + groups = ?groups, + policy_documents = ?policy_documents, + missing_policies = ?missing_policies, + combined_policy = ?combined_policy, + "OIDC STS policy diagnostics" + ); + return; + } + + match iam_store.list_policy_docs("").await { + Ok(policy_docs) => { + let mut policy_documents = BTreeMap::new(); + let mut missing_policies = Vec::new(); + for policy_name in policies { + match policy_docs.get(policy_name) { + Some(policy_doc) => { + let policy_doc_json = serde_json::to_value(policy_doc).unwrap_or_else(|err| { + serde_json::json!({ + "serialization_error": err.to_string(), + }) + }); + policy_documents.insert(policy_name.clone(), policy_doc_json); + } + None => missing_policies.push(policy_name.clone()), + } + } + + let combined_policy = iam_store.get_combined_policy(policies).await; + let combined_policy_json = serde_json::to_value(&combined_policy).unwrap_or_else(|err| { + serde_json::json!({ + "serialization_error": err.to_string(), + }) + }); + + debug!( + provider_id = %provider_id, + parent_user = %parent_user, + policy_count = policies.len(), + group_count = groups.len(), + policies = ?policies, + groups = ?groups, + missing_policies = ?missing_policies, + policy_documents = ?policy_documents, + combined_policy = ?combined_policy_json, + "OIDC STS policy diagnostics" + ); + } + Err(err) => { + warn!( + provider_id = %provider_id, + parent_user = %parent_user, + policy_count = policies.len(), + group_count = groups.len(), + policies = ?policies, + groups = ?groups, + error = %err, + "OIDC STS policy diagnostics failed" + ); + } + } +} + pub fn register_admin_auth_route(r: &mut S3Router) -> std::io::Result<()> { r.insert(Method::POST, "/", AdminOperation(&AssumeRoleHandle {}))?; @@ -347,12 +426,25 @@ async fn handle_assume_role_with_web_identity(body: AssumeRoleRequest) -> S3Resu let (policies, groups) = oidc_sys.map_claims_to_policies(&provider_id, &claims); if !has_identity_authorization_context(&policies, &groups) { + warn!( + provider_id = %provider_id, + username = %claims.username, + sub = %claims.sub, + policy_count = policies.len(), + group_count = groups.len(), + "AssumeRoleWithWebIdentity has no mapped policies or groups" + ); return Err(s3_error!(InvalidArgument, "no policies are available for this OIDC token")); } - info!( - "AssumeRoleWithWebIdentity: user='{}', provider='{}', policies={:?}, groups={:?}", - claims.username, provider_id, policies, groups + debug!( + provider_id = %provider_id, + username = %claims.username, + policy_count = policies.len(), + group_count = groups.len(), + policies = ?policies, + groups = ?groups, + "AssumeRoleWithWebIdentity mapped OIDC policies and groups" ); let mut duration = if body.duration_seconds > 0 { @@ -429,9 +521,19 @@ pub async fn create_oidc_sts_credentials( // Set the parent user: prefer username, then email, then sub let parent_user = resolve_oidc_session_identity(claims); - info!( - "OIDC STS credential: parent_user='{}' (email='{}', username='{}', sub='{}')", - parent_user, claims.email, claims.username, claims.sub + debug!( + provider_id = %provider_id, + parent_user = %parent_user, + email = %claims.email, + username = %claims.username, + sub = %claims.sub, + policy_count = policies.len(), + group_count = groups.len(), + policies = ?policies, + groups = ?groups, + roles_claim_key = ?roles_claim_key, + has_session_policy = session_policy.is_some(), + "OIDC STS credential claims prepared" ); token_claims.insert("parent".to_string(), Value::String(parent_user.clone())); @@ -457,6 +559,9 @@ pub async fn create_oidc_sts_credentials( // Store temp user in IAM let iam_store = crate::admin::runtime_sources::current_ready_iam_handle().map_err(|_| s3_error!(InternalError, "IAM not initialized"))?; + if tracing::enabled!(tracing::Level::DEBUG) { + log_oidc_policy_diagnostics(&iam_store, provider_id, &new_cred.parent_user, policies, groups).await; + } let updated_at = iam_store .set_temp_user(&new_cred.access_key, &new_cred, None)