[WEB-5225] feat: enhance authentication logging with detailed error and info message (#7998)

* feat: enhance authentication logging with detailed error and info messages

- Added logging for various authentication events in the Adapter and its subclasses, including email validation, user existence checks, and password strength validation.
- Implemented error handling for GitHub OAuth email retrieval, ensuring proper logging of unexpected responses and missing primary emails.
- Updated logging configuration in local and production settings to include a dedicated logger for authentication events.

* chore: address copilot comments

* chore: addressed some additional comments

* chore: update log

* fix: lint

apps/api/plane/api/views/project.py

@@ -23,7 +23,6 @@ from drf_spectacular.utils import OpenApiResponse, OpenApiRequest
 from plane.db.models import (
     Cycle,
     Intake,
-    ProjectUserProperty,
     Module,
     Project,
     DeployBoard,

apps/api/plane/authentication/adapter/base.py

@@ -3,29 +3,33 @@
 # See the LICENSE file for details.
 
 # Python imports
+import logging
 import os
 import uuid
-import requests
 from io import BytesIO
 
+import requests
+from django.conf import settings
+from django.core.exceptions import ValidationError
+from django.core.validators import validate_email
+
 # Django imports
 from django.utils import timezone
-from django.core.validators import validate_email
-from django.core.exceptions import ValidationError
-from django.conf import settings
 
 # Third party imports
 from zxcvbn import zxcvbn
 
-# Module imports
-from plane.db.models import Profile, User, WorkspaceMemberInvite, FileAsset
-from plane.license.utils.instance_value import get_configuration_value
-from .error import AuthenticationException, AUTHENTICATION_ERROR_CODES
 from plane.bgtasks.user_activation_email_task import user_activation_email
+
+# Module imports
+from plane.db.models import FileAsset, Profile, User, WorkspaceMemberInvite
+from plane.license.utils.instance_value import get_configuration_value
+from plane.settings.storage import S3Storage
+from plane.utils.exception_logger import log_exception
 from plane.utils.host import base_host
 from plane.utils.ip_address import get_client_ip
-from plane.utils.exception_logger import log_exception
+
-from plane.settings.storage import S3Storage
+from .error import AUTHENTICATION_ERROR_CODES, AuthenticationException
 
 
 class Adapter:
@@ -37,6 +41,7 @@ class Adapter:
         self.callback = callback
         self.token_data = None
         self.user_data = None
+        self.logger = logging.getLogger("plane.authentication")
 
     def get_user_token(self, data, headers=None):
         raise NotImplementedError
@@ -59,6 +64,7 @@ class Adapter:
     def sanitize_email(self, email):
         # Check if email is present
         if not email:
+            self.logger.error("Email is not present")
             raise AuthenticationException(
                 error_code=AUTHENTICATION_ERROR_CODES["INVALID_EMAIL"],
                 error_message="INVALID_EMAIL",
@@ -72,6 +78,7 @@ class Adapter:
         try:
             validate_email(email)
         except ValidationError:
+            self.logger.warning(f"Email is not valid: {email}")
             raise AuthenticationException(
                 error_code=AUTHENTICATION_ERROR_CODES["INVALID_EMAIL"],
                 error_message="INVALID_EMAIL",
@@ -84,6 +91,7 @@ class Adapter:
         """Validate password strength"""
         results = zxcvbn(self.code)
         if results["score"] < 3:
+            self.logger.warning("Password is not strong enough")
             raise AuthenticationException(
                 error_code=AUTHENTICATION_ERROR_CODES["PASSWORD_TOO_WEAK"],
                 error_message="PASSWORD_TOO_WEAK",
@@ -101,6 +109,7 @@ class Adapter:
 
         # Check if sign up is disabled and invite is present or not
         if ENABLE_SIGNUP == "0" and not WorkspaceMemberInvite.objects.filter(email=email).exists():
+            self.logger.warning("Sign up is disabled and invite is not present")
             # Raise exception
             raise AuthenticationException(
                 error_code=AUTHENTICATION_ERROR_CODES["SIGNUP_DISABLED"],

apps/api/plane/authentication/adapter/oauth.py

@@ -4,20 +4,21 @@
 
 # Python imports
 import requests
+from django.db import DatabaseError, IntegrityError
 
 # Django imports
 from django.utils import timezone
-from django.db import DatabaseError, IntegrityError
+
+from plane.authentication.adapter.error import (
+    AUTHENTICATION_ERROR_CODES,
+    AuthenticationException,
+)
 
 # Module imports
 from plane.db.models import Account
+from plane.utils.exception_logger import log_exception
 
 from .base import Adapter
-from plane.authentication.adapter.error import (
-    AuthenticationException,
-    AUTHENTICATION_ERROR_CODES,
-)
-from plane.utils.exception_logger import log_exception
 
 
 class OauthAdapter(Adapter):
@@ -78,6 +79,7 @@ class OauthAdapter(Adapter):
             response.raise_for_status()
             return response.json()
         except requests.RequestException:
+            self.logger.warning("Error getting user token")
             code = self.authentication_error_code()
             raise AuthenticationException(error_code=AUTHENTICATION_ERROR_CODES[code], error_message=str(code))
 
@@ -88,6 +90,12 @@ class OauthAdapter(Adapter):
             response.raise_for_status()
             return response.json()
         except requests.RequestException:
+            self.logger.warning(
+                "Error getting user response",
+                extra={
+                    "headers": headers,
+                },
+            )
             code = self.authentication_error_code()
             raise AuthenticationException(error_code=AUTHENTICATION_ERROR_CODES[code], error_message=str(code))
 

apps/api/plane/authentication/provider/credentials/email.py

@@ -7,11 +7,11 @@ import os
 
 # Module imports
 from plane.authentication.adapter.credential import CredentialAdapter
-from plane.db.models import User
 from plane.authentication.adapter.error import (
     AUTHENTICATION_ERROR_CODES,
     AuthenticationException,
 )
+from plane.db.models import User
 from plane.license.utils.instance_value import get_configuration_value
 
 
@@ -24,14 +24,12 @@ class EmailProvider(CredentialAdapter):
         self.code = code
         self.is_signup = is_signup
 
-        (ENABLE_EMAIL_PASSWORD,) = get_configuration_value(
+        (ENABLE_EMAIL_PASSWORD,) = get_configuration_value([
-            [
+            {
-                {
+                "key": "ENABLE_EMAIL_PASSWORD",
-                    "key": "ENABLE_EMAIL_PASSWORD",
+                "default": os.environ.get("ENABLE_EMAIL_PASSWORD"),
-                    "default": os.environ.get("ENABLE_EMAIL_PASSWORD"),
+            }
-                }
+        ])
-            ]
-        )
 
         if ENABLE_EMAIL_PASSWORD == "0":
             raise AuthenticationException(
@@ -43,29 +41,29 @@ class EmailProvider(CredentialAdapter):
         if self.is_signup:
             # Check if the user already exists
             if User.objects.filter(email=self.key).exists():
+                self.logger.warning("User already exists")
                 raise AuthenticationException(
                     error_message="USER_ALREADY_EXIST",
                     error_code=AUTHENTICATION_ERROR_CODES["USER_ALREADY_EXIST"],
                 )
 
-            super().set_user_data(
+            super().set_user_data({
-                {
+                "email": self.key,
-                    "email": self.key,
+                "user": {
-                    "user": {
+                    "avatar": "",
-                        "avatar": "",
+                    "first_name": "",
-                        "first_name": "",
+                    "last_name": "",
-                        "last_name": "",
+                    "provider_id": "",
-                        "provider_id": "",
+                    "is_password_autoset": False,
-                        "is_password_autoset": False,
+                },
-                    },
+            })
-                }
-            )
             return
         else:
             user = User.objects.filter(email=self.key).first()
 
             # User does not exists
             if not user:
+                self.logger.warning("User does not exist")
                 raise AuthenticationException(
                     error_message="USER_DOES_NOT_EXIST",
                     error_code=AUTHENTICATION_ERROR_CODES["USER_DOES_NOT_EXIST"],
@@ -74,6 +72,7 @@ class EmailProvider(CredentialAdapter):
 
             # Check user password
             if not user.check_password(self.code):
+                self.logger.warning("Authentication failed - invalid credentials")
                 raise AuthenticationException(
                     error_message=(
                         "AUTHENTICATION_FAILED_SIGN_UP" if self.is_signup else "AUTHENTICATION_FAILED_SIGN_IN"
@@ -84,16 +83,14 @@ class EmailProvider(CredentialAdapter):
                     payload={"email": self.key},
                 )
 
-            super().set_user_data(
+            super().set_user_data({
-                {
+                "email": self.key,
-                    "email": self.key,
+                "user": {
-                    "user": {
+                    "avatar": "",
-                        "avatar": "",
+                    "first_name": "",
-                        "first_name": "",
+                    "last_name": "",
-                        "last_name": "",
+                    "provider_id": "",
-                        "provider_id": "",
+                    "is_password_autoset": False,
-                        "is_password_autoset": False,
+                },
-                    },
+            })
-                }
-            )
             return

apps/api/plane/authentication/provider/oauth/github.py

@@ -10,13 +10,14 @@ from urllib.parse import urlencode
 import pytz
 import requests
 
+from plane.authentication.adapter.error import (
+    AUTHENTICATION_ERROR_CODES,
+    AuthenticationException,
+)
+
 # Module imports
 from plane.authentication.adapter.oauth import OauthAdapter
 from plane.license.utils.instance_value import get_configuration_value
-from plane.authentication.adapter.error import (
-    AuthenticationException,
-    AUTHENTICATION_ERROR_CODES,
-)
 
 
 class GitHubOAuthProvider(OauthAdapter):
@@ -30,22 +31,20 @@ class GitHubOAuthProvider(OauthAdapter):
     organization_scope = "read:org"
 
     def __init__(self, request, code=None, state=None, callback=None):
-        GITHUB_CLIENT_ID, GITHUB_CLIENT_SECRET, GITHUB_ORGANIZATION_ID = get_configuration_value(
+        GITHUB_CLIENT_ID, GITHUB_CLIENT_SECRET, GITHUB_ORGANIZATION_ID = get_configuration_value([
-            [
+            {
-                {
+                "key": "GITHUB_CLIENT_ID",
-                    "key": "GITHUB_CLIENT_ID",
+                "default": os.environ.get("GITHUB_CLIENT_ID"),
-                    "default": os.environ.get("GITHUB_CLIENT_ID"),
+            },
-                },
+            {
-                {
+                "key": "GITHUB_CLIENT_SECRET",
-                    "key": "GITHUB_CLIENT_SECRET",
+                "default": os.environ.get("GITHUB_CLIENT_SECRET"),
-                    "default": os.environ.get("GITHUB_CLIENT_SECRET"),
+            },
-                },
+            {
-                {
+                "key": "GITHUB_ORGANIZATION_ID",
-                    "key": "GITHUB_ORGANIZATION_ID",
+                "default": os.environ.get("GITHUB_ORGANIZATION_ID"),
-                    "default": os.environ.get("GITHUB_ORGANIZATION_ID"),
+            },
-                },
+        ])
-            ]
-        )
 
         if not (GITHUB_CLIENT_ID and GITHUB_CLIENT_SECRET):
             raise AuthenticationException(
@@ -90,32 +89,46 @@ class GitHubOAuthProvider(OauthAdapter):
             "redirect_uri": self.redirect_uri,
         }
         token_response = self.get_user_token(data=data, headers={"Accept": "application/json"})
-        super().set_token_data(
+        super().set_token_data({
-            {
+            "access_token": token_response.get("access_token"),
-                "access_token": token_response.get("access_token"),
+            "refresh_token": token_response.get("refresh_token", None),
-                "refresh_token": token_response.get("refresh_token", None),
+            "access_token_expired_at": (
-                "access_token_expired_at": (
+                datetime.fromtimestamp(token_response.get("expires_in"), tz=pytz.utc)
-                    datetime.fromtimestamp(token_response.get("expires_in"), tz=pytz.utc)
+                if token_response.get("expires_in")
-                    if token_response.get("expires_in")
+                else None
-                    else None
+            ),
-                ),
+            "refresh_token_expired_at": (
-                "refresh_token_expired_at": (
+                datetime.fromtimestamp(token_response.get("refresh_token_expired_at"), tz=pytz.utc)
-                    datetime.fromtimestamp(token_response.get("refresh_token_expired_at"), tz=pytz.utc)
+                if token_response.get("refresh_token_expired_at")
-                    if token_response.get("refresh_token_expired_at")
+                else None
-                    else None
+            ),
-                ),
+            "id_token": token_response.get("id_token", ""),
-                "id_token": token_response.get("id_token", ""),
+        })
-            }
-        )
 
     def __get_email(self, headers):
         try:
             # Github does not provide email in user response
             emails_url = "https://api.github.com/user/emails"
             emails_response = requests.get(emails_url, headers=headers).json()
+            # Ensure the response is a list before iterating
+            if not isinstance(emails_response, list):
+                self.logger.error("Unexpected response format from GitHub emails API")
+                raise AuthenticationException(
+                    error_code=AUTHENTICATION_ERROR_CODES["GITHUB_OAUTH_PROVIDER_ERROR"],
+                    error_message="GITHUB_OAUTH_PROVIDER_ERROR",
+                )
             email = next((email["email"] for email in emails_response if email["primary"]), None)
+            if not email:
+                self.logger.error("No primary email found for user")
+                raise AuthenticationException(
+                    error_code=AUTHENTICATION_ERROR_CODES["GITHUB_OAUTH_PROVIDER_ERROR"],
+                    error_message="GITHUB_OAUTH_PROVIDER_ERROR",
+                )
             return email
         except requests.RequestException:
+            self.logger.warning(
+                "Error getting email from GitHub",
+            )
             raise AuthenticationException(
                 error_code=AUTHENTICATION_ERROR_CODES["GITHUB_OAUTH_PROVIDER_ERROR"],
                 error_message="GITHUB_OAUTH_PROVIDER_ERROR",
@@ -138,22 +151,33 @@ class GitHubOAuthProvider(OauthAdapter):
 
         if self.organization_id:
             if not self.is_user_in_organization(user_info_response.get("login")):
+                self.logger.warning(
+                    "User is not in organization",
+                    extra={
+                        "organization_id": self.organization_id,
+                        "user_login": user_info_response.get("login"),
+                    },
+                )
                 raise AuthenticationException(
                     error_code=AUTHENTICATION_ERROR_CODES["GITHUB_USER_NOT_IN_ORG"],
                     error_message="GITHUB_USER_NOT_IN_ORG",
                 )
 
         email = self.__get_email(headers=headers)
-        super().set_user_data(
+        self.logger.debug(
-            {
+            "Email found",
+            extra={
                 "email": email,
-                "user": {
+            },
-                    "provider_id": user_info_response.get("id"),
-                    "email": email,
-                    "avatar": user_info_response.get("avatar_url"),
-                    "first_name": user_info_response.get("name"),
-                    "last_name": user_info_response.get("family_name"),
-                    "is_password_autoset": True,
-                },
-            }
         )
+        super().set_user_data({
+            "email": email,
+            "user": {
+                "provider_id": user_info_response.get("id"),
+                "email": email,
+                "avatar": user_info_response.get("avatar_url"),
+                "first_name": user_info_response.get("name"),
+                "last_name": user_info_response.get("family_name"),
+                "is_password_autoset": True,
+            },
+        })

apps/api/plane/db/models/estimate.py

@@ -3,7 +3,7 @@
 # See the LICENSE file for details.
 
 # Django imports
-from django.core.validators import MaxValueValidator, MinValueValidator
+from django.core.validators import MinValueValidator
 from django.db import models
 from django.db.models import Q
 

apps/api/plane/settings/local.py

@@ -80,6 +80,11 @@ LOGGING = {
             "handlers": ["console"],
             "propagate": False,
         },
+        "plane.authentication": {
+            "level": "INFO",
+            "handlers": ["console"],
+            "propagate": False,
+        },
         "plane.migrations": {
             "level": "INFO",
             "handlers": ["console"],

apps/api/plane/settings/production.py

@@ -90,6 +90,11 @@ LOGGING = {
             "handlers": ["console"],
             "propagate": False,
         },
+        "plane.authentication": {
+            "level": "DEBUG" if DEBUG else "INFO",
+            "handlers": ["console"],
+            "propagate": False,
+        },
         "plane.migrations": {
             "level": "DEBUG" if DEBUG else "INFO",
             "handlers": ["console"],