From 1ae50fc46683c815128e7fd15dc2d53264903fef Mon Sep 17 00:00:00 2001 From: Feanil Patel Date: Wed, 13 Jan 2021 16:37:05 -0500 Subject: [PATCH 1/3] Add more cookie logging code. We want to be able to easily figure out what our biggest cookies are and we want to also group cookies by prefix because certain services create multiple cookies and then put unique identifiers in the cookie name. For example braze cookie names use the following pattern: ab.storage. ab.storage. ab.storage. In this case we want to group all the `ab` cookies together so we can see their total size. New attributes: cookies..group.size: The size of a group of cookies. For example the sum of the size of all braze cookies would be the value of the `cookies.ab.group.size` attribute. cookies.max.name: The name of the largest cookie sent by the user. cookies.max.size: The size of the largest cookie sent by the user. cookies.max.group.name: The name of the largest group of cookies. A single cookie counts as a group of one for this calculation. cookies.max.group.size: The sum total size of all the cookies in the largest group. --- openedx/core/lib/request_utils.py | 60 ++++++++++++++- openedx/core/lib/tests/test_request_utils.py | 78 +++++++++++++++++++- 2 files changed, 133 insertions(+), 5 deletions(-) diff --git a/openedx/core/lib/request_utils.py b/openedx/core/lib/request_utils.py index dfeb2d4356..660584b5f2 100644 --- a/openedx/core/lib/request_utils.py +++ b/openedx/core/lib/request_utils.py @@ -102,19 +102,71 @@ class CookieMonitoringMiddleware(MiddlewareMixin): Don't log contents of cookies because that might cause a security issue. We just want to see if any cookies are growing out of control. + + A useful NRQL Query: + SELECT count(*), max(`cookies.max.group.size`) from Transaction FACET + `cookies.max.group.name` + + SELECT * FROM Transaction WHERE cookies_total_size > 6000 + + Attributes that are added by this middleware: + + cookies..size: The size of a cookie by the given name. + cookies..group.size: The size of a group of cookies. For example + the sum of the size of all braze cookies would be the value of the + `cookies.ab.group.size` attribute. + cookies.max.name: The name of the largest cookie sent by the user. + cookies.max.size: The size of the largest cookie sent by the user. + cookies.max.group.name: The name of the largest group of cookies. A single cookie + counts as a group of one for this calculation. + cookies.max.group.size: The sum total size of all the cookies in the largest group. + cookies_total_size: The sum total size of all cookies in this request. + """ if not CAPTURE_COOKIE_SIZES.is_enabled(): return - cookie_names_to_size = { - name: len(value) - for name, value in request.COOKIES.items() - } + cookie_names_to_size = {} + cookie_groups_to_size = {} + + for name, value in request.COOKIES.items(): + # Get cookie size for all cookies. + cookie_size = len(value) + cookie_names_to_size[name] = cookie_size + + # Group cookies by their prefix seperated by a period or underscore + grouping_name = re.split('[._]', name, 1)[0] + if grouping_name and grouping_name != name: + # Add or update the size for this group. + cookie_groups_to_size[grouping_name] = cookie_groups_to_size.get(grouping_name, 0) + cookie_size + + max_cookie_name = max(cookie_names_to_size, key=lambda name: cookie_names_to_size[name]) + max_cookie_size = cookie_names_to_size[max_cookie_name] + + max_group_cookie_name = max(cookie_groups_to_size, key=lambda name: cookie_groups_to_size[name]) + max_group_cookie_size = cookie_groups_to_size[max_group_cookie_name] + + # If a single cookies is bigger than any group of cookies, we want max_group... to reflect that. + # Treating an individual cookie as a group of 1 for calculating the max. + if max_group_cookie_size < max_cookie_size: + max_group_cookie_name = max_cookie_name + max_group_cookie_size = max_cookie_size + for name, size in cookie_names_to_size.items(): attribute_name = 'cookies.{}.size'.format(name) set_custom_attribute(attribute_name, size) log.debug(u'%s = %d', attribute_name, size) + for name, size in cookie_groups_to_size.items(): + attribute_name = 'cookies.{}.group.size'.format(name) + set_custom_attribute(attribute_name, size) + log.debug(u'%s = %d', attribute_name, size) + + set_custom_attribute('cookies.max.name', max_cookie_name) + set_custom_attribute('cookies.max.size', max_cookie_size) + set_custom_attribute('cookies.max.group.name', max_group_cookie_name) + set_custom_attribute('cookies.max.group.size', max_group_cookie_size) + total_cookie_size = sum(cookie_names_to_size.values()) set_custom_attribute('cookies_total_size', total_cookie_size) log.debug(u'cookies_total_size = %d', total_cookie_size) diff --git a/openedx/core/lib/tests/test_request_utils.py b/openedx/core/lib/tests/test_request_utils.py index b091dfd790..d79f8aa174 100644 --- a/openedx/core/lib/tests/test_request_utils.py +++ b/openedx/core/lib/tests/test_request_utils.py @@ -2,12 +2,20 @@ import unittest +from unittest.mock import Mock, patch, call from django.conf import settings from django.core.exceptions import SuspiciousOperation from django.test.client import RequestFactory -from openedx.core.lib.request_utils import get_request_or_stub, course_id_from_url, safe_get_host +from edx_toggles.toggles.testutils import override_waffle_flag +from openedx.core.lib.request_utils import ( + get_request_or_stub, + course_id_from_url, + safe_get_host, + CookieMonitoringMiddleware, + CAPTURE_COOKIE_SIZES, +) class RequestUtilTestCase(unittest.TestCase): @@ -83,3 +91,71 @@ class RequestUtilTestCase(unittest.TestCase): self.assertEqual(course_id.org, org) self.assertEqual(course_id.course, course) self.assertEqual(course_id.run, run) + + @patch("openedx.core.lib.request_utils.CAPTURE_COOKIE_SIZES") + @patch("openedx.core.lib.request_utils.set_custom_attribute") + def test_cookie_monitoring(self, mock_set_custom_attribute, mock_capture_cookie_sizes): + + mock_capture_cookie_sizes.is_enabled.return_value = True + middleware = CookieMonitoringMiddleware() + + mock_request = Mock() + mock_request.COOKIES = { + "a": "." * 100, + "_b": "." * 13, + "_c_": "." * 13, + "a.b": "." * 10, + "a.c": "." * 10, + "b.": "." * 13, + "b_a": "." * 15, + "b_c": "." * 15, + } + + middleware.process_request(mock_request) + + mock_set_custom_attribute.assert_has_calls([ + call('cookies.a.size', 100), + call('cookies._b.size', 13), + call('cookies._c_.size', 13), + call('cookies.a.b.size', 10), + call('cookies.a.c.size', 10), + call('cookies.b..size', 13), + call('cookies.b_a.size', 15), + call('cookies.b_c.size', 15), + call('cookies.a.group.size', 20), + call('cookies.b.group.size', 43), + call('cookies.max.name', 'a'), + call('cookies.max.size', 100), + # Test that single cookie is also treated as a group for max calculations. + call('cookies.max.group.name', 'a'), + call('cookies.max.group.size', 100), + call('cookies_total_size', 189) + ]) + + @patch("openedx.core.lib.request_utils.CAPTURE_COOKIE_SIZES") + @patch("openedx.core.lib.request_utils.set_custom_attribute") + def test_cookie_monitoring_max_group(self, mock_set_custom_attribute, mock_capture_cookie_sizes): + + mock_capture_cookie_sizes.is_enabled.return_value = True + middleware = CookieMonitoringMiddleware() + + mock_request = Mock() + mock_request.COOKIES = { + "a": "." * 10, + "b_a": "." * 15, + "b_c": "." * 20, + } + + middleware.process_request(mock_request) + + mock_set_custom_attribute.assert_has_calls([ + call('cookies.a.size', 10), + call('cookies.b_a.size', 15), + call('cookies.b_c.size', 20), + call('cookies.b.group.size', 35), + call('cookies.max.name', 'b_c'), + call('cookies.max.size', 20), + call('cookies.max.group.name', 'b'), + call('cookies.max.group.size', 35), + call('cookies_total_size', 45) + ]) From 1a1da89f55ddf6c06056eb8396190c62e1720e2c Mon Sep 17 00:00:00 2001 From: Feanil Patel Date: Thu, 14 Jan 2021 09:56:01 -0500 Subject: [PATCH 2/3] Drop setting attributes for the size of each cookie. Setting a new metric per cookie name resulted in a lot of metrics getting added to New Relic. In some cases, this was causing other more important metrics to not get registered. --- openedx/core/lib/request_utils.py | 7 ++----- openedx/core/lib/tests/test_request_utils.py | 11 ----------- 2 files changed, 2 insertions(+), 16 deletions(-) diff --git a/openedx/core/lib/request_utils.py b/openedx/core/lib/request_utils.py index 660584b5f2..2dbc9151ff 100644 --- a/openedx/core/lib/request_utils.py +++ b/openedx/core/lib/request_utils.py @@ -152,11 +152,8 @@ class CookieMonitoringMiddleware(MiddlewareMixin): max_group_cookie_name = max_cookie_name max_group_cookie_size = max_cookie_size - for name, size in cookie_names_to_size.items(): - attribute_name = 'cookies.{}.size'.format(name) - set_custom_attribute(attribute_name, size) - log.debug(u'%s = %d', attribute_name, size) - + # Only log the groups because adding an arbitrary number of individual cookies pushes too many + # metrics into NR and results in other metrics getting dropped potentially. for name, size in cookie_groups_to_size.items(): attribute_name = 'cookies.{}.group.size'.format(name) set_custom_attribute(attribute_name, size) diff --git a/openedx/core/lib/tests/test_request_utils.py b/openedx/core/lib/tests/test_request_utils.py index d79f8aa174..e3b63bf9f3 100644 --- a/openedx/core/lib/tests/test_request_utils.py +++ b/openedx/core/lib/tests/test_request_utils.py @@ -114,14 +114,6 @@ class RequestUtilTestCase(unittest.TestCase): middleware.process_request(mock_request) mock_set_custom_attribute.assert_has_calls([ - call('cookies.a.size', 100), - call('cookies._b.size', 13), - call('cookies._c_.size', 13), - call('cookies.a.b.size', 10), - call('cookies.a.c.size', 10), - call('cookies.b..size', 13), - call('cookies.b_a.size', 15), - call('cookies.b_c.size', 15), call('cookies.a.group.size', 20), call('cookies.b.group.size', 43), call('cookies.max.name', 'a'), @@ -149,9 +141,6 @@ class RequestUtilTestCase(unittest.TestCase): middleware.process_request(mock_request) mock_set_custom_attribute.assert_has_calls([ - call('cookies.a.size', 10), - call('cookies.b_a.size', 15), - call('cookies.b_c.size', 20), call('cookies.b.group.size', 35), call('cookies.max.name', 'b_c'), call('cookies.max.size', 20), From e5e2b7f7b61c1881c9f4dc73dc7c41971f1d5a38 Mon Sep 17 00:00:00 2001 From: Feanil Patel Date: Thu, 14 Jan 2021 12:31:55 -0500 Subject: [PATCH 3/3] Only capture the top N cookies and cookie groups. Instead of adding new attributes for each cookie name we create consistent attribute names. This should prevent any issues where we have too many different unique attribute names because the cookie names are unique to the user. We added two new settings to make the number of cookies and groups capture configurable: - TOP_N_COOKIES_CAPTURED - TOP_N_COOKIE_GROUPS_CAPTURED --- openedx/core/lib/request_utils.py | 57 ++++++++++++++++---- openedx/core/lib/tests/test_request_utils.py | 30 ++++++++--- 2 files changed, 70 insertions(+), 17 deletions(-) diff --git a/openedx/core/lib/request_utils.py b/openedx/core/lib/request_utils.py index 2dbc9151ff..7255052af2 100644 --- a/openedx/core/lib/request_utils.py +++ b/openedx/core/lib/request_utils.py @@ -111,10 +111,10 @@ class CookieMonitoringMiddleware(MiddlewareMixin): Attributes that are added by this middleware: - cookies..size: The size of a cookie by the given name. - cookies..group.size: The size of a group of cookies. For example - the sum of the size of all braze cookies would be the value of the - `cookies.ab.group.size` attribute. + cookies..name: The name of the Nth largest cookie + cookies..size: The size of the Nth largest cookie + cookies..group..name: The name of the Nth largest cookie. + cookies.group..size: The size of the Nth largest cookie group. cookies.max.name: The name of the largest cookie sent by the user. cookies.max.size: The size of the largest cookie sent by the user. cookies.max.group.name: The name of the largest group of cookies. A single cookie @@ -122,10 +122,23 @@ class CookieMonitoringMiddleware(MiddlewareMixin): cookies.max.group.size: The sum total size of all the cookies in the largest group. cookies_total_size: The sum total size of all cookies in this request. + Related Settings: + + - `request_utils.capture_cookie_sizes` is the waffle flag that control whether this + middleware logs anything or not. + + - TOP_N_COOKIES_CAPTURED(Default: 5) controls how many cookies to log. + - TOP_N_COOKIE_GROUPS_CAPTURED(Default: 5): controls how many cookie groups to capture. + + """ if not CAPTURE_COOKIE_SIZES.is_enabled(): return + # Capture the N largest cookies + top_n_cookies_captured = getattr(settings, "TOP_N_COOKIES_CAPTURED", 5) + top_n_cookie_groups_captured = getattr(settings, "TOP_N_COOKIE_GROUPS_CAPTURED", 5) + cookie_names_to_size = {} cookie_groups_to_size = {} @@ -152,12 +165,36 @@ class CookieMonitoringMiddleware(MiddlewareMixin): max_group_cookie_name = max_cookie_name max_group_cookie_size = max_cookie_size - # Only log the groups because adding an arbitrary number of individual cookies pushes too many - # metrics into NR and results in other metrics getting dropped potentially. - for name, size in cookie_groups_to_size.items(): - attribute_name = 'cookies.{}.group.size'.format(name) - set_custom_attribute(attribute_name, size) - log.debug(u'%s = %d', attribute_name, size) + # Log only the top N biggest cookies. + top_n_cookies = sorted( + cookie_names_to_size, + key=lambda x: cookie_names_to_size[x], + reverse=True, + )[:top_n_cookies_captured] + for index, name in enumerate(top_n_cookies, start=1): + size = cookie_names_to_size[name] + name_attribute = 'cookies.{}.name'.format(index) + size_attribute = 'cookies.{}.size'.format(index) + + set_custom_attribute(name_attribute, name) + set_custom_attribute(size_attribute, size) + log.debug(u'%s = %d', name, size) + + # Log only the top N biggest groups. + top_n_cookie_groups = sorted( + cookie_groups_to_size, + key=lambda x: cookie_groups_to_size[x], + reverse=True, + )[:top_n_cookie_groups_captured] + + for index, name in enumerate(top_n_cookie_groups, start=1): + size = cookie_groups_to_size[name] + name_attribute = 'cookies.group.{}.name'.format(index) + size_attribute = 'cookies.group.{}.size'.format(index) + + set_custom_attribute(name_attribute, name) + set_custom_attribute(size_attribute, size) + log.debug(u'%s = %d', name, size) set_custom_attribute('cookies.max.name', max_cookie_name) set_custom_attribute('cookies.max.size', max_cookie_size) diff --git a/openedx/core/lib/tests/test_request_utils.py b/openedx/core/lib/tests/test_request_utils.py index e3b63bf9f3..6c140b7f11 100644 --- a/openedx/core/lib/tests/test_request_utils.py +++ b/openedx/core/lib/tests/test_request_utils.py @@ -8,13 +8,11 @@ from django.conf import settings from django.core.exceptions import SuspiciousOperation from django.test.client import RequestFactory -from edx_toggles.toggles.testutils import override_waffle_flag from openedx.core.lib.request_utils import ( get_request_or_stub, course_id_from_url, safe_get_host, CookieMonitoringMiddleware, - CAPTURE_COOKIE_SIZES, ) @@ -114,14 +112,25 @@ class RequestUtilTestCase(unittest.TestCase): middleware.process_request(mock_request) mock_set_custom_attribute.assert_has_calls([ - call('cookies.a.group.size', 20), - call('cookies.b.group.size', 43), + call('cookies.1.name', 'a'), + call('cookies.1.size', 100), + call('cookies.2.name', 'b_a'), + call('cookies.2.size', 15), + call('cookies.3.name', 'b_c'), + call('cookies.3.size', 15), + call('cookies.4.name', '_b'), + call('cookies.4.size', 13), + call('cookies.5.name', '_c_'), + call('cookies.5.size', 13), + call('cookies.group.1.name', 'b'), + call('cookies.group.1.size', 43), + call('cookies.group.2.name', 'a'), + call('cookies.group.2.size', 20), call('cookies.max.name', 'a'), call('cookies.max.size', 100), - # Test that single cookie is also treated as a group for max calculations. call('cookies.max.group.name', 'a'), call('cookies.max.group.size', 100), - call('cookies_total_size', 189) + call('cookies_total_size', 189), ]) @patch("openedx.core.lib.request_utils.CAPTURE_COOKIE_SIZES") @@ -141,7 +150,14 @@ class RequestUtilTestCase(unittest.TestCase): middleware.process_request(mock_request) mock_set_custom_attribute.assert_has_calls([ - call('cookies.b.group.size', 35), + call('cookies.1.name', 'b_c'), + call('cookies.1.size', 20), + call('cookies.2.name', 'b_a'), + call('cookies.2.size', 15), + call('cookies.3.name', 'a'), + call('cookies.3.size', 10), + call('cookies.group.1.name', 'b'), + call('cookies.group.1.size', 35), call('cookies.max.name', 'b_c'), call('cookies.max.size', 20), call('cookies.max.group.name', 'b'),