From e218b716011889e5995b08d4df306d4dd26e6477 Mon Sep 17 00:00:00 2001 From: Tim McCormack Date: Fri, 18 Feb 2022 19:01:37 +0000 Subject: [PATCH] feat: Just log cookie sizes when over threshold (no encrypted contents) (#29938) This should really be all we need for most cases, and we don't want to emit sensitive data more than necessary, even encrypted. If we need to inspect one cookie in particular, we can add special logging for that. Also, change to greater-than-or-equal for threshold to match setting docs. ref: ARCHBOM-2042 --- openedx/core/lib/request_utils.py | 23 +++--------- openedx/core/lib/tests/test_request_utils.py | 37 ++++---------------- 2 files changed, 10 insertions(+), 50 deletions(-) diff --git a/openedx/core/lib/request_utils.py b/openedx/core/lib/request_utils.py index d3121a6f5b..0de99c00d7 100644 --- a/openedx/core/lib/request_utils.py +++ b/openedx/core/lib/request_utils.py @@ -14,7 +14,6 @@ from edx_toggles.toggles import WaffleFlag from opaque_keys import InvalidKeyError from opaque_keys.edx.keys import CourseKey from rest_framework.views import exception_handler -from common.djangoapps.util.log_sensitive import encrypt_for_log from openedx.core.djangoapps.site_configuration import helpers as configuration_helpers @@ -145,7 +144,6 @@ class CookieMonitoringMiddleware(MiddlewareMixin): - TOP_N_COOKIES_CAPTURED - TOP_N_COOKIE_GROUPS_CAPTURED - COOKIE_SIZE_LOGGING_THRESHOLD - - COOKIE_HEADER_DEBUG_PUBLIC_KEY """ @@ -155,26 +153,13 @@ class CookieMonitoringMiddleware(MiddlewareMixin): # .. setting_name: COOKIE_SIZE_LOGGING_THRESHOLD # .. setting_default: None - # .. setting_description: The minimum size for logging the entire (encrypted) cookie header. Should be set + # .. setting_description: The minimum size for logging a list of cookie names and sizes. Should be set # to a relatively high threshold (suggested 9-10K) to avoid flooding the logs. - # .. setting_warning: Requires COOKIE_HEADER_DEBUG_PUBLIC_KEY to be set logging_threshold = getattr(settings, "COOKIE_SIZE_LOGGING_THRESHOLD", None) - # .. setting_name: COOKIE_HEADER_DEBUG_PUBLIC_KEY - # .. setting_default: None - # .. setting_description: The public key used to encrypt large cookie headers. See See - # https://github.com/edx/edx-platform/blob/master/common/djangoapps/util/log_sensitive.py - # for instructions on decrypting. - debug_key = getattr(settings, "COOKIE_HEADER_DEBUG_PUBLIC_KEY", None) - - if logging_threshold and cookie_header_size > logging_threshold: - if not debug_key: - log.warning("COOKIE_SIZE_LOGGING_THRESHOLD set without COOKIE_HEADER_DEBUG_PUBLIC_KEY") - else: - encrypted_cookie_header = encrypt_for_log(str(raw_header_cookie), - debug_key) - log.info(f"Large (> {logging_threshold}) cookie header detected." - f" Encrypted contents: {encrypted_cookie_header}") + if logging_threshold and cookie_header_size >= logging_threshold: + sizes = ', '.join(f"{name}: {len(value)}" for (name, value) in sorted(request.COOKIES.items())) + log.info(f"Large (>= {logging_threshold}) cookie header detected. Cookie sizes: {sizes}") if not CAPTURE_COOKIE_SIZES.is_enabled(): return diff --git a/openedx/core/lib/tests/test_request_utils.py b/openedx/core/lib/tests/test_request_utils.py index 0a9021d65d..af6f7bc44d 100644 --- a/openedx/core/lib/tests/test_request_utils.py +++ b/openedx/core/lib/tests/test_request_utils.py @@ -268,49 +268,24 @@ class RequestUtilTestCase(unittest.TestCase): ], any_order=True) @override_settings(COOKIE_SIZE_LOGGING_THRESHOLD=1) - @patch("openedx.core.lib.request_utils.CAPTURE_COOKIE_SIZES") - @patch("openedx.core.lib.request_utils.encrypt_for_log") - def test_log_encrypted_cookies_no_key(self, mock_encrypt, mock_capture_cookie_sizes): + @patch("openedx.core.lib.request_utils.CAPTURE_COOKIE_SIZES.is_enabled", return_value=False) + @patch('openedx.core.lib.request_utils.log', autospec=True) + def test_log_cookie_sizes(self, mock_logger, _): middleware = CookieMonitoringMiddleware() - cookies_dict = { "a": "." * 10, "b": "." * 15, } - factory = RequestFactory() for name, value in cookies_dict.items(): factory.cookies[name] = value - mock_request = factory.request() middleware.process_request(mock_request) - mock_encrypt.assert_not_called() - @override_settings(COOKIE_SIZE_LOGGING_THRESHOLD=1) - @override_settings(COOKIE_HEADER_DEBUG_PUBLIC_KEY="fake-key") - @patch("openedx.core.lib.request_utils.CAPTURE_COOKIE_SIZES") - @patch("openedx.core.lib.request_utils.encrypt_for_log") - def test_log_encrypted_cookies(self, mock_encrypt, mock_capture_cookie_sizes): - - middleware = CookieMonitoringMiddleware() - - cookies_dict = { - "a": "." * 10, - "b": "." * 15, - } - - factory = RequestFactory() - for name, value in cookies_dict.items(): - factory.cookies[name] = value - - mock_request = factory.request() - cookie_header = str(mock_request.META.get('HTTP_COOKIE', '')) - - middleware.process_request(mock_request) - mock_encrypt.assert_has_calls([ - call(cookie_header, "fake-key") - ]) + mock_logger.info.assert_called_once_with( + "Large (>= 1) cookie header detected. Cookie sizes: a: 10, b: 15" + ) class TestGetExpectedErrorSettingsDict(unittest.TestCase):