From 536525fce357d914786e10fdfb67f575c42ea6d9 Mon Sep 17 00:00:00 2001 From: Mark Boyd Date: Tue, 15 Feb 2022 16:28:16 -0500 Subject: [PATCH] Merge user contribution from #43 (#44) * test_logger setup: allow kwargs to be forwarded to CumulusLogger constructor * add failing test, each logger should only have one handler * CumulusLogger: only create new handler if one is not present This fixes the test added in the previous commit Before this change, multiple calls to `CumulusLogger(name)` would construct a `CumulusLogger` instance with the same underlying `Logger` instance, but each construction would also create and attach a new handler, resulting in duplicate messages, e.g.: ``` > python >>> from cumulus_logger import CumulusLogger >>> logger = CumulusLogger('test') >>> logger.info('hello there') {"message": "hello there", "timestamp": "2021-12-21T16:18:09.315309", "level": "info"} >>> >>> logger2 = CumulusLogger('test') >>> logger2.info('hello there') {"message": "hello there", "timestamp": "2021-12-21T16:18:16.845070", "level": "info"} {"message": "hello there", "timestamp": "2021-12-21T16:18:16.845070", "level": "info"} >>> >>> logger.info('hello there') {"message": "hello there", "timestamp": "2021-12-21T16:18:18.165564", "level": "info"} {"message": "hello there", "timestamp": "2021-12-21T16:18:18.165564", "level": "info"} ``` See also the screenshots on https://github.com/ghrcdaac/dmrpp-file-generator-docker/pull/25 With this change, a new handler is only constructed if the underlying `Logger` does not already have any handlers, preventing messages from being handled more than once: ``` > python >>> from cumulus_logger import CumulusLogger >>> logger = CumulusLogger('test') >>> logger.info('hello there') {"message": "hello there", "timestamp": "2021-12-21T16:33:56.735453", "level": "info"} >>> >>> logger2 = CumulusLogger('test') >>> logger2.info('hello there') {"message": "hello there", "timestamp": "2021-12-21T16:34:03.887972", "level": "info"} >>> >>> logger.info('hello there') {"message": "hello there", "timestamp": "2021-12-21T16:34:07.808415", "level": "info"} ``` Co-authored-by: Michael Brandt --- cumulus_logger.py | 11 +++++++---- tests/test_logger.py | 12 ++++++++++-- 2 files changed, 17 insertions(+), 6 deletions(-) diff --git a/cumulus_logger.py b/cumulus_logger.py index 9e318bd..83bbbe5 100644 --- a/cumulus_logger.py +++ b/cumulus_logger.py @@ -88,15 +88,18 @@ def _get_exception_message(**kwargs): class CumulusLogger: def __init__(self, name=__name__, level=logging.DEBUG): """Creates a logger with a name and loggging level.""" - log_handler = logging.StreamHandler() - log_handler.setLevel(logging.DEBUG) - log_handler.setFormatter(logging.Formatter('%(message)s')) self.logger = logging.getLogger(name) - self.logger.addHandler(log_handler) self.logger.setLevel(level) + # Avoid duplicate message in AWS cloudwatch self.logger.propagate = False + if not self.logger.handlers: + log_handler = logging.StreamHandler() + log_handler.setLevel(logging.DEBUG) + log_handler.setFormatter(logging.Formatter('%(message)s')) + self.logger.addHandler(log_handler) + self.event = None self.context = None self._msg = {} diff --git a/tests/test_logger.py b/tests/test_logger.py index c155e53..b1a51bd 100644 --- a/tests/test_logger.py +++ b/tests/test_logger.py @@ -7,7 +7,7 @@ class TestLogger(unittest.TestCase): - def set_up_logger(self, event=None, context=None, logger=None): + def set_up_logger(self, event=None, context=None, logger=None, **kwargs): if event is None: event = create_event() @@ -15,7 +15,7 @@ def set_up_logger(self, event=None, context=None, logger=None): context = LambdaContextMock() if logger is None: - logger = CumulusLogger() + logger = CumulusLogger(**kwargs) logger.setMetadata(event, context) return logger @@ -143,3 +143,11 @@ def test_message_with_json_no_kwargs(self): logger = self.set_up_logger() msg = logger.createMessage('some message about JSON and the json: {"test": "simple"}') self.assertEqual(msg["message"], 'some message about JSON and the json: {"test": "simple"}') + + def test_multiple_instances_with_same_name_dont_have_multiple_handlers(self): + logger1 = self.set_up_logger(name='test') + self.assertEqual(1, len(logger1.logger.handlers)) + + logger2 = self.set_up_logger(name='test') + self.assertEqual(1, len(logger1.logger.handlers)) + self.assertEqual(1, len(logger2.logger.handlers))