From 78ba9f09a16d2555ab5985e70678b95fa50b47ed Mon Sep 17 00:00:00 2001 From: Robert Raposa Date: Fri, 11 Mar 2022 14:36:26 -0500 Subject: [PATCH] feat: add corrupt cookie header monitoring (#30039) In case of unusual cookie headers containing "Cookie ", add custom attributes for monitoring: - cookies.header.corrupt_count - cookies.header.corrupt_key_count See annotation documentation for more details. Separately, updated to skip cookie log sampling for 0 size cookie header. ARCHBOM-2055 --- openedx/core/lib/request_utils.py | 22 +++++++++++ openedx/core/lib/tests/test_request_utils.py | 40 ++++++++++++++++++++ 2 files changed, 62 insertions(+) diff --git a/openedx/core/lib/request_utils.py b/openedx/core/lib/request_utils.py index 54e395d14a..88a9110145 100644 --- a/openedx/core/lib/request_utils.py +++ b/openedx/core/lib/request_utils.py @@ -143,6 +143,28 @@ class CookieMonitoringMiddleware: # .. custom_attribute_description: The total size in bytes of the cookie header. set_custom_attribute('cookies.header.size', cookie_header_size) + if cookie_header_size == 0: + return + + if corrupt_cookie_count := raw_header_cookie.count('Cookie: '): + # .. custom_attribute_name: cookies.header.corrupt_count + # .. custom_attribute_description: The attribute will only appear for potentially corrupt cookie headers, + # where "Cookie: " is found in the header. If this custom attribute is seen on the same + # requests where other mysterious cookie problems are occurring, this may help troubleshoot. + # See https://openedx.atlassian.net/browse/CR-4614 for more details. + # Also see cookies.header.corrupt_key_count + set_custom_attribute('cookies.header.corrupt_count', corrupt_cookie_count) + # .. custom_attribute_name: cookies.header.corrupt_key_count + # .. custom_attribute_description: The attribute will only appear for potentially corrupt cookie headers, + # where "Cookie: " is found in some of the cookie keys. If this custom attribute is seen on the same + # requests where other mysterious cookie problems are occurring, this may help troubleshoot. + # See https://openedx.atlassian.net/browse/CR-4614 for more details. + # Also see cookies.header.corrupt_count. + set_custom_attribute( + 'cookies.header.corrupt_key_count', + sum(1 for key in request.COOKIES.keys() if 'Cookie: ' in key) + ) + # .. setting_name: COOKIE_HEADER_SIZE_LOGGING_THRESHOLD # .. setting_default: None # .. setting_description: The minimum size for the full cookie header to log a list of cookie names and sizes. diff --git a/openedx/core/lib/tests/test_request_utils.py b/openedx/core/lib/tests/test_request_utils.py index 7290723cbc..f918470258 100644 --- a/openedx/core/lib/tests/test_request_utils.py +++ b/openedx/core/lib/tests/test_request_utils.py @@ -135,6 +135,31 @@ class CookieMonitoringMiddlewareTestCase(unittest.TestCase): # cookie logging was not enabled, so nothing should be logged mock_logger.info.assert_not_called() + @override_settings(COOKIE_HEADER_SIZE_LOGGING_THRESHOLD=None) + @override_settings(COOKIE_SAMPLING_REQUEST_COUNT=None) + @patch("openedx.core.lib.request_utils.set_custom_attribute") + @ddt.data( + # A corrupt cookie header contains "Cookie: ". + ('corruptCookie: normal-cookie=value', 1, 1), + ('corrupt1Cookie: normal-cookie1=value1;corrupt2Cookie: normal-cookie2=value2', 2, 2), + ('corrupt=Cookie: value', 1, 0), + ) + @ddt.unpack + def test_cookie_header_corrupt_monitoring( + self, corrupt_cookie_header, expected_corrupt_count, expected_corrupt_key_count, mock_set_custom_attribute + ): + middleware = CookieMonitoringMiddleware(self.mock_response) + request = RequestFactory().request() + request.META['HTTP_COOKIE'] = corrupt_cookie_header + + middleware(request) + + mock_set_custom_attribute.assert_has_calls([ + call('cookies.header.size', len(request.META['HTTP_COOKIE'])), + call('cookies.header.corrupt_count', expected_corrupt_count), + call('cookies.header.corrupt_key_count', expected_corrupt_key_count), + ]) + @override_settings(COOKIE_HEADER_SIZE_LOGGING_THRESHOLD=1) @patch('openedx.core.lib.request_utils.log', autospec=True) @patch("openedx.core.lib.request_utils.set_custom_attribute") @@ -178,6 +203,21 @@ class CookieMonitoringMiddlewareTestCase(unittest.TestCase): "Sampled small (< 9999) cookie header. BEGIN-COOKIE-SIZES(total=16) b: 3, a: 2, c: 1 END-COOKIE-SIZES" ) + @override_settings(COOKIE_HEADER_SIZE_LOGGING_THRESHOLD=9999) + @override_settings(COOKIE_SAMPLING_REQUEST_COUNT=1) + @patch('openedx.core.lib.request_utils.log', autospec=True) + @patch("openedx.core.lib.request_utils.set_custom_attribute") + def test_empty_cookie_header_skips_sampling(self, mock_set_custom_attribute, mock_logger): + middleware = CookieMonitoringMiddleware(self.mock_response) + cookies_dict = {} + + middleware(self.get_mock_request(cookies_dict)) + + mock_set_custom_attribute.assert_has_calls([ + call('cookies.header.size', 0), + ]) + mock_logger.info.assert_not_called() + def get_mock_request(self, cookies_dict): """ Return mock request with the provided cookies in the header.