feat: add auth login diagnostics (#13797)
## Problem Browser login failures historically leave support with an incomplete picture. HARs can show that the browser completed OAuth and reached the localhost callback, but they do not explain why the native client failed on the final `/oauth/token` exchange. Direct `codex login` also relied mostly on terminal stderr and the browser error page, so even when the login crate emitted better sign-in diagnostics through TUI or app-server flows, the one-shot CLI path still did not leave behind an easy artifact to collect. ## Mental model This implementation treats the browser page, the returned `io::Error`, and the normal structured log as separate surfaces with different safety requirements. The browser page and returned error preserve the detail that operators need to diagnose failures. The structured log stays narrower: it records reviewed lifecycle events, parsed safe fields, and redacted transport errors without becoming a sink for secrets or arbitrary backend bodies. Direct `codex login` now adds a fourth support surface: a small file-backed log at `codex-login.log` under the configured `log_dir`. That artifact carries the same login-target events as the other entrypoints without changing the existing stderr/browser UX. ## Non-goals This does not add auth logging to normal runtime requests, and it does not try to infer precise transport root causes from brittle string matching. The scope remains the browser-login callback flow in the `login` crate plus a direct-CLI wrapper that persists those events to disk. This also does not try to reuse the TUI logging stack wholesale. The TUI path initializes feedback, OpenTelemetry, and other session-oriented layers that are useful for an interactive app but unnecessary for a one-shot login command. ## Tradeoffs The implementation favors fidelity for caller-visible errors and restraint for persistent logs. Parsed JSON token-endpoint errors are logged safely by field. Non-JSON token-endpoint bodies remain available to the returned error so CLI and browser surfaces still show backend detail. Transport errors keep their real `reqwest` message, but attached URLs are surgically redacted. Custom issuer URLs are sanitized before logging. On the CLI side, the code intentionally duplicates a narrow slice of the TUI file-logging setup instead of sharing the full initializer. That keeps `codex login` easy to reason about and avoids coupling it to interactive-session layers that the command does not need. ## Architecture The core auth behavior lives in `codex-rs/login/src/server.rs`. The callback path now logs callback receipt, callback validation, token-exchange start, token-exchange success, token-endpoint non-2xx responses, and transport failures. App-server consumers still use this same login-server path via `run_login_server(...)`, so the same instrumentation benefits TUI, Electron, and VS Code extension flows. The direct CLI path in `codex-rs/cli/src/login.rs` now installs a small file-backed tracing layer for login commands only. That writes `codex-login.log` under `log_dir` with login-specific targets such as `codex_cli::login` and `codex_login::server`. ## Observability The main signals come from the `login` crate target and are intentionally scoped to sign-in. Structured logs include redacted issuer URLs, redacted transport errors, HTTP status, and parsed token-endpoint fields when available. The callback-layer log intentionally avoids `%err` on token-endpoint failures so arbitrary backend bodies do not get copied into the normal log file. Direct `codex login` now leaves a durable artifact for both failure and success cases. Example output from the new file-backed CLI path: Failing callback: ```text 2026-03-06T22:08:54.143612Z INFO codex_cli::login: starting browser login flow 2026-03-06T22:09:03.431699Z INFO codex_login::server: received login callback path=/auth/callback has_code=false has_state=true has_error=true state_valid=true 2026-03-06T22:09:03.431745Z WARN codex_login::server: oauth callback returned error error_code="access_denied" has_error_description=true ``` Succeeded callback and token exchange: ```text 2026-03-06T22:09:14.065559Z INFO codex_cli::login: starting browser login flow 2026-03-06T22:09:36.431678Z INFO codex_login::server: received login callback path=/auth/callback has_code=true has_state=true has_error=false state_valid=true 2026-03-06T22:09:36.436977Z INFO codex_login::server: starting oauth token exchange issuer=https://auth.openai.com/ redirect_uri=http://localhost:1455/auth/callback 2026-03-06T22:09:36.685438Z INFO codex_login::server: oauth token exchange succeeded status=200 OK ``` ## Tests - `cargo test -p codex-login` - `cargo clippy -p codex-login --tests -- -D warnings` - `cargo test -p codex-cli` - `just bazel-lock-update` - `just bazel-lock-check` - manual direct `codex login` smoke tests for both a failing callback and a successful browser login --------- Co-authored-by: Codex <noreply@openai.com>
This commit is contained in:
Josh McKinney
GitHub
parent
dd4a5216c9
commit
4e68fb96e2
6 changed files with 616 additions and 12 deletions
4
codex-rs/Cargo.lock
generated
4
codex-rs/Cargo.lock
generated
|
|
@ -1647,6 +1647,8 @@ dependencies = [
|
|||
"tokio",
|
||||
"toml 0.9.11+spec-1.1.0",
|
||||
"tracing",
|
||||
"tracing-appender",
|
||||
"tracing-subscriber",
|
||||
]
|
||||
|
||||
[[package]]
|
||||
|
|
@ -2088,6 +2090,7 @@ dependencies = [
|
|||
"codex-app-server-protocol",
|
||||
"codex-core",
|
||||
"core_test_support",
|
||||
"pretty_assertions",
|
||||
"rand 0.9.2",
|
||||
"reqwest",
|
||||
"serde",
|
||||
|
|
@ -2096,6 +2099,7 @@ dependencies = [
|
|||
"tempfile",
|
||||
"tiny_http",
|
||||
"tokio",
|
||||
"tracing",
|
||||
"url",
|
||||
"urlencoding",
|
||||
"webbrowser",
|
||||
|
|
|
|||
|
|
@ -53,6 +53,8 @@ tokio = { workspace = true, features = [
|
|||
] }
|
||||
toml = { workspace = true }
|
||||
tracing = { workspace = true }
|
||||
tracing-appender = { workspace = true }
|
||||
tracing-subscriber = { workspace = true }
|
||||
|
||||
[target.'cfg(target_os = "windows")'.dependencies]
|
||||
codex_windows_sandbox = { package = "codex-windows-sandbox", path = "../windows-sandbox-rs" }
|
||||
|
|
|
|||
|
|
@ -1,3 +1,12 @@
|
|||
//! CLI login commands and their direct-user observability surfaces.
|
||||
//!
|
||||
//! The TUI path already installs a broader tracing stack with feedback, OpenTelemetry, and other
|
||||
//! interactive-session layers. Direct `codex login` intentionally does less: it preserves the
|
||||
//! existing stderr/browser UX and adds only a small file-backed tracing layer for login-specific
|
||||
//! targets. Keeping that setup local avoids pulling the TUI's session-oriented logging machinery
|
||||
//! into a one-shot CLI command while still producing a durable `codex-login.log` artifact that
|
||||
//! support can request from users.
|
||||
|
||||
use codex_core::CodexAuth;
|
||||
use codex_core::auth::AuthCredentialsStoreMode;
|
||||
use codex_core::auth::AuthMode;
|
||||
|
|
@ -10,9 +19,16 @@ use codex_login::run_device_code_login;
|
|||
use codex_login::run_login_server;
|
||||
use codex_protocol::config_types::ForcedLoginMethod;
|
||||
use codex_utils_cli::CliConfigOverrides;
|
||||
use std::fs::OpenOptions;
|
||||
use std::io::IsTerminal;
|
||||
use std::io::Read;
|
||||
use std::path::PathBuf;
|
||||
use tracing_appender::non_blocking;
|
||||
use tracing_appender::non_blocking::WorkerGuard;
|
||||
use tracing_subscriber::EnvFilter;
|
||||
use tracing_subscriber::Layer;
|
||||
use tracing_subscriber::layer::SubscriberExt;
|
||||
use tracing_subscriber::util::SubscriberInitExt;
|
||||
|
||||
const CHATGPT_LOGIN_DISABLED_MESSAGE: &str =
|
||||
"ChatGPT login is disabled. Use API key login instead.";
|
||||
|
|
@ -20,6 +36,74 @@ const API_KEY_LOGIN_DISABLED_MESSAGE: &str =
|
|||
"API key login is disabled. Use ChatGPT login instead.";
|
||||
const LOGIN_SUCCESS_MESSAGE: &str = "Successfully logged in";
|
||||
|
||||
/// Installs a small file-backed tracing layer for direct `codex login` flows.
|
||||
///
|
||||
/// This deliberately duplicates a narrow slice of the TUI logging setup instead of reusing it
|
||||
/// wholesale. The TUI stack includes session-oriented layers that are valuable for interactive
|
||||
/// runs but unnecessary for a one-shot login command. Keeping the direct CLI path local lets this
|
||||
/// command produce a durable `codex-login.log` artifact without coupling it to the TUI's broader
|
||||
/// telemetry and feedback initialization.
|
||||
fn init_login_file_logging(config: &Config) -> Option<WorkerGuard> {
|
||||
let log_dir = match codex_core::config::log_dir(config) {
|
||||
Ok(log_dir) => log_dir,
|
||||
Err(err) => {
|
||||
eprintln!("Warning: failed to resolve login log directory: {err}");
|
||||
return None;
|
||||
}
|
||||
};
|
||||
|
||||
if let Err(err) = std::fs::create_dir_all(&log_dir) {
|
||||
eprintln!(
|
||||
"Warning: failed to create login log directory {}: {err}",
|
||||
log_dir.display()
|
||||
);
|
||||
return None;
|
||||
}
|
||||
|
||||
let mut log_file_opts = OpenOptions::new();
|
||||
log_file_opts.create(true).append(true);
|
||||
|
||||
#[cfg(unix)]
|
||||
{
|
||||
use std::os::unix::fs::OpenOptionsExt;
|
||||
log_file_opts.mode(0o600);
|
||||
}
|
||||
|
||||
let log_path = log_dir.join("codex-login.log");
|
||||
let log_file = match log_file_opts.open(&log_path) {
|
||||
Ok(log_file) => log_file,
|
||||
Err(err) => {
|
||||
eprintln!(
|
||||
"Warning: failed to open login log file {}: {err}",
|
||||
log_path.display()
|
||||
);
|
||||
return None;
|
||||
}
|
||||
};
|
||||
|
||||
let (non_blocking, guard) = non_blocking(log_file);
|
||||
let env_filter = EnvFilter::try_from_default_env()
|
||||
.unwrap_or_else(|_| EnvFilter::new("codex_cli=info,codex_core=info,codex_login=info"));
|
||||
let file_layer = tracing_subscriber::fmt::layer()
|
||||
.with_writer(non_blocking)
|
||||
.with_target(true)
|
||||
.with_ansi(false)
|
||||
.with_filter(env_filter);
|
||||
|
||||
// Direct `codex login` otherwise relies on ephemeral stderr and browser output.
|
||||
// Persist the same login targets to a file so support can inspect auth failures
|
||||
// without reproducing them through TUI or app-server.
|
||||
if let Err(err) = tracing_subscriber::registry().with(file_layer).try_init() {
|
||||
eprintln!(
|
||||
"Warning: failed to initialize login log file {}: {err}",
|
||||
log_path.display()
|
||||
);
|
||||
return None;
|
||||
}
|
||||
|
||||
Some(guard)
|
||||
}
|
||||
|
||||
fn print_login_server_start(actual_port: u16, auth_url: &str) {
|
||||
eprintln!(
|
||||
"Starting local login server on http://localhost:{actual_port}.\nIf your browser did not open, navigate to this URL to authenticate:\n\n{auth_url}\n\nOn a remote or headless machine? Use `codex login --device-auth` instead."
|
||||
|
|
@ -46,6 +130,8 @@ pub async fn login_with_chatgpt(
|
|||
|
||||
pub async fn run_login_with_chatgpt(cli_config_overrides: CliConfigOverrides) -> ! {
|
||||
let config = load_config_or_exit(cli_config_overrides).await;
|
||||
let _login_log_guard = init_login_file_logging(&config);
|
||||
tracing::info!("starting browser login flow");
|
||||
|
||||
if matches!(config.forced_login_method, Some(ForcedLoginMethod::Api)) {
|
||||
eprintln!("{CHATGPT_LOGIN_DISABLED_MESSAGE}");
|
||||
|
|
@ -77,6 +163,8 @@ pub async fn run_login_with_api_key(
|
|||
api_key: String,
|
||||
) -> ! {
|
||||
let config = load_config_or_exit(cli_config_overrides).await;
|
||||
let _login_log_guard = init_login_file_logging(&config);
|
||||
tracing::info!("starting api key login flow");
|
||||
|
||||
if matches!(config.forced_login_method, Some(ForcedLoginMethod::Chatgpt)) {
|
||||
eprintln!("{API_KEY_LOGIN_DISABLED_MESSAGE}");
|
||||
|
|
@ -133,6 +221,8 @@ pub async fn run_login_with_device_code(
|
|||
client_id: Option<String>,
|
||||
) -> ! {
|
||||
let config = load_config_or_exit(cli_config_overrides).await;
|
||||
let _login_log_guard = init_login_file_logging(&config);
|
||||
tracing::info!("starting device code login flow");
|
||||
if matches!(config.forced_login_method, Some(ForcedLoginMethod::Api)) {
|
||||
eprintln!("{CHATGPT_LOGIN_DISABLED_MESSAGE}");
|
||||
std::process::exit(1);
|
||||
|
|
@ -169,6 +259,8 @@ pub async fn run_login_with_device_code_fallback_to_browser(
|
|||
client_id: Option<String>,
|
||||
) -> ! {
|
||||
let config = load_config_or_exit(cli_config_overrides).await;
|
||||
let _login_log_guard = init_login_file_logging(&config);
|
||||
tracing::info!("starting login flow with device code fallback");
|
||||
if matches!(config.forced_login_method, Some(ForcedLoginMethod::Api)) {
|
||||
eprintln!("{CHATGPT_LOGIN_DISABLED_MESSAGE}");
|
||||
std::process::exit(1);
|
||||
|
|
|
|||
|
|
@ -26,6 +26,7 @@ tokio = { workspace = true, features = [
|
|||
"rt-multi-thread",
|
||||
"signal",
|
||||
] }
|
||||
tracing = { workspace = true }
|
||||
url = { workspace = true }
|
||||
urlencoding = { workspace = true }
|
||||
webbrowser = { workspace = true }
|
||||
|
|
@ -33,5 +34,6 @@ webbrowser = { workspace = true }
|
|||
[dev-dependencies]
|
||||
anyhow = { workspace = true }
|
||||
core_test_support = { workspace = true }
|
||||
pretty_assertions = { workspace = true }
|
||||
tempfile = { workspace = true }
|
||||
wiremock = { workspace = true }
|
||||
|
|
|
|||
|
|
@ -1,6 +1,16 @@
|
|||
//! Local OAuth callback server for CLI login.
|
||||
//!
|
||||
//! This module runs the short-lived localhost server used by interactive sign-in.
|
||||
//!
|
||||
//! The callback flow has two competing responsibilities:
|
||||
//!
|
||||
//! - preserve enough backend and transport detail for developers, sysadmins, and support
|
||||
//! engineers to diagnose failed sign-ins
|
||||
//! - avoid persisting secrets or sensitive URL/query data into normal application logs
|
||||
//!
|
||||
//! This module therefore keeps the user-facing error path and the structured-log path separate.
|
||||
//! Returned `io::Error` values still carry the detail needed by CLI/browser callers, while
|
||||
//! structured logs only emit explicitly reviewed fields plus redacted URL/error values.
|
||||
use std::io::Cursor;
|
||||
use std::io::Read;
|
||||
use std::io::Write;
|
||||
|
|
@ -31,6 +41,9 @@ use tiny_http::Request;
|
|||
use tiny_http::Response;
|
||||
use tiny_http::Server;
|
||||
use tiny_http::StatusCode;
|
||||
use tracing::error;
|
||||
use tracing::info;
|
||||
use tracing::warn;
|
||||
|
||||
const DEFAULT_ISSUER: &str = "https://auth.openai.com";
|
||||
const DEFAULT_PORT: u16 = 1455;
|
||||
|
|
@ -253,7 +266,26 @@ async fn process_request(
|
|||
"/auth/callback" => {
|
||||
let params: std::collections::HashMap<String, String> =
|
||||
parsed_url.query_pairs().into_owned().collect();
|
||||
if params.get("state").map(String::as_str) != Some(state) {
|
||||
let has_code = params.get("code").is_some_and(|code| !code.is_empty());
|
||||
let has_state = params.get("state").is_some_and(|state| !state.is_empty());
|
||||
let has_error = params.get("error").is_some_and(|error| !error.is_empty());
|
||||
let state_valid = params.get("state").map(String::as_str) == Some(state);
|
||||
info!(
|
||||
path = %path,
|
||||
has_code,
|
||||
has_state,
|
||||
has_error,
|
||||
state_valid,
|
||||
"received login callback"
|
||||
);
|
||||
if !state_valid {
|
||||
warn!(
|
||||
path = %path,
|
||||
has_code,
|
||||
has_state,
|
||||
has_error,
|
||||
"login callback state mismatch"
|
||||
);
|
||||
return HandledRequest::Response(
|
||||
Response::from_string("State mismatch").with_status_code(400),
|
||||
);
|
||||
|
|
@ -262,6 +294,11 @@ async fn process_request(
|
|||
let error_description = params.get("error_description").map(String::as_str);
|
||||
let message = oauth_callback_error_message(error_code, error_description);
|
||||
eprintln!("OAuth callback error: {message}");
|
||||
warn!(
|
||||
error_code,
|
||||
has_error_description = error_description.is_some_and(|s| !s.trim().is_empty()),
|
||||
"oauth callback returned error"
|
||||
);
|
||||
return login_error_response(
|
||||
&message,
|
||||
io::ErrorKind::PermissionDenied,
|
||||
|
|
@ -338,6 +375,7 @@ async fn process_request(
|
|||
}
|
||||
Err(err) => {
|
||||
eprintln!("Token exchange error: {err}");
|
||||
error!("login callback token exchange failed");
|
||||
login_error_response(
|
||||
&format!("Token exchange failed: {err}"),
|
||||
io::ErrorKind::Other,
|
||||
|
|
@ -533,7 +571,110 @@ pub(crate) struct ExchangedTokens {
|
|||
pub refresh_token: String,
|
||||
}
|
||||
|
||||
#[derive(Debug, Clone, PartialEq, Eq)]
|
||||
struct TokenEndpointErrorDetail {
|
||||
error_code: Option<String>,
|
||||
error_message: Option<String>,
|
||||
display_message: String,
|
||||
}
|
||||
|
||||
impl std::fmt::Display for TokenEndpointErrorDetail {
|
||||
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
|
||||
self.display_message.fmt(f)
|
||||
}
|
||||
}
|
||||
|
||||
const REDACTED_URL_VALUE: &str = "<redacted>";
|
||||
const SENSITIVE_URL_QUERY_KEYS: &[&str] = &[
|
||||
"access_token",
|
||||
"api_key",
|
||||
"client_secret",
|
||||
"code",
|
||||
"code_verifier",
|
||||
"id_token",
|
||||
"key",
|
||||
"refresh_token",
|
||||
"requested_token",
|
||||
"state",
|
||||
"subject_token",
|
||||
"token",
|
||||
];
|
||||
|
||||
fn redact_sensitive_query_value(key: &str, value: &str) -> String {
|
||||
if SENSITIVE_URL_QUERY_KEYS
|
||||
.iter()
|
||||
.any(|candidate| candidate.eq_ignore_ascii_case(key))
|
||||
{
|
||||
REDACTED_URL_VALUE.to_string()
|
||||
} else {
|
||||
value.to_string()
|
||||
}
|
||||
}
|
||||
|
||||
/// Redacts URL components that commonly carry auth secrets while preserving the host/path shape.
|
||||
///
|
||||
/// This keeps developer-facing logs useful for debugging transport failures without persisting
|
||||
/// tokens, callback codes, fragments, or embedded credentials.
|
||||
fn redact_sensitive_url_parts(url: &mut url::Url) {
|
||||
let _ = url.set_username("");
|
||||
let _ = url.set_password(None);
|
||||
url.set_fragment(None);
|
||||
|
||||
let query_pairs = url
|
||||
.query_pairs()
|
||||
.map(|(key, value)| {
|
||||
let key = key.into_owned();
|
||||
let value = value.into_owned();
|
||||
(key.clone(), redact_sensitive_query_value(&key, &value))
|
||||
})
|
||||
.collect::<Vec<_>>();
|
||||
|
||||
if query_pairs.is_empty() {
|
||||
url.set_query(None);
|
||||
return;
|
||||
}
|
||||
|
||||
let redacted_query = query_pairs
|
||||
.into_iter()
|
||||
.fold(
|
||||
url::form_urlencoded::Serializer::new(String::new()),
|
||||
|mut serializer, (key, value)| {
|
||||
serializer.append_pair(&key, &value);
|
||||
serializer
|
||||
},
|
||||
)
|
||||
.finish();
|
||||
url.set_query(Some(&redacted_query));
|
||||
}
|
||||
|
||||
/// Redacts any URL attached to a reqwest transport error before it is logged or returned.
|
||||
fn redact_sensitive_error_url(mut err: reqwest::Error) -> reqwest::Error {
|
||||
if let Some(url) = err.url_mut() {
|
||||
redact_sensitive_url_parts(url);
|
||||
}
|
||||
err
|
||||
}
|
||||
|
||||
/// Sanitizes a free-form URL string for structured logging.
|
||||
///
|
||||
/// This is used for caller-supplied issuer values, which may contain credentials or query
|
||||
/// parameters on non-default deployments.
|
||||
fn sanitize_url_for_logging(url: &str) -> String {
|
||||
match url::Url::parse(url) {
|
||||
Ok(mut url) => {
|
||||
redact_sensitive_url_parts(&mut url);
|
||||
url.to_string()
|
||||
}
|
||||
Err(_) => "<invalid-url>".to_string(),
|
||||
}
|
||||
}
|
||||
|
||||
/// Exchanges an authorization code for tokens.
|
||||
///
|
||||
/// The returned error remains suitable for user-facing CLI/browser surfaces, so backend-provided
|
||||
/// non-JSON error text is preserved there. Structured logging stays narrower: it logs reviewed
|
||||
/// fields from parsed token responses and redacted transport errors, but does not log the final
|
||||
/// callback-layer `%err` string.
|
||||
pub(crate) async fn exchange_code_for_tokens(
|
||||
issuer: &str,
|
||||
client_id: &str,
|
||||
|
|
@ -549,6 +690,11 @@ pub(crate) async fn exchange_code_for_tokens(
|
|||
}
|
||||
|
||||
let client = reqwest::Client::new();
|
||||
info!(
|
||||
issuer = %sanitize_url_for_logging(issuer),
|
||||
redirect_uri = %redirect_uri,
|
||||
"starting oauth token exchange"
|
||||
);
|
||||
let resp = client
|
||||
.post(format!("{issuer}/oauth/token"))
|
||||
.header("Content-Type", "application/x-www-form-urlencoded")
|
||||
|
|
@ -561,18 +707,35 @@ pub(crate) async fn exchange_code_for_tokens(
|
|||
))
|
||||
.send()
|
||||
.await
|
||||
.map_err(io::Error::other)?;
|
||||
.map_err(|err| {
|
||||
let err = redact_sensitive_error_url(err);
|
||||
error!(
|
||||
is_timeout = err.is_timeout(),
|
||||
is_connect = err.is_connect(),
|
||||
is_request = err.is_request(),
|
||||
error = %err,
|
||||
"oauth token exchange transport failure"
|
||||
);
|
||||
io::Error::other(err)
|
||||
})?;
|
||||
|
||||
let status = resp.status();
|
||||
if !status.is_success() {
|
||||
let body = resp.text().await.map_err(io::Error::other)?;
|
||||
let detail = parse_token_endpoint_error(&body);
|
||||
warn!(
|
||||
%status,
|
||||
error_code = detail.error_code.as_deref().unwrap_or("unknown"),
|
||||
error_message = detail.error_message.as_deref().unwrap_or("unknown"),
|
||||
"oauth token exchange returned non-success status"
|
||||
);
|
||||
return Err(io::Error::other(format!(
|
||||
"token endpoint returned status {status}: {detail}"
|
||||
)));
|
||||
}
|
||||
|
||||
let tokens: TokenResponse = resp.json().await.map_err(io::Error::other)?;
|
||||
info!(%status, "oauth token exchange succeeded");
|
||||
Ok(ExchangedTokens {
|
||||
id_token: tokens.id_token,
|
||||
access_token: tokens.access_token,
|
||||
|
|
@ -760,34 +923,73 @@ fn oauth_callback_error_message(error_code: &str, error_description: Option<&str
|
|||
format!("Sign-in failed: {error_code}")
|
||||
}
|
||||
|
||||
/// Extracts a readable error from token endpoint responses.
|
||||
fn parse_token_endpoint_error(body: &str) -> String {
|
||||
/// Extracts token endpoint error detail for both structured logging and caller-visible errors.
|
||||
///
|
||||
/// Parsed JSON fields are safe to log individually. If the response is not JSON, the raw body is
|
||||
/// preserved only for the returned error path so the CLI/browser can still surface the backend
|
||||
/// detail, while the structured log path continues to use the explicitly parsed safe fields above.
|
||||
fn parse_token_endpoint_error(body: &str) -> TokenEndpointErrorDetail {
|
||||
let trimmed = body.trim();
|
||||
if trimmed.is_empty() {
|
||||
return "unknown error".to_string();
|
||||
return TokenEndpointErrorDetail {
|
||||
error_code: None,
|
||||
error_message: None,
|
||||
display_message: "unknown error".to_string(),
|
||||
};
|
||||
}
|
||||
|
||||
let parsed = serde_json::from_str::<JsonValue>(trimmed).ok();
|
||||
if let Some(json) = parsed {
|
||||
let error_code = json
|
||||
.get("error")
|
||||
.and_then(JsonValue::as_str)
|
||||
.filter(|error_code| !error_code.trim().is_empty())
|
||||
.map(ToString::to_string)
|
||||
.or_else(|| {
|
||||
json.get("error")
|
||||
.and_then(JsonValue::as_object)
|
||||
.and_then(|error_obj| error_obj.get("code"))
|
||||
.and_then(JsonValue::as_str)
|
||||
.filter(|code| !code.trim().is_empty())
|
||||
.map(ToString::to_string)
|
||||
});
|
||||
if let Some(description) = json.get("error_description").and_then(JsonValue::as_str)
|
||||
&& !description.trim().is_empty()
|
||||
{
|
||||
return description.to_string();
|
||||
return TokenEndpointErrorDetail {
|
||||
error_code,
|
||||
error_message: Some(description.to_string()),
|
||||
display_message: description.to_string(),
|
||||
};
|
||||
}
|
||||
if let Some(error_obj) = json.get("error")
|
||||
&& let Some(message) = error_obj.get("message").and_then(JsonValue::as_str)
|
||||
&& !message.trim().is_empty()
|
||||
{
|
||||
return message.to_string();
|
||||
return TokenEndpointErrorDetail {
|
||||
error_code,
|
||||
error_message: Some(message.to_string()),
|
||||
display_message: message.to_string(),
|
||||
};
|
||||
}
|
||||
if let Some(error_code) = json.get("error").and_then(JsonValue::as_str)
|
||||
&& !error_code.trim().is_empty()
|
||||
{
|
||||
return error_code.to_string();
|
||||
if let Some(error_code) = error_code {
|
||||
return TokenEndpointErrorDetail {
|
||||
display_message: error_code.clone(),
|
||||
error_code: Some(error_code),
|
||||
error_message: None,
|
||||
};
|
||||
}
|
||||
}
|
||||
|
||||
trimmed.to_string()
|
||||
// Preserve non-JSON token-endpoint bodies for the returned error so CLI/browser flows still
|
||||
// surface the backend detail users and admins need, but keep that text out of structured logs
|
||||
// by only logging explicitly parsed fields above and avoiding `%err` logging at the callback
|
||||
// layer.
|
||||
TokenEndpointErrorDetail {
|
||||
error_code: None,
|
||||
error_message: None,
|
||||
display_message: trimmed.to_string(),
|
||||
}
|
||||
}
|
||||
|
||||
/// Renders the branded error page used by callback failures.
|
||||
|
|
@ -877,3 +1079,112 @@ pub(crate) async fn obtain_api_key(
|
|||
let body: ExchangeResp = resp.json().await.map_err(io::Error::other)?;
|
||||
Ok(body.access_token)
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use pretty_assertions::assert_eq;
|
||||
|
||||
use super::TokenEndpointErrorDetail;
|
||||
use super::parse_token_endpoint_error;
|
||||
use super::redact_sensitive_query_value;
|
||||
use super::redact_sensitive_url_parts;
|
||||
use super::sanitize_url_for_logging;
|
||||
|
||||
#[test]
|
||||
fn parse_token_endpoint_error_prefers_error_description() {
|
||||
let detail = parse_token_endpoint_error(
|
||||
r#"{"error":"invalid_grant","error_description":"refresh token expired"}"#,
|
||||
);
|
||||
|
||||
assert_eq!(
|
||||
detail,
|
||||
TokenEndpointErrorDetail {
|
||||
error_code: Some("invalid_grant".to_string()),
|
||||
error_message: Some("refresh token expired".to_string()),
|
||||
display_message: "refresh token expired".to_string(),
|
||||
}
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn parse_token_endpoint_error_reads_nested_error_message_and_code() {
|
||||
let detail = parse_token_endpoint_error(
|
||||
r#"{"error":{"code":"proxy_auth_required","message":"proxy authentication required"}}"#,
|
||||
);
|
||||
|
||||
assert_eq!(
|
||||
detail,
|
||||
TokenEndpointErrorDetail {
|
||||
error_code: Some("proxy_auth_required".to_string()),
|
||||
error_message: Some("proxy authentication required".to_string()),
|
||||
display_message: "proxy authentication required".to_string(),
|
||||
}
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn parse_token_endpoint_error_falls_back_to_error_code() {
|
||||
let detail = parse_token_endpoint_error(r#"{"error":"temporarily_unavailable"}"#);
|
||||
|
||||
assert_eq!(
|
||||
detail,
|
||||
TokenEndpointErrorDetail {
|
||||
error_code: Some("temporarily_unavailable".to_string()),
|
||||
error_message: None,
|
||||
display_message: "temporarily_unavailable".to_string(),
|
||||
}
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn parse_token_endpoint_error_preserves_plain_text_for_display() {
|
||||
let detail = parse_token_endpoint_error("service unavailable");
|
||||
|
||||
assert_eq!(
|
||||
detail,
|
||||
TokenEndpointErrorDetail {
|
||||
error_code: None,
|
||||
error_message: None,
|
||||
display_message: "service unavailable".to_string(),
|
||||
}
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn redact_sensitive_query_value_only_scrubs_known_keys() {
|
||||
assert_eq!(
|
||||
redact_sensitive_query_value("code", "abc123"),
|
||||
"<redacted>".to_string()
|
||||
);
|
||||
assert_eq!(
|
||||
redact_sensitive_query_value("redirect_uri", "http://localhost:1455/auth/callback"),
|
||||
"http://localhost:1455/auth/callback".to_string()
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn redact_sensitive_url_parts_preserves_safe_url_shape() {
|
||||
let mut url = url::Url::parse(
|
||||
"https://user:pass@auth.openai.com/oauth/token?code=abc123&redirect_uri=http%3A%2F%2Flocalhost%3A1455%2Fauth%2Fcallback#frag",
|
||||
)
|
||||
.expect("valid url");
|
||||
|
||||
redact_sensitive_url_parts(&mut url);
|
||||
|
||||
assert_eq!(
|
||||
url.as_str(),
|
||||
"https://auth.openai.com/oauth/token?code=%3Credacted%3E&redirect_uri=http%3A%2F%2Flocalhost%3A1455%2Fauth%2Fcallback"
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn sanitize_url_for_logging_redacts_sensitive_issuer_parts() {
|
||||
let redacted =
|
||||
sanitize_url_for_logging("https://user:pass@example.com/base?token=abc123&env=prod");
|
||||
|
||||
assert_eq!(
|
||||
redacted,
|
||||
"https://example.com/base?token=%3Credacted%3E&env=prod".to_string()
|
||||
);
|
||||
}
|
||||
}
|
||||
|
|
|
|||
193
docs/auth-login-logging-plan.md
Normal file
193
docs/auth-login-logging-plan.md
Normal file
|
|
@ -0,0 +1,193 @@
|
|||
# Auth Login Logging
|
||||
|
||||
## Problem
|
||||
|
||||
Customer-side auth failures are hard to diagnose because the most important browser-login step,
|
||||
the final `POST https://auth.openai.com/oauth/token` after the localhost callback, historically
|
||||
does not show up as a first-class application event.
|
||||
|
||||
In the failing HARs and Slack thread, browser auth succeeds, workspace selection succeeds, and the
|
||||
browser reaches `http://localhost:1455/auth/callback`. Support can usually confirm that:
|
||||
|
||||
- the user reached the browser sign-in flow
|
||||
- the browser returned to the localhost callback
|
||||
- Codex showed a generic sign-in failure
|
||||
|
||||
What support cannot reliably determine from Codex-owned logs is why the final token exchange
|
||||
failed. That leaves the most important diagnostic question unanswered:
|
||||
|
||||
- was this a backend non-2xx response
|
||||
- a transport failure talking to `auth.openai.com`
|
||||
- a proxy, TLS, DNS, or connectivity issue
|
||||
- some other local client-side failure after browser auth completed
|
||||
|
||||
This documentation explains how the current instrumentation closes that gap without broadening the
|
||||
normal logging surface in unsafe ways.
|
||||
|
||||
## Mental Model
|
||||
|
||||
The browser-login flow has three separate outputs, and they do not serve the same audience:
|
||||
|
||||
- the browser-facing error page
|
||||
- the caller-visible returned `io::Error`
|
||||
- the normal structured application log
|
||||
|
||||
Those outputs now intentionally diverge.
|
||||
|
||||
The browser-facing page and returned error still preserve the backend detail needed by developers,
|
||||
sysadmins, and support engineers to understand what happened. The structured log stays narrower:
|
||||
it emits explicitly reviewed fields, redacted URLs, and redacted transport errors so the normal
|
||||
log file is useful without becoming a credential sink.
|
||||
|
||||
## Non-goals
|
||||
|
||||
This does not add auth logging to every runtime request.
|
||||
|
||||
- The instrumentation is scoped to the initial browser-login callback flow.
|
||||
- The refresh-token path in `codex-core` remains a separate concern.
|
||||
- This does not attempt to classify every transport failure into a specific root cause from string
|
||||
matching.
|
||||
|
||||
## Tradeoffs
|
||||
|
||||
This implementation prefers fidelity for caller-visible errors and restraint for structured logs.
|
||||
|
||||
- Non-2xx token endpoint responses log parsed safe fields such as status, `error`, and
|
||||
`error_description` when available.
|
||||
- Non-JSON token endpoint bodies are preserved in the returned error so CLI/browser flows still
|
||||
surface the backend detail that operators need.
|
||||
- The callback-layer structured log does not log `%err` for token endpoint failures, because that
|
||||
would persist arbitrary backend response text into the normal log file.
|
||||
- Transport failures keep the underlying `reqwest` error text, but attached URLs are redacted
|
||||
before they are logged or returned.
|
||||
- Caller-supplied issuer URLs are sanitized before they are logged, including custom issuers with
|
||||
embedded credentials or sensitive query params.
|
||||
|
||||
The result is not maximally detailed in one place. It is intentionally split so each surface gets
|
||||
the level of detail it can safely carry.
|
||||
|
||||
## Architecture
|
||||
|
||||
The browser-login callback flow lives in
|
||||
[`codex-rs/login/src/server.rs`](../codex-rs/login/src/server.rs).
|
||||
|
||||
The key behavior is:
|
||||
|
||||
- the callback handler logs whether the callback was received and whether state validation passed
|
||||
- the token exchange logs start, success, and non-2xx responses as structured events
|
||||
- transport failures log the redacted `reqwest` error plus `is_timeout`, `is_connect`, and
|
||||
`is_request`
|
||||
- the browser-facing `Codex Sign-in Error` page remains intact
|
||||
- the returned `io::Error` continues to carry useful backend detail for CLI/browser callers
|
||||
|
||||
App-server consumers use the same login-server path rather than a separate auth implementation.
|
||||
|
||||
- `account/login/start` calls into `run_login_server(...)`
|
||||
- app-server waits for `server.block_until_done()`
|
||||
- app-server emits `account/login/completed` with wrapped success/error state
|
||||
|
||||
That means the login-crate instrumentation benefits:
|
||||
|
||||
- direct CLI / TUI login
|
||||
- Electron app login
|
||||
- VS Code extension login
|
||||
|
||||
Direct `codex login` also writes a small file-backed log through the CLI crate.
|
||||
|
||||
- the file is `codex-login.log` under the configured `log_dir`
|
||||
- this uses a deliberately small tracing setup local to the CLI login commands
|
||||
- it does not try to reuse the TUI logging stack wholesale, because the TUI path also installs
|
||||
feedback, OpenTelemetry, and other interactive-session layers that are not needed for a
|
||||
one-shot login command
|
||||
- the duplication is intentional: it keeps the direct CLI behavior easy to reason about while
|
||||
still giving support a durable artifact from the same `codex_login::server` events
|
||||
|
||||
## Observability
|
||||
|
||||
The main new signals are emitted from the `login` crate target, for example
|
||||
`codex_login::server`, so they stay aligned with the code that produces them.
|
||||
|
||||
The useful events are:
|
||||
|
||||
- callback received
|
||||
- callback state mismatch
|
||||
- OAuth callback returned error
|
||||
- OAuth token exchange started
|
||||
- OAuth token exchange transport failure
|
||||
- OAuth token exchange returned non-success status
|
||||
- OAuth token exchange succeeded
|
||||
|
||||
The structured log intentionally uses a narrower payload than the returned error:
|
||||
|
||||
- issuer URLs are sanitized before logging
|
||||
- sensitive URL query keys such as `code`, `state`, `token`, `access_token`, `refresh_token`,
|
||||
`id_token`, `client_secret`, and `code_verifier` are redacted
|
||||
- embedded credentials and fragments are stripped from logged URLs
|
||||
- parsed token-endpoint fields are logged individually when available
|
||||
- arbitrary non-JSON token endpoint bodies are not logged into the normal application log
|
||||
|
||||
This split is the main privacy boundary in the implementation.
|
||||
|
||||
## Failure Modes
|
||||
|
||||
The current instrumentation is most useful for these cases:
|
||||
|
||||
- browser auth succeeds but the final token exchange fails
|
||||
- custom issuer deployments need confirmation that the callback reached the login server
|
||||
- operators need to distinguish backend non-2xx responses from transport failures
|
||||
- transport failures need the underlying `reqwest` signal without leaking sensitive URL parts
|
||||
|
||||
It is intentionally weaker for one class of diagnosis:
|
||||
|
||||
- it does not try to infer specific transport causes such as proxy, TLS, or DNS from message
|
||||
string matching, because that kind of over-classification can mislead operators
|
||||
|
||||
## Security and Sensitivity Notes
|
||||
|
||||
This implementation treats the normal application log as a persistent surface that must be safe to
|
||||
collect and share.
|
||||
|
||||
That means:
|
||||
|
||||
- user-supplied issuer URLs are sanitized before logging
|
||||
- transport errors redact attached URLs instead of dropping them entirely
|
||||
- known secret-bearing query params are redacted surgically rather than removing all URL context
|
||||
- non-JSON token endpoint bodies are preserved only for the returned error path, not the
|
||||
structured-log path
|
||||
|
||||
This behavior reflects two review-driven constraints that are already fixed in the code:
|
||||
|
||||
- custom issuers no longer leak embedded credentials or sensitive query params in the
|
||||
`starting oauth token exchange` log line
|
||||
- non-JSON token endpoint bodies are once again preserved for caller-visible errors, but they no
|
||||
longer get duplicated into normal structured logs through callback-layer `%err` logging
|
||||
|
||||
## Debug Path
|
||||
|
||||
For a failed sign-in, read the evidence in this order:
|
||||
|
||||
1. Browser/HAR evidence:
|
||||
confirm the browser reached `http://localhost:1455/auth/callback`.
|
||||
2. Login-crate structured logs:
|
||||
check whether the callback was received, whether state validation passed, and whether the token
|
||||
exchange failed as transport or non-2xx.
|
||||
3. Caller-visible error:
|
||||
use the CLI/browser/app error text to recover backend detail that is intentionally not copied
|
||||
into the normal log file.
|
||||
4. App-server wrapper:
|
||||
if the flow runs through app-server, use `account/login/completed` and its wrapped
|
||||
`Login server error: ...` result as the client-facing envelope around the same login-crate
|
||||
behavior.
|
||||
|
||||
The most important invariant is simple: browser success does not imply login success. The native
|
||||
client still has to exchange the auth code successfully after the callback arrives.
|
||||
|
||||
## Tests
|
||||
|
||||
The `codex-login` test suite covers the new redaction and parsing boundaries:
|
||||
|
||||
- parsed token endpoint JSON fields still surface correctly
|
||||
- plain-text token endpoint bodies still remain available to the caller-visible error path
|
||||
- sensitive query values are redacted selectively
|
||||
- URL shape is preserved while credentials, fragments, and known secret-bearing params are removed
|
||||
- issuer sanitization redacts custom issuer credentials and sensitive params before logging
|
||||
Loading…
Add table
Reference in a new issue