Add logging when user fails to verify password

We currently alert if we see too many errors, so we should write to the
logs what is going on.

Author: erikjohnston

crates/data-model/src/users.rs

@@ -4,7 +4,7 @@
 // SPDX-License-Identifier: AGPL-3.0-only OR LicenseRef-Element-Commercial
 // Please see LICENSE files in the repository root for full details.
 
-use std::net::IpAddr;
+use std::{fmt::Display, net::IpAddr};
 
 use chrono::{DateTime, Utc};
 use rand::Rng;
@@ -47,6 +47,14 @@ impl User {
     }
 }
 
+impl Display for User {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        // Format the user as their username, this is useful for logging and
+        // debugging.
+        self.username.fmt(f)
+    }
+}
+
 #[derive(Debug, Clone, PartialEq, Eq, Serialize)]
 pub struct Password {
     pub id: Ulid,

crates/handlers/src/views/login.rs

@@ -166,6 +166,7 @@ pub(crate) async fn post(
     }
 
     if !form_state.is_valid() {
+        tracing::warn!("Invalid login form: {form_state:?}");
         PASSWORD_LOGIN_COUNTER.add(1, &[KeyValue::new(RESULT, "error")]);
         return render(
             locale,
@@ -189,6 +190,7 @@ pub(crate) async fn post(
     // First, lookup the user
     let Some(user) = get_user_by_email_or_by_username(site_config, &mut repo, username).await?
     else {
+        tracing::warn!("User not found: {username}");
         let form_state = form_state.with_error_on_form(FormError::InvalidCredentials);
         PASSWORD_LOGIN_COUNTER.add(1, &[KeyValue::new(RESULT, "error")]);
         return render(
@@ -228,6 +230,7 @@ pub(crate) async fn post(
     let Some(user_password) = repo.user_password().active(&user).await? else {
         // There is no password for this user, but we don't want to disclose that. Show
         // a generic 'invalid credentials' error instead
+        tracing::warn!("No password for user: {user}");
         let form_state = form_state.with_error_on_form(FormError::InvalidCredentials);
         PASSWORD_LOGIN_COUNTER.add(1, &[KeyValue::new(RESULT, "error")]);
         return render(
@@ -271,6 +274,7 @@ pub(crate) async fn post(
         }
         Ok(None) => user_password,
         Err(_) => {
+            tracing::warn!("Failed to verify/upgrade password for user: {user}");
             let form_state = form_state.with_error_on_form(FormError::InvalidCredentials);
             PASSWORD_LOGIN_COUNTER.add(1, &[KeyValue::new(RESULT, "error")]);
             return render(
@@ -291,6 +295,7 @@ pub(crate) async fn post(
     // Now that we have checked the user password, we now want to show an error if
     // the user is locked or deactivated
     if user.deactivated_at.is_some() {
+        tracing::warn!("User is deactivated: {user}");
         PASSWORD_LOGIN_COUNTER.add(1, &[KeyValue::new(RESULT, "error")]);
         let (csrf_token, cookie_jar) = cookie_jar.csrf_token(&clock, &mut rng);
         let ctx = AccountInactiveContext::new(user)
@@ -301,6 +306,7 @@ pub(crate) async fn post(
     }
 
     if user.locked_at.is_some() {
+        tracing::warn!("User is locked: {user}");
         PASSWORD_LOGIN_COUNTER.add(1, &[KeyValue::new(RESULT, "error")]);
         let (csrf_token, cookie_jar) = cookie_jar.csrf_token(&clock, &mut rng);
         let ctx = AccountInactiveContext::new(user)