From bd81ccfc6b7195bbcf2a0d77d5ad64771c2cd45f Mon Sep 17 00:00:00 2001
From: Andrew <mcdeweykp@gmail.com>
Date: Sun, 21 Sep 2025 15:58:33 -0400
Subject: [PATCH 1/2] Add debug logging to help troubleshoot MFA issues

---
 app/classes/controllers/totp_controller.py | 10 ++++++++++
 1 file changed, 10 insertions(+)

diff --git a/app/classes/controllers/totp_controller.py b/app/classes/controllers/totp_controller.py
index 8aa807ee..3dfd76cf 100644
--- a/app/classes/controllers/totp_controller.py
+++ b/app/classes/controllers/totp_controller.py
@@ -62,11 +62,14 @@ class TOTPController:
             _type_: _description_
         """
         user = HelperUsers.get_by_id(user_id)
+        logger.debug("Validating TOTP entry for user %s", user.username)
         authenticated = False
         # Iterate through just in case a user has multiple 2FA methods
         now = datetime.now(tz=timezone.utc)
+        logger.debug("TOTP sequence: current time is %s", now)
 
         # Check to see if someone is trying to reuse a key in the 60 second window
+        logger.debug("TOTP sequence: checking for reused code.")
         if str(user_id) in self.used_totp_codes:
             if str(totp_code) in self.used_totp_codes[
                 str(user_id)
@@ -78,14 +81,17 @@ class TOTPController:
                 )
                 return authenticated
         else:
+            logger.debug("TOTP sequence: No previous code dict found. Creating one")
             self.used_totp_codes[str(user_id)] = {}  # Init empty dict if not in there
 
+        logger.debug("TOTP sequence: reused code check passed. Validating user code")
         # Store OTP as used for 60 seconds
         self.used_totp_codes[str(user_id)][str(totp_code)] = now
 
         self.clear_stale_entries()
 
         for totp in user.totp_user:
+            logger.debug("TOTP sequence: Starting TOTP factory initialization")
             totp_factory = pyotp.TOTP(totp.totp_secret)
             if totp_factory.verify(
                 totp_code,
@@ -94,15 +100,19 @@ class TOTPController:
             ):
                 logger.info("Successfully verified user MFA %s", user_id)
                 authenticated = True
+        if not authenticated:
+            logger.error("TOTP sequence: Code validation failed. Code is not valid.")
         return authenticated
 
     def clear_stale_entries(self):
         """clears out totp codes older than 1 minute when one is sent"""
         now = datetime.now(tz=timezone.utc)
         # Clean up expired entries reclaim some memory
+        logger.debug("Checking for used codes entries older than 1 minute")
         for key, totp_dict in self.used_totp_codes.items():
             for item, timestamp in totp_dict.items():
                 if now - timestamp > timedelta(seconds=60):
+                    logger.debug("Found saved code older than one minute. Deleting...")
                     # needs to ref the self var to remove expired entries
                     del self.used_totp_codes[  # pylint: disable=unnecessary-dict-index-lookup
                         key
-- 
GitLab


From 993ad409d6bb0b0f0c3bcd6062222fb63b441809 Mon Sep 17 00:00:00 2001
From: Zedifus <zedifus@zediverse.gg>
Date: Tue, 7 Oct 2025 01:10:09 +0100
Subject: [PATCH 2/2] Upgrade changelog !898

---
 CHANGELOG.md | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/CHANGELOG.md b/CHANGELOG.md
index 321e802a..562caf6d 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -6,7 +6,7 @@ TBD
 - Fix MFA login failure when the totp `dict`'s attempted codes list changes size while being processed ([Merge Request](https://gitlab.com/crafty-controller/crafty-4/-/merge_requests/899))
 - Resolve additional json being appended to downloaded files ([Merge Request](https://gitlab.com/crafty-controller/crafty-4/-/merge_requests/902))
 ### Tweaks
-TBD
+- Add extended debug logging to help troubleshoot MFA issues ([Merge Request](https://gitlab.com/crafty-controller/crafty-4/-/merge_requests/898))
 ### Lang
 TBD
 <br><br>
-- 
GitLab