From 416407fd736f2e8a5e6963c5ec512079ba79c22d Mon Sep 17 00:00:00 2001
From: Feanil Patel <feanil@edx.org>
Date: Thu, 18 Mar 2021 10:31:49 -0400
Subject: [PATCH] fix: Add more info in warning log messages.
If this happens, it's usefule to know what main view code was being
targetd so that we can more easily investigate what might have caused
this issue.
Add a new custom attribute 'safe_sessions.user_mismatch' to find
requests that had this issue in our monitoring system.
---
.../djangoapps/safe_sessions/middleware.py | 23 ++++++++++++++-----
.../safe_sessions/tests/test_middleware.py | 6 ++---
.../safe_sessions/tests/test_utils.py | 18 ++++++++++-----
3 files changed, 32 insertions(+), 15 deletions(-)
diff --git a/openedx/core/djangoapps/safe_sessions/middleware.py b/openedx/core/djangoapps/safe_sessions/middleware.py
index 612ae6e6f10..ddd21dfb428 100644
--- a/openedx/core/djangoapps/safe_sessions/middleware.py
+++ b/openedx/core/djangoapps/safe_sessions/middleware.py
@@ -54,6 +54,10 @@ to the browser that the cookie should be sent only over an
SSL-protected channel. Otherwise, a session hijacker could copy
the entire cookie and use it to impersonate the victim.
+Custom Attributes:
+ safe_sessions.user_mismatch: 'request-response-mismatch' | 'request-session-mismatch'
+ This attribute can be one of the above two values which correspond to the kind of comparison
+ that failed when processing the response. See SafeSessionMiddleware._verify_user
"""
@@ -72,6 +76,7 @@ from django.http import HttpResponse
from django.utils.crypto import get_random_string
from django.utils.deprecation import MiddlewareMixin
from django.utils.encoding import python_2_unicode_compatible
+from edx_django_utils.monitoring import set_custom_attribute
from six import text_type # pylint: disable=ungrouped-imports
@@ -372,18 +377,24 @@ class SafeSessionMiddleware(SessionMiddleware, MiddlewareMixin):
# conditionally set the log level.
log_func = log.debug if request.user.id is None else log.warning
log_func(
- u"SafeCookieData user at request '{0}' does not match user at response: '{1}'".format(
- request.safe_cookie_verified_user_id,
- request.user.id,
+ (
+ "SafeCookieData user at request '{0}' does not match user at response: '{1}' "
+ "for request path '{2}'"
+ ).format(
+ request.safe_cookie_verified_user_id, request.user.id, request.path,
),
)
+ set_custom_attribute("safe_sessions.user_mismatch", "request-response-mismatch")
if request.safe_cookie_verified_user_id != userid_in_session:
log.warning(
- u"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,
+ (
+ "SafeCookieData user at request '{0}' does not match user in session: '{1}' "
+ "for request path '{2}'"
+ ).format( # pylint: disable=logging-format-interpolation
+ request.safe_cookie_verified_user_id, userid_in_session, request.path,
),
)
+ set_custom_attribute("safe_sessions.user_mismatch", "request-session-mismatch")
@staticmethod
def get_user_id_from_session(request):
diff --git a/openedx/core/djangoapps/safe_sessions/tests/test_middleware.py b/openedx/core/djangoapps/safe_sessions/tests/test_middleware.py
index 1dd19e85f23..f24259246ee 100644
--- a/openedx/core/djangoapps/safe_sessions/tests/test_middleware.py
+++ b/openedx/core/djangoapps/safe_sessions/tests/test_middleware.py
@@ -185,10 +185,10 @@ 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, 'warning'):
+ with self.assert_logged_for_request_user_mismatch("different_user", self.user.id, 'warning', self.request.path):
self.assert_response(set_request_user=True, set_session_cookie=True)
- with self.assert_logged_for_session_user_mismatch("different_user", self.user.id):
+ with self.assert_logged_for_session_user_mismatch("different_user", self.user.id, self.request.path):
self.assert_response(set_request_user=True, set_session_cookie=True)
def test_anonymous_user(self):
@@ -196,7 +196,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, 'debug'):
+ with self.assert_logged_for_request_user_mismatch(self.user.id, None, 'debug', self.request.path):
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_utils.py b/openedx/core/djangoapps/safe_sessions/tests/test_utils.py
index c4c765be708..529c9efe465 100644
--- a/openedx/core/djangoapps/safe_sessions/tests/test_utils.py
+++ b/openedx/core/djangoapps/safe_sessions/tests/test_utils.py
@@ -116,28 +116,34 @@ class TestSafeSessionsLogMixin(object):
yield
@contextmanager
- def assert_logged_for_request_user_mismatch(self, user_at_request, user_at_response, log_level):
+ def assert_logged_for_request_user_mismatch(self, user_at_request, user_at_response, log_level, request_path):
"""
Asserts that warning was logged when request.user
was not equal to user at response
"""
with self.assert_logged_with_message(
- u"SafeCookieData user at request '{}' does not match user at response: '{}'".format(
- user_at_request, user_at_response
+ (
+ "SafeCookieData user at request '{}' does not match user at response: '{}' "
+ "for request path '{}'"
+ ).format(
+ user_at_request, user_at_response, request_path
),
log_level=log_level,
):
yield
@contextmanager
- def assert_logged_for_session_user_mismatch(self, user_at_request, user_in_session):
+ def assert_logged_for_session_user_mismatch(self, user_at_request, user_in_session, request_path):
"""
Asserts that warning was logged when request.user
was not equal to user at session
"""
with self.assert_logged_with_message(
- u"SafeCookieData user at request '{}' does not match user in session: '{}'".format(
- user_at_request, user_in_session
+ (
+ "SafeCookieData user at request '{}' does not match user in session: '{}' "
+ "for request path '{}'"
+ ).format(
+ user_at_request, user_in_session, request_path
),
log_level='warning',
):
--
GitLab