From 52c7dca2e50af1b078dbf754f988a34e85b40596 Mon Sep 17 00:00:00 2001 From: Atte Isopuro Date: Fri, 25 Aug 2023 19:40:03 +0300 Subject: [PATCH 1/3] [FIX] sentry: respect sentry_logging_level Before this fix, the Sentry module sent events for WARNING- level logs, even if sentry_logging_level was registered as "error" or higher. The fix itself is minor: setup of the integration mistakenly set the hardcoded WARNING level to the event handler and the sentry_logging_level to the breadcrumb handler, when they should have been the other way around. The largest part of the diff is a reworking of the tests in order to properly replicate the issue: * The test previously emitted a fake log event directly using the integration's handler's emit-method, which skipped the part of the logic that actually filters based on logging level. This has been changed to use a bespoke NoopHandler and dedicated Logger, so that the tests can emit "actual logs" and test Sentry as accurately as possible. * The tests were not configured to use a non-default logging level, thus making it so that none of them caught the fact we were basically hard-coding the setting to WARNING-level. The tests now set the logging level to ERROR in order to make sure the configuration parameter works when it is non-default. * Changes to configuration (especially ignored loggers) were leaking from one test into others. The tests were directly mutating the `odoo.tools.config.options` mapping, without resetting it afterward, leaving the changes in place for subsequent tests. Introduced a helper method `patch_config` that can be used to patch the config object so that the patch is undone at the end of the test. --- sentry/const.py | 6 ++- sentry/tests/test_client.py | 99 ++++++++++++++++++++++++++++--------- 2 files changed, 81 insertions(+), 24 deletions(-) diff --git a/sentry/const.py b/sentry/const.py index c3135a9dfe0..9f7eab3af95 100644 --- a/sentry/const.py +++ b/sentry/const.py @@ -69,7 +69,11 @@ def get_sentry_logging(level=DEFAULT_LOG_LEVEL): if level not in LOG_LEVEL_MAP: level = DEFAULT_LOG_LEVEL - return LoggingIntegration(level=LOG_LEVEL_MAP[level], event_level=logging.WARNING) + return LoggingIntegration( + # Gather warnings into breadcrumbs regardless of actual logging level + level=logging.WARNING, + event_level=LOG_LEVEL_MAP[level], + ) def get_sentry_options(): diff --git a/sentry/tests/test_client.py b/sentry/tests/test_client.py index 322b999c24a..f25ec2c8ee6 100644 --- a/sentry/tests/test_client.py +++ b/sentry/tests/test_client.py @@ -56,21 +56,56 @@ def kill(self, *args, **kwargs): pass +class NoopHandler(logging.Handler): + """ + A Handler subclass that does nothing with any given log record. + + Sentry's log patching works by having the integration process things after + the normal log handlers are run, so we use this handler to do nothing and + move to Sentry logic ASAP. + """ + + def emit(self, record): + pass + + class TestClientSetup(TransactionCase): def setUp(self): super(TestClientSetup, self).setUp() self.dsn = "http://public:secret@example.com/1" - config.options["sentry_enabled"] = True - config.options["sentry_dsn"] = self.dsn - with patch( - "odoo.addons.sentry.const.select_transport", return_value=InMemoryTransport - ): - self.client = initialize_sentry(config)._client - self.handler = self.client.integrations["logging"]._handler + self.patch_config( + { + "sentry_enabled": True, + "sentry_dsn": self.dsn, + "sentry_logging_level": "error", + } + ) + self.client = initialize_sentry(config)._client + self.client.transport = InMemoryTransport({"dsn": self.dsn}) + + # Setup our own logger so we don't flood stderr with error logs + self.logger = logging.getLogger("odoo.sentry.test.logger") + # Do not mutate list while iterating it + handlers = [handler for handler in self.logger.handlers] + for handler in handlers: + self.logger.removeHandler(handler) + self.logger.addHandler(NoopHandler()) + self.logger.propagate = False + + def patch_config(self, options: dict): + """ + Patch Odoo's config with the given `options`, ensuring that the patch + is undone when the test completes. + """ + _config_patcher = patch.dict( + in_dict=config.options, + values=options, + ) + _config_patcher.start() + self.addCleanup(_config_patcher.stop) def log(self, level, msg, exc_info=None): - record = logging.LogRecord(__name__, level, __file__, 42, msg, (), exc_info) - self.handler.emit(record) + self.logger.log(level, msg, exc_info=exc_info) def assertEventCaptured(self, client, event_level, event_msg): self.assertTrue( @@ -100,50 +135,64 @@ def test_startup_event_disabled(self): def test_initialize_raven_sets_dsn(self): self.assertEqual(self.client.dsn, self.dsn) - def test_capture_event(self): + def test_ignore_low_level_event(self): level, msg = logging.WARNING, "Test event, can be ignored" self.log(level, msg) level = "warning" + self.assertEventNotCaptured(self.client, level, msg) + + def test_capture_event(self): + level, msg = logging.ERROR, "Test event, should be captured" + self.log(level, msg) + level = "error" self.assertEventCaptured(self.client, level, msg) def test_capture_event_exc(self): - level, msg = logging.WARNING, "Test event, can be ignored exception" + level, msg = logging.ERROR, "Test event, can be ignored exception" try: raise TestException(msg) except TestException: exc_info = sys.exc_info() self.log(level, msg, exc_info) - level = "warning" + level = "error" self.assertEventCaptured(self.client, level, msg) def test_ignore_exceptions(self): - config.options["sentry_ignore_exceptions"] = "odoo.exceptions.UserError" + self.patch_config( + { + "sentry_ignore_exceptions": "odoo.exceptions.UserError", + } + ) client = initialize_sentry(config)._client client.transport = InMemoryTransport({"dsn": self.dsn}) - level, msg = logging.WARNING, "Test exception" + level, msg = logging.ERROR, "Test exception" try: raise exceptions.UserError(msg) except exceptions.UserError: exc_info = sys.exc_info() self.log(level, msg, exc_info) - level = "warning" + level = "error" self.assertEventNotCaptured(client, level, msg) def test_exclude_logger(self): - config.options["sentry_enabled"] = True - config.options["sentry_exclude_loggers"] = __name__ + self.patch_config( + { + "sentry_enabled": True, + "sentry_exclude_loggers": self.logger.name, + } + ) client = initialize_sentry(config)._client client.transport = InMemoryTransport({"dsn": self.dsn}) - level, msg = logging.WARNING, "Test exclude logger %s" % __name__ + level, msg = logging.ERROR, "Test exclude logger %s" % __name__ self.log(level, msg) - level = "warning" + level = "error" # Revert ignored logger so it doesn't affect other tests - remove_handler_ignore(__name__) + remove_handler_ignore(self.logger.name) self.assertEventNotCaptured(client, level, msg) @patch("odoo.addons.sentry.hooks.get_odoo_commit", return_value=GIT_SHA) def test_config_odoo_dir(self, get_odoo_commit): - config.options["sentry_odoo_dir"] = "/opt/odoo/core" + self.patch_config({"sentry_odoo_dir": "/opt/odoo/core"}) client = initialize_sentry(config)._client self.assertEqual( @@ -154,8 +203,12 @@ def test_config_odoo_dir(self, get_odoo_commit): @patch("odoo.addons.sentry.hooks.get_odoo_commit", return_value=GIT_SHA) def test_config_release(self, get_odoo_commit): - config.options["sentry_odoo_dir"] = "/opt/odoo/core" - config.options["sentry_release"] = RELEASE + self.patch_config( + { + "sentry_odoo_dir": "/opt/odoo/core", + "sentry_release": RELEASE, + } + ) client = initialize_sentry(config)._client self.assertEqual( From e2351c60d5df9efbcb4a7aa15207b1b4882f371d Mon Sep 17 00:00:00 2001 From: Atte Isopuro Date: Mon, 28 Aug 2023 15:46:59 +0300 Subject: [PATCH 2/3] [IMP] sentry: increase test coverage --- sentry/tests/test_client.py | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) diff --git a/sentry/tests/test_client.py b/sentry/tests/test_client.py index f25ec2c8ee6..72e4202f65a 100644 --- a/sentry/tests/test_client.py +++ b/sentry/tests/test_client.py @@ -12,6 +12,7 @@ from odoo.tests import TransactionCase from odoo.tools import config +from ..const import to_int_if_defined from ..hooks import initialize_sentry GIT_SHA = "d670460b4b4aece5915caf5c68d12f560a9fe3e4" @@ -190,6 +191,22 @@ def test_exclude_logger(self): remove_handler_ignore(self.logger.name) self.assertEventNotCaptured(client, level, msg) + def test_invalid_logging_level(self): + self.patch_config( + { + "sentry_logging_level": "foo_bar", + } + ) + client = initialize_sentry(config)._client + client.transport = InMemoryTransport({"dsn": self.dsn}) + level, msg = logging.WARNING, "Test we use the default" + self.log(level, msg) + level = "warning" + self.assertEventCaptured(client, level, msg) + + def test_undefined_to_int(self): + self.assertIsNone(to_int_if_defined("")) + @patch("odoo.addons.sentry.hooks.get_odoo_commit", return_value=GIT_SHA) def test_config_odoo_dir(self, get_odoo_commit): self.patch_config({"sentry_odoo_dir": "/opt/odoo/core"}) From f3dd4d9f34b954e6697b50b3e82d582901958f9f Mon Sep 17 00:00:00 2001 From: Pierre Verkest Date: Thu, 28 Mar 2024 18:54:25 +0100 Subject: [PATCH 3/3] sentry: fix test after backporting test ensure info log is sent to sentry but this is not the case as long backport set level to be sent from error Also split revert some change regarding class setup to make startup test working --- sentry/tests/test_client.py | 95 ++++++++++++++++++++++++++----------- 1 file changed, 68 insertions(+), 27 deletions(-) diff --git a/sentry/tests/test_client.py b/sentry/tests/test_client.py index 72e4202f65a..a0a5d171c87 100644 --- a/sentry/tests/test_client.py +++ b/sentry/tests/test_client.py @@ -70,10 +70,76 @@ def emit(self, record): pass -class TestClientSetup(TransactionCase): +class TestSentryCommon(TransactionCase): def setUp(self): - super(TestClientSetup, self).setUp() + super().setUp() self.dsn = "http://public:secret@example.com/1" + + def assertEventCaptured(self, client, event_level, event_msg): + self.assertTrue( + client.transport.has_event(event_level, event_msg), + msg='Event: "%s" was not captured' % event_msg, + ) + + def assertEventNotCaptured(self, client, event_level, event_msg): + self.assertFalse( + client.transport.has_event(event_level, event_msg), + msg='Event: "%s" was captured' % event_msg, + ) + + +class TestClientSetupStartup(TestSentryCommon): + def setUp(self): + super().setUp() + config.options["sentry_enabled"] = True + config.options["sentry_dsn"] = self.dsn + config.options["sentry_logging_level"] = "info" + with patch( + "odoo.addons.sentry.const.select_transport", return_value=InMemoryTransport + ): + self.client = initialize_sentry(config)._client + self.handler = self.client.integrations["logging"]._handler + + def assertEventCaptured(self, client, event_level, event_msg): + self.assertTrue( + client.transport.has_event(event_level, event_msg), + msg='Event: "%s" was not captured' % event_msg, + ) + + def assertEventNotCaptured(self, client, event_level, event_msg): + self.assertFalse( + client.transport.has_event(event_level, event_msg), + msg='Event: "%s" was captured' % event_msg, + ) + + def test_startup_event(self): + self.assertEventCaptured(self.client, "info", "Starting Odoo Server") + + def test_startup_event_disabled(self): + config.options["sentry_enabled"] = True + config.options["sentry_dsn"] = self.dsn + config.options["sentry_ignore_startup_event"] = True + with patch( + "odoo.addons.sentry.const.select_transport", return_value=InMemoryTransport + ): + self.client = initialize_sentry(config)._client + self.assertEventNotCaptured(self.client, "info", "Starting Odoo Server") + + def test_startup_event_disabled_if_warning_level(self): + config.options["sentry_enabled"] = True + config.options["sentry_dsn"] = self.dsn + config.options["sentry_ignore_startup_event"] = True + config.options["sentry_logging_level"] = "warning" + with patch( + "odoo.addons.sentry.const.select_transport", return_value=InMemoryTransport + ): + self.client = initialize_sentry(config)._client + self.assertEventNotCaptured(self.client, "info", "Starting Odoo Server") + + +class TestClientSetup(TestSentryCommon): + def setUp(self): + super().setUp() self.patch_config( { "sentry_enabled": True, @@ -108,31 +174,6 @@ def patch_config(self, options: dict): def log(self, level, msg, exc_info=None): self.logger.log(level, msg, exc_info=exc_info) - def assertEventCaptured(self, client, event_level, event_msg): - self.assertTrue( - client.transport.has_event(event_level, event_msg), - msg='Event: "%s" was not captured' % event_msg, - ) - - def assertEventNotCaptured(self, client, event_level, event_msg): - self.assertFalse( - client.transport.has_event(event_level, event_msg), - msg='Event: "%s" was captured' % event_msg, - ) - - def test_startup_event(self): - self.assertEventCaptured(self.client, "info", "Starting Odoo Server") - - def test_startup_event_disabled(self): - config.options["sentry_enabled"] = True - config.options["sentry_dsn"] = self.dsn - config.options["sentry_ignore_startup_event"] = True - with patch( - "odoo.addons.sentry.const.select_transport", return_value=InMemoryTransport - ): - self.client = initialize_sentry(config)._client - self.assertEventNotCaptured(self.client, "info", "Starting Odoo Server") - def test_initialize_raven_sets_dsn(self): self.assertEqual(self.client.dsn, self.dsn)