Fix - Bypass unnecessary logs on logging out.

common/djangoapps/student/views.py

@@ -1341,6 +1341,7 @@ def logout_user(request):
     """
     # We do not log here, because we have a handler registered
     # to perform logging on successful logouts.
+    request.is_from_logout = True
     logout(request)
     if settings.FEATURES.get('AUTH_USE_CAS'):
         target = reverse('cas-logout')

lms/djangoapps/courseware/tests/tests.py

@@ -39,6 +39,14 @@ def test_logout(self):
         """
         self.logout()
 
+    def test_request_attr_on_logout(self):
+        """
+        Test request object after logging out to see whether it
+        has 'is_from_log_out' attribute set to true.
+        """
+        response = self.client.get(reverse('logout'))
+        self.assertTrue(getattr(response.wsgi_request, 'is_from_logout', False))  # pylint: disable=no-member
+
 
 class PageLoaderTestCase(LoginEnrollmentTestCase):
     """

openedx/core/djangoapps/safe_sessions/middleware.py

@@ -56,6 +56,7 @@
 
 """
 
+from contextlib import contextmanager
 from django.conf import settings
 from django.contrib.auth import SESSION_KEY
 from django.contrib.auth.views import redirect_to_login
@@ -64,7 +65,7 @@
 from django.http import HttpResponse
 from django.utils.crypto import get_random_string
 from hashlib import sha256
-from logging import getLogger
+from logging import getLogger, ERROR
 
 from openedx.core.lib.mobile_utils import is_request_from_mobile_app
 
@@ -318,12 +319,13 @@ def process_response(self, request, response):
         if not _is_cookie_marked_for_deletion(request) and _is_cookie_present(response):
             try:
                 user_id_in_session = self.get_user_id_from_session(request)
-                self._verify_user(request, user_id_in_session)  # Step 2
+                with controlled_logging(request, log):
+                    self._verify_user(request, user_id_in_session)  # Step 2
 
-                # Use the user_id marked in the session instead of the
-                # one in the request in case the user is not set in the
-                # request, for example during Anonymous API access.
-                self.update_with_safe_session_cookie(response.cookies, user_id_in_session)  # Step 3
+                    # Use the user_id marked in the session instead of the
+                    # one in the request in case the user is not set in the
+                    # request, for example during Anonymous API access.
+                    self.update_with_safe_session_cookie(response.cookies, user_id_in_session)  # Step 3
 
             except SafeCookieError:
                 _mark_cookie_for_deletion(request)
@@ -365,7 +367,7 @@ def _verify_user(request, userid_in_session):
                     ),
                 )
             if request.safe_cookie_verified_user_id != userid_in_session:
-                log.error(
+                log.warning(
                     "SafeCookieData user at request '{0}' does not match user in session: '{1}'".format(  # pylint: disable=logging-format-interpolation
                         request.safe_cookie_verified_user_id,
                         userid_in_session,
@@ -459,3 +461,31 @@ def _delete_cookie(response):
         secure=settings.SESSION_COOKIE_SECURE or None,
         httponly=settings.SESSION_COOKIE_HTTPONLY or None,
     )
+
+
+def _is_from_logout(request):
+    """
+    Returns whether the request has come from logout action to see if
+    'is_from_logout' attribute is present.
+    """
+    return getattr(request, 'is_from_logout', False)
+
+
+@contextmanager
+def controlled_logging(request, logger):
+    """
+    Control the logging by changing logger's level if
+    the request is from logout.
+    """
+    default_level = None
+    from_logout = _is_from_logout(request)
+    if from_logout:
+        default_level = logger.getEffectiveLevel()
+        logger.setLevel(ERROR)
+
+    try:
+        yield
+
+    finally:
+        if from_logout:
+            logger.setLevel(default_level)

openedx/core/djangoapps/safe_sessions/tests/test_middleware.py

@@ -192,16 +192,19 @@ def test_confirm_user_at_step_2(self):
 
     def test_different_user_at_step_2_error(self):
         self.request.safe_cookie_verified_user_id = "different_user"
-        with self.assert_request_user_mismatch("different_user", self.user.id):
-            with self.assert_session_user_mismatch("different_user", self.user.id):
-                self.assert_response(set_request_user=True, set_session_cookie=True)
+
+        with self.assert_logged_for_request_user_mismatch("different_user", self.user.id):
+            self.assert_response(set_request_user=True, set_session_cookie=True)
+
+        with self.assert_logged_for_session_user_mismatch("different_user", self.user.id):
+            self.assert_response(set_request_user=True, set_session_cookie=True)
 
     def test_anonymous_user(self):
         self.request.safe_cookie_verified_user_id = self.user.id
         self.request.user = AnonymousUser()
         self.request.session[SESSION_KEY] = self.user.id
         with self.assert_no_error_logged():
-            with self.assert_request_user_mismatch(self.user.id, None):
+            with self.assert_logged_for_request_user_mismatch(self.user.id, None):
                 self.assert_response(set_request_user=False, set_session_cookie=True)
 
     def test_update_cookie_data_at_step_3(self):

openedx/core/djangoapps/safe_sessions/tests/test_utils.py

@@ -22,6 +22,16 @@ def assert_logged(self, log_string, log_level='error'):
             self.assertTrue(mock_log.called)
             self.assertRegexpMatches(mock_log.call_args_list[0][0][0], log_string)
 
+    @contextmanager
+    def assert_logged_with_message(self, log_string, log_level='error'):
+        """
+        Asserts that the logger with the given log_level was called
+        with a string.
+        """
+        with patch('openedx.core.djangoapps.safe_sessions.middleware.log.' + log_level) as mock_log:
+            yield
+            mock_log.assert_any_call(log_string)
+
     @contextmanager
     def assert_not_logged(self):
         """
@@ -104,12 +114,12 @@ def assert_invalid_session_id(self):
             yield
 
     @contextmanager
-    def assert_request_user_mismatch(self, user_at_request, user_at_response):
+    def assert_logged_for_request_user_mismatch(self, user_at_request, user_at_response):
         """
-        Asserts that the logger was called when request.user at request
-        time doesn't match the request.user at response time.
+        Asserts that warning was logged when request.user
+        was not equal to user at response
         """
-        with self.assert_logged(
+        with self.assert_logged_with_message(
             "SafeCookieData user at request '{}' does not match user at response: '{}'".format(
                 user_at_request, user_at_response
             ),
@@ -118,14 +128,15 @@ def assert_request_user_mismatch(self, user_at_request, user_at_response):
             yield
 
     @contextmanager
-    def assert_session_user_mismatch(self, user_at_request, user_in_session):
+    def assert_logged_for_session_user_mismatch(self, user_at_request, user_in_session):
         """
-        Asserts that the logger was called when request.user at request
-        time doesn't match the request.user at response time.
+        Asserts that warning was logged when request.user
+        was not equal to user at session
         """
-        with self.assert_logged(
+        with self.assert_logged_with_message(
             "SafeCookieData user at request '{}' does not match user in session: '{}'".format(
                 user_at_request, user_in_session
             ),
+            log_level='warning',
         ):
             yield