diff --git a/crates/starstats-server/src/auth_routes.rs b/crates/starstats-server/src/auth_routes.rs index 1846f07d..afc843bd 100644 --- a/crates/starstats-server/src/auth_routes.rs +++ b/crates/starstats-server/src/auth_routes.rs @@ -370,7 +370,7 @@ pub async fn signup( .send_verification(&user.email, &user.claimed_handle, &token) .await { - tracing::warn!(error = %e, user_id = %user.id, "send verification email failed"); + tracing::warn!(error = %format!("{e:#}"), user_id = %user.id, "send verification email failed"); } issue_token(&issuer, &user.id.to_string(), &user.claimed_handle) @@ -580,7 +580,7 @@ pub async fn resend_verification( .send_verification(&user.email, &user.claimed_handle, &token) .await { - tracing::warn!(error = %e, user_id = %user.id, "send verification email failed"); + tracing::warn!(error = %format!("{e:#}"), user_id = %user.id, "send verification email failed"); } if let Err(e) = audit @@ -947,7 +947,7 @@ pub async fn password_reset_start( .send_password_reset(&user.email, &user.claimed_handle, &token) .await { - tracing::warn!(error = %e, user_id = %user.id, "send reset email failed"); + tracing::warn!(error = %format!("{e:#}"), user_id = %user.id, "send reset email failed"); } } else { // Sleep briefly to flatten the timing oracle — a fast @@ -1127,7 +1127,7 @@ pub async fn email_change_start( .send_email_change_verify(&new_email, &auth.preferred_username, &token) .await { - tracing::warn!(error = %e, "send email-change verify failed"); + tracing::warn!(error = %format!("{e:#}"), "send email-change verify failed"); } ( StatusCode::OK, diff --git a/crates/starstats-server/src/magic_link_routes.rs b/crates/starstats-server/src/magic_link_routes.rs index ff4c6341..6bab3bbc 100644 --- a/crates/starstats-server/src/magic_link_routes.rs +++ b/crates/starstats-server/src/magic_link_routes.rs @@ -139,7 +139,7 @@ pub async fn start( .send_magic_link(&user.email, &user.claimed_handle, &token) .await { - tracing::warn!(error = %e, "send magic link failed (best-effort)"); + tracing::warn!(error = %format!("{e:#}"), "send magic link failed (best-effort)"); } Json(MagicLinkStartResponse { sent: true }).into_response() diff --git a/crates/starstats-server/src/mail.rs b/crates/starstats-server/src/mail.rs index 395bce2f..17445b9b 100644 --- a/crates/starstats-server/src/mail.rs +++ b/crates/starstats-server/src/mail.rs @@ -703,6 +703,48 @@ pub mod test_support { mod tests { use super::*; + /// Why the mailer log sites format with `{e:#}` and not `%e`. + /// + /// `Display` on an `anyhow::Error` prints ONLY the outermost context. + /// Every mail failure is wrapped (`.context("parse To address")`, + /// `.context("SMTP send failed")`, …), so `error = %e` logs the wrapper + /// and silently discards the actual cause. That is exactly how the + /// waitlist invite outage read as "the mail transport is broken" for as + /// long as it did — the logs only ever said `parse To address`, never + /// which address or why. + /// + /// The alternate form `{e:#}` flattens the whole chain onto one line, + /// which keeps it greppable in the JSON log pipeline (unlike `?e`, + /// whose `Debug` output is multi-line). + #[test] + fn alternate_display_surfaces_the_cause_chain_that_plain_display_hides() { + let err = anyhow::anyhow!("invalid email address: a@b.com ") + .context("parse To address") + .context("send_waitlist_invite failed"); + + let plain = format!("{err}"); + let chained = format!("{err:#}"); + + // What `%e` would have logged: the wrapper only. + assert_eq!(plain, "send_waitlist_invite failed"); + assert!( + !plain.contains("invalid email address"), + "plain Display hides the root cause — this is the bug being guarded against" + ); + + // What `{e:#}` logs: every layer, root cause included. + assert!(chained.contains("send_waitlist_invite failed")); + assert!(chained.contains("parse To address")); + assert!( + chained.contains("invalid email address: a@b.com "), + "the root cause must survive into the log line, got {chained}" + ); + assert!( + !chained.contains('\n'), + "must stay single-line for the JSON log pipeline, got {chained}" + ); + } + /// Repro for the production failure: every waitlist invite/resend /// died with `parse To address`. /// diff --git a/crates/starstats-server/src/smtp_admin_routes.rs b/crates/starstats-server/src/smtp_admin_routes.rs index b433e17d..42af66d0 100644 --- a/crates/starstats-server/src/smtp_admin_routes.rs +++ b/crates/starstats-server/src/smtp_admin_routes.rs @@ -344,7 +344,7 @@ pub async fn test_smtp( // without it the user only sees the outermost wrap ("SMTP send // failed") and the actual cause (auth rejected, TLS handshake, // connection refused, …) is invisible. - tracing::warn!(error = ?e, "smtp test send failed"); + tracing::warn!(error = %format!("{e:#}"), "smtp test send failed"); return error( StatusCode::BAD_GATEWAY, "smtp_send_failed", diff --git a/crates/starstats-server/src/waitlist_routes.rs b/crates/starstats-server/src/waitlist_routes.rs index a7317171..69b51645 100644 --- a/crates/starstats-server/src/waitlist_routes.rs +++ b/crates/starstats-server/src/waitlist_routes.rs @@ -198,7 +198,7 @@ pub async fn join( // and the row looks perfectly admitted from the DB side. if let Err(e) = mailer.send_waitlist_invite(&req.email, invite_token).await { tracing::error!( - error = %e, + error = %format!("{e:#}"), email = %req.email, "waitlist invite send FAILED — admitted user has no link; re-admit from /admin/waitlist" ); @@ -331,7 +331,7 @@ pub async fn admin_admit( .await { tracing::error!( - error = %e, + error = %format!("{e:#}"), email = %inv.email, "waitlist invite send FAILED for an admitted user — they have no link" ); @@ -387,7 +387,7 @@ pub async fn admin_resend( .await { tracing::error!( - error = %e, + error = %format!("{e:#}"), email = %inv.email, "waitlist invite RESEND failed — the mail transport is still broken" );