From de3fca35be49ede7c8c910dd7e6395ec1f8019ad Mon Sep 17 00:00:00 2001
From: Nimisha Asthagiri <nasthagiri@edx.org>
Date: Wed, 2 Mar 2016 14:22:30 -0500
Subject: [PATCH] Quiet the safe sessions logging for expected use case

---
 openedx/core/djangoapps/safe_sessions/middleware.py       | 8 ++++++--
 .../djangoapps/safe_sessions/tests/test_middleware.py     | 4 ++--
 .../safe_sessions/tests/test_safe_cookie_data.py          | 2 +-
 openedx/core/djangoapps/safe_sessions/tests/test_utils.py | 4 ++--
 4 files changed, 11 insertions(+), 7 deletions(-)

diff --git a/openedx/core/djangoapps/safe_sessions/middleware.py b/openedx/core/djangoapps/safe_sessions/middleware.py
index 3ab31a6407..6285167d57 100644
--- a/openedx/core/djangoapps/safe_sessions/middleware.py
+++ b/openedx/core/djangoapps/safe_sessions/middleware.py
@@ -223,7 +223,7 @@ class SafeCookieData(object):
             # 3rd party Auth and external Auth transactions
             # as some of the session requests are made as
             # Anonymous users.
-            log.warning(
+            log.debug(
                 "SafeCookieData received empty user_id '%s' for session_id '%s'.",
                 user_id,
                 session_id,
@@ -360,7 +360,11 @@ class SafeSessionMiddleware(SessionMiddleware):
         """
         if hasattr(request, 'safe_cookie_verified_user_id'):
             if request.safe_cookie_verified_user_id != request.user.id:
-                log.warning(
+                # The user at response time is expected to be None when the user
+                # is logging out. To prevent extra noise in the logs,
+                # conditionally set the log level.
+                log_func = log.debug if request.user.id is None else log.warning
+                log_func(
                     "SafeCookieData user at request '{0}' does not match user at response: '{1}'".format(  # pylint: disable=logging-format-interpolation
                         request.safe_cookie_verified_user_id,
                         request.user.id,
diff --git a/openedx/core/djangoapps/safe_sessions/tests/test_middleware.py b/openedx/core/djangoapps/safe_sessions/tests/test_middleware.py
index d39cd31c5f..0aee5ab904 100644
--- a/openedx/core/djangoapps/safe_sessions/tests/test_middleware.py
+++ b/openedx/core/djangoapps/safe_sessions/tests/test_middleware.py
@@ -193,7 +193,7 @@ class TestSafeSessionProcessResponse(TestSafeSessionsLogMixin, TestCase):
     def test_different_user_at_step_2_error(self):
         self.request.safe_cookie_verified_user_id = "different_user"
 
-        with self.assert_logged_for_request_user_mismatch("different_user", self.user.id):
+        with self.assert_logged_for_request_user_mismatch("different_user", self.user.id, 'warning'):
             self.assert_response(set_request_user=True, set_session_cookie=True)
 
         with self.assert_logged_for_session_user_mismatch("different_user", self.user.id):
@@ -204,7 +204,7 @@ class TestSafeSessionProcessResponse(TestSafeSessionsLogMixin, TestCase):
         self.request.user = AnonymousUser()
         self.request.session[SESSION_KEY] = self.user.id
         with self.assert_no_error_logged():
-            with self.assert_logged_for_request_user_mismatch(self.user.id, None):
+            with self.assert_logged_for_request_user_mismatch(self.user.id, None, 'debug'):
                 self.assert_response(set_request_user=False, set_session_cookie=True)
 
     def test_update_cookie_data_at_step_3(self):
diff --git a/openedx/core/djangoapps/safe_sessions/tests/test_safe_cookie_data.py b/openedx/core/djangoapps/safe_sessions/tests/test_safe_cookie_data.py
index f1220b69d7..468d9c09b0 100644
--- a/openedx/core/djangoapps/safe_sessions/tests/test_safe_cookie_data.py
+++ b/openedx/core/djangoapps/safe_sessions/tests/test_safe_cookie_data.py
@@ -102,7 +102,7 @@ class TestSafeCookieData(TestSafeSessionsLogMixin, TestCase):
 
     @ddt.data(None, '')
     def test_create_no_user_id(self, user_id):
-        with self.assert_logged('SafeCookieData received empty user_id', 'warning'):
+        with self.assert_logged('SafeCookieData received empty user_id', 'debug'):
             safe_cookie_data = SafeCookieData.create(self.session_id, user_id)
             self.assertTrue(safe_cookie_data.verify(user_id))
 
diff --git a/openedx/core/djangoapps/safe_sessions/tests/test_utils.py b/openedx/core/djangoapps/safe_sessions/tests/test_utils.py
index 4a41011fb3..4dca196cea 100644
--- a/openedx/core/djangoapps/safe_sessions/tests/test_utils.py
+++ b/openedx/core/djangoapps/safe_sessions/tests/test_utils.py
@@ -114,7 +114,7 @@ class TestSafeSessionsLogMixin(object):
             yield
 
     @contextmanager
-    def assert_logged_for_request_user_mismatch(self, user_at_request, user_at_response):
+    def assert_logged_for_request_user_mismatch(self, user_at_request, user_at_response, log_level):
         """
         Asserts that warning was logged when request.user
         was not equal to user at response
@@ -123,7 +123,7 @@ class TestSafeSessionsLogMixin(object):
             "SafeCookieData user at request '{}' does not match user at response: '{}'".format(
                 user_at_request, user_at_response
             ),
-            log_level='warning',
+            log_level=log_level,
         ):
             yield