diff --git a/zerver/tests/test_auth_backends.py b/zerver/tests/test_auth_backends.py index 6d7f9f44db..f55f0ce31d 100644 --- a/zerver/tests/test_auth_backends.py +++ b/zerver/tests/test_auth_backends.py @@ -547,6 +547,11 @@ class AuthBackendTest(ZulipTestCase): backend.strategy.request_data = return_email + if request is None: + request = mock.MagicMock() + request.META = dict(REMOTE_ADDR="127.0.0.1") + backend.strategy.request = request + result = orig_authenticate(backend, request, **kwargs) return result @@ -594,7 +599,12 @@ class AuthBackendTest(ZulipTestCase): self.verify_backend(backend, good_kwargs=good_kwargs, bad_kwargs=bad_kwargs) # Verify logging for deactivated users self.assertEqual( - info_log.output, + # Filter out noisy logs: + [ + output + for output in info_log.output + if "Authentication attempt from 127.0.0.1" not in output + ], [ f"INFO:{logger_name}:Failed login attempt for deactivated account: {user.id}@{user.realm.string_id}", f"INFO:{logger_name}:Failed login attempt for deactivated account: {user.id}@{user.realm.string_id}", @@ -1054,12 +1064,13 @@ class SocialAuthBase(DesktopFlowTestingLib, ZulipTestCase): def test_social_auth_success(self) -> None: account_data_dict = self.get_account_data_dict(email=self.email, name=self.name) - result = self.social_auth_test( - account_data_dict, - expect_choose_email_screen=False, - subdomain="zulip", - next="/user_uploads/image", - ) + with self.assertLogs(self.logger_string, level="INFO") as m: + result = self.social_auth_test( + account_data_dict, + expect_choose_email_screen=False, + subdomain="zulip", + next="/user_uploads/image", + ) data = load_subdomain_token(result) self.assertEqual(data["email"], self.example_email("hamlet")) self.assertEqual(data["full_name"], self.name) @@ -1070,6 +1081,11 @@ class SocialAuthBase(DesktopFlowTestingLib, ZulipTestCase): uri = f"{parsed_url.scheme}://{parsed_url.netloc}{parsed_url.path}" self.assertTrue(uri.startswith("http://zulip.testserver/accounts/login/subdomain/")) + self.assertIn( + f"INFO:{self.logger_string}:Authentication attempt from 127.0.0.1: subdomain=zulip;username=hamlet@zulip.com;outcome=success", + m.output[0], + ) + @override_settings(SOCIAL_AUTH_SUBDOMAIN=None) def test_when_social_auth_subdomain_is_not_set(self) -> None: account_data_dict = self.get_account_data_dict(email=self.email, name=self.name) diff --git a/zproject/backends.py b/zproject/backends.py index 0d15933876..0082169e13 100644 --- a/zproject/backends.py +++ b/zproject/backends.py @@ -304,9 +304,29 @@ def log_auth_attempts(auth_func: AuthFuncT, *args: Any, **kwargs: Any) -> Option realm = kwargs["realm"] return_data = kwargs["return_data"] + log_auth_attempt( + backend_instance.logger, + request, + realm, + username, + succeeded=result is not None, + return_data=return_data, + ) + + return result + + +def log_auth_attempt( + logger: logging.Logger, + request: HttpRequest, + realm: Realm, + username: str, + succeeded: bool, + return_data: Dict[str, Any], +) -> None: ip_addr = request.META.get("REMOTE_ADDR") - outcome = "success" if result is not None else "failed" - backend_instance.logger.info( + outcome = "success" if succeeded else "failed" + logger.info( "Authentication attempt from %s: subdomain=%s;username=%s;outcome=%s;return_data=%s", ip_addr, realm.subdomain, @@ -315,8 +335,6 @@ def log_auth_attempts(auth_func: AuthFuncT, *args: Any, **kwargs: Any) -> Option return_data, ) - return result - class ZulipAuthMixin: """This common mixin is used to override Django's default behavior for @@ -1661,6 +1679,18 @@ def social_auth_finish( # The next step is to call login_or_register_remote_user, but # there are two code paths here because of an optimization to save # a redirect on mobile and desktop. + + # Authentication failures happen on the external provider's side, so we don't get to log those, + # but we should log the successes at least. + log_auth_attempt( + backend.logger, + strategy.request, + realm, + username=email_address, + succeeded=True, + return_data={}, + ) + data_dict = ExternalAuthDataDict( subdomain=realm.subdomain, is_signup=is_signup,