From a4e77d514bb99b46200517438f6bbc1d07957138 Mon Sep 17 00:00:00 2001
From: Mateusz Mandera <mateusz.mandera@zulip.com>
Date: Wed, 1 Sep 2021 20:17:33 +0200
Subject: [PATCH] auth: Log details of authentication attempts.

These details are useful to log. This only makes sense for some auth
backends, namely email and ldap backends, because other backends are
"external" in the sense that they happen at some external provider's
server (Google, SAML IdP etc.) so the failure also happens there and we
don't get useful information about what happened.
---
 zproject/backends.py            | 26 ++++++++++++++++++++++++++
 zproject/test_extra_settings.py |  1 +
 2 files changed, 27 insertions(+)

diff --git a/zproject/backends.py b/zproject/backends.py
index d8eff0f697..0d15933876 100644
--- a/zproject/backends.py
+++ b/zproject/backends.py
@@ -294,6 +294,30 @@ def rate_limit_auth(auth_func: AuthFuncT, *args: Any, **kwargs: Any) -> Optional
     return result
 
 
+@decorator
+def log_auth_attempts(auth_func: AuthFuncT, *args: Any, **kwargs: Any) -> Optional[UserProfile]:
+    result = auth_func(*args, **kwargs)
+
+    backend_instance = args[0]
+    request = args[1]
+    username = kwargs["username"]
+    realm = kwargs["realm"]
+    return_data = kwargs["return_data"]
+
+    ip_addr = request.META.get("REMOTE_ADDR")
+    outcome = "success" if result is not None else "failed"
+    backend_instance.logger.info(
+        "Authentication attempt from %s: subdomain=%s;username=%s;outcome=%s;return_data=%s",
+        ip_addr,
+        realm.subdomain,
+        username,
+        outcome,
+        return_data,
+    )
+
+    return result
+
+
 class ZulipAuthMixin:
     """This common mixin is used to override Django's default behavior for
     looking up a logged-in user by ID to use a version that fetches
@@ -371,6 +395,7 @@ class EmailAuthBackend(ZulipAuthMixin):
     name = "email"
 
     @rate_limit_auth
+    @log_auth_attempts
     def authenticate(
         self,
         request: HttpRequest,
@@ -779,6 +804,7 @@ class ZulipLDAPAuthBackend(ZulipLDAPAuthBackendBase):
     REALM_IS_NONE_ERROR = 1
 
     @rate_limit_auth
+    @log_auth_attempts
     def authenticate(
         self,
         request: Optional[HttpRequest] = None,
diff --git a/zproject/test_extra_settings.py b/zproject/test_extra_settings.py
index d1cc7b771b..4dbcac3227 100644
--- a/zproject/test_extra_settings.py
+++ b/zproject/test_extra_settings.py
@@ -136,6 +136,7 @@ if not PUPPETEER_TESTS:
 
     set_loglevel("zulip.requests", "CRITICAL")
     set_loglevel("zulip.management", "CRITICAL")
+    set_loglevel("zulip.auth", "WARNING")
     set_loglevel("django.request", "ERROR")
     set_loglevel("django_auth_ldap", "WARNING")
     set_loglevel("fakeldap", "ERROR")