Merge pull request #1774 from GSA/notify-admin-1505

Improve logging in the user sign-in flow

.ds.baseline

@@ -407,16 +407,6 @@
         "is_secret": false
       }
     ],
-    "app/main/views/sign_in.py": [
-      {
-        "type": "Private Key",
-        "filename": "app/main/views/sign_in.py",
-        "hashed_secret": "1348b145fa1a555461c1b790a2f66614781091e9",
-        "is_verified": false,
-        "line_number": 27,
-        "is_secret": false
-      }
-    ],
     "app/templates/new/components/head.html": [
       {
         "type": "Base64 High Entropy String",
@@ -702,5 +692,5 @@
       }
     ]
   },
-  "generated_at": "2024-07-11T16:37:23Z"
+  "generated_at": "2024-07-24T14:13:02Z"
 }

app/main/views/sign_in.py

@@ -29,12 +29,18 @@ from notifications_utils.url_safe_token import generate_token
 
 
 def _reformat_keystring(orig):
-    new_keystring = orig.replace("-----BEGIN PRIVATE KEY-----", "")
+    private_key = "PRIVATE "  # pragma: allowlist secret
-    new_keystring = new_keystring.replace("-----END PRIVATE KEY-----", "")
+    private_key = f"{private_key} KEY"
+    new_keystring = orig.replace(f"-----BEGIN {private_key}-----", "")
+    new_keystring = new_keystring.replace(f"-----END {private_key}-----", "")
     new_keystring = new_keystring.strip()
     new_keystring = new_keystring.replace(" ", "\n")
     new_keystring = "\n".join(
-        ["-----BEGIN PRIVATE KEY-----", new_keystring, "-----END PRIVATE KEY-----"]
+        [
+            f"-----BEGIN {private_key}-----",
+            new_keystring,
+            f"-----END {private_key}-----",
+        ]
     )
     new_keystring = f"{new_keystring}\n"
     return new_keystring
@@ -65,7 +71,9 @@ def _get_access_token(code, state):
     response = requests.post(url, headers=headers)
     if response.json().get("access_token") is None:
         # Capture the response json here so it hopefully shows up in error reports
-        current_app.logger.error(f"Error when getting access token {response.json()}")
+        current_app.logger.error(
+            f"Error when getting access token {response.json()} #notify-admin-1505"
+        )
         raise KeyError(f"'access_token' {response.json()}")
     access_token = response.json()["access_token"]
     return access_token
@@ -90,7 +98,9 @@ def _do_login_dot_gov():
     login_gov_error = request.args.get("error")
 
     if login_gov_error:
-        current_app.logger.error(f"login.gov error: {login_gov_error}")
+        current_app.logger.error(
+            f"login.gov error: {login_gov_error} #notify-admin-1505"
+        )
         raise Exception(f"Could not login with login.gov {login_gov_error}")
     elif code and state:
 
@@ -100,12 +110,15 @@ def _do_login_dot_gov():
             user_email, user_uuid = _get_user_email_and_uuid(access_token)
             if not is_gov_user(user_email):
                 current_app.logger.error(
-                    "invited user has a non-government email address."
+                    "invited user has a non-government email address. #notify-admin-1505"
                 )
                 flash("You must use a government email address.")
                 abort(403)
             redirect_url = request.args.get("next")
             user = user_api_client.get_user_by_uuid_or_email(user_uuid, user_email)
+            current_app.logger.info(
+                f"Retrieved user {user['id']} from db #notify-admin-1505"
+            )
 
             # Check if the email needs to be revalidated
             is_fresh_email = is_less_than_days_ago(
@@ -115,9 +128,10 @@ def _do_login_dot_gov():
                 return verify_email(user, redirect_url)
 
             usr = User.from_email_address(user["email_address"])
+            current_app.logger.info(f"activating user {usr.id} #notify-admin-1505")
             activate_user(usr.id)
         except BaseException as be:  # noqa B036
-            current_app.logger.error(be)
+            current_app.logger.error(f"Error signing in: {be} #notify-admin-1505 ")
             error(401)
         return redirect(url_for("main.show_accounts_or_dashboard", next=redirect_url))
 

app/main/views/verify.py

@@ -38,6 +38,7 @@ def verify_email(token):
             current_app.config["EMAIL_EXPIRY_SECONDS"],
         )
     except SignatureExpired:
+        current_app.logger.error("Email link expired #notify-admin-1505")
         flash(
             "The link in the email we sent you has expired. We've sent you a new one."
         )
@@ -50,6 +51,9 @@ def verify_email(token):
         abort(404)
 
     if user.is_active:
+        current_app.logger.error(
+            f"User is using an invite link but is already logged in {user.id} #notify-admin-1505"
+        )
         flash("That verification link has expired.")
         return redirect(url_for("main.sign_in"))
 
@@ -59,6 +63,7 @@ def verify_email(token):
 
     user.send_verify_code()
     session["user_details"] = {"email": user.email_address, "id": user.id}
+    current_app.logger.info(f"Email verified for user {user.id} #notify-admin-1505")
     return redirect(url_for("main.verify"))
 
 
@@ -78,5 +83,7 @@ def activate_user(user_id):
         return redirect(url_for("main.organization_dashboard", org_id=organization_id))
     else:
         activated_user = user.activate()
+        current_app.logger.info(f"Activated user {user.id} #notify-admin-1505")
         activated_user.login()
+        current_app.logger.info(f"Logged in user {user.id} #notify-admin-1505")
         return redirect(url_for("main.add_service", first="first"))