Log auth details

onadata/apps/api/tests/viewsets/test_connect_viewset.py

@@ -422,8 +422,10 @@ def test_user_has_no_profile_bug(self):
         response = view(request)
         self.assertEqual(response.status_code, 200)
 
+    @patch("onadata.libs.authentication.report_exception")
+    @patch("onadata.libs.authentication.logger.debug")
     @patch("onadata.apps.api.tasks.send_account_lockout_email.apply_async")
-    def test_login_attempts(self, send_account_lockout_email):
+    def test_login_attempts(self, send_account_lockout_email, mock_logger, rpt_mock):
         view = ConnectViewSet.as_view(
             {"get": "list"}, authentication_classes=(DigestAuthentication,)
         )
@@ -442,7 +444,26 @@ def test_login_attempts(self, send_account_lockout_email):
             "after 9 more failed login attempts you'll have to "
             "wait 30 minutes before trying again.",
         )
+
+        # test logger
         request_ip = request.META.get("REMOTE_ADDR")
+        user_agent = request.META.get("HTTP_USER_AGENT", None)
+        self.assertTrue(mock_logger.called)
+        info_str = (
+            f"IP: {request_ip}, USERNAME: {self.user.username}, "
+            f"REMAINING_ATTEMPTS: 9, USER_AGENT: {user_agent}"
+        )
+        mock_logger.assert_called_once_with(info_str)
+
+        # test report exception
+        self.assertTrue(rpt_mock.called)
+        rpt_mock.assert_called_once_with(
+            "Authentication Failure",
+            "Invalid username/password. For security reasons, "
+            "after 9 more failed login attempts you'll have to "
+            "wait 30 minutes before trying again.",
+        )
+
         self.assertEqual(cache.get(safe_key(f"login_attempts-{request_ip}-bob")), 1)
 
         # cache value increments with subsequent attempts

onadata/libs/authentication.py

@@ -4,6 +4,8 @@
 """
 from __future__ import unicode_literals
 
+import logging
+
 from datetime import datetime
 from typing import Optional, Tuple
 
@@ -35,8 +37,12 @@
 from onadata.apps.api.tasks import send_account_lockout_email
 from onadata.libs.utils.cache_tools import LOCKOUT_IP, LOGIN_ATTEMPTS, cache, safe_key
 from onadata.libs.utils.common_tags import API_TOKEN
+from onadata.libs.utils.common_tools import report_exception
 from onadata.libs.utils.email import get_account_lockout_email_data
 
+logger = logging.getLogger(__name__)
+logger.setLevel(logging.DEBUG)
+
 ENKETO_AUTH_COOKIE = getattr(settings, "ENKETO_AUTH_COOKIE", "__enketo")
 TEMP_TOKEN_EXPIRY_TIME = getattr(
     settings, "DEFAULT_TEMP_TOKEN_EXPIRY_TIME", 60 * 60 * 6
@@ -114,14 +120,23 @@ def authenticate(self, request):
             remaining_attempts = getattr(settings, "MAX_LOGIN_ATTEMPTS", 10) - attempts
             # pylint: disable=unused-variable
             lockout_time = getattr(settings, "LOCKOUT_TIME", 1800) // 60  # noqa
-            raise AuthenticationFailed(
-                _(
-                    "Invalid username/password. "
-                    f"For security reasons, after {remaining_attempts} more failed "
-                    f"login attempts you'll have to wait {lockout_time} minutes "
-                    "before trying again."
-                )
+            ip_address, username = retrieve_user_identification(request)
+            user_agent = request.META.get("HTTP_USER_AGENT", None)
+            info_str = (
+                f"IP: {ip_address}, USERNAME: {username}, "
+                f"REMAINING_ATTEMPTS: {remaining_attempts}, USER_AGENT: {user_agent}"
             )
+            logger.debug(info_str)
+            error_str = _(
+                "Invalid username/password. "
+                f"For security reasons, after {remaining_attempts} more failed "
+                f"login attempts you'll have to wait {lockout_time} minutes "
+                "before trying again."
+            )
+            # log to sentry
+            report_exception("Authentication Failure", error_str)
+            raise AuthenticationFailed(error_str)
+
         except (AttributeError, ValueError, DataError) as e:
             raise AuthenticationFailed(e) from e
 

onadata/settings/common.py

@@ -407,6 +407,14 @@ def skip_suspicious_operations(record):
             "formatter": "verbose",
             "model": "onadata.apps.main.models.audit.AuditLog",
         },
+        "file": {
+            "class": "logging.handlers.RotatingFileHandler",
+            "filename": "auth_debug.log",
+            "backupCount": 5,  # Number of backup files to keep
+            "maxBytes": 1024 * 1024 * 5,  # 5MB
+            "formatter": "profiler",
+            "level": "DEBUG",
+        }
         # 'sql_handler': {
         #     'level': 'DEBUG',
         #     'class': 'logging.StreamHandler',
@@ -421,6 +429,11 @@ def skip_suspicious_operations(record):
         # }
     },
     "loggers": {
+        "onadata.libs.authentication": {
+            "handlers": ["file"],
+            "level": "DEBUG",
+            "propagate": True,
+        },
         "django.request": {
             "handlers": ["mail_admins", "console"],
             "level": "DEBUG",