fix: remove root logger handler set by Lambda #115

CHANGELOG.md

@@ -6,6 +6,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+## [1.1.3] - 2020-08-18
+### Fixed
+- **Logger**: Logs emitted twice, structured and unstructured, due to Lambda configuring the root handler
+
 ## [1.1.2] - 2020-08-16
 ### Fixed
 - **Docs**: Clarify confusion on Tracer reuse and `auto_patch=False` statement

aws_lambda_powertools/logging/logger.py

@@ -168,6 +168,13 @@ def _get_caller_filename(self):
     def _init_logger(self, **kwargs):
         """Configures new logger"""
 
+        # Lambda by default configures the root logger handler
+        # therefore, we need to remove it to prevent messages being logged twice
+        # when customers use our Logger
+        logger.debug("Removing Lambda root handler whether it exists")
+        root_logger = logging.getLogger()
+        root_logger.handlers.clear()
+
         # Skip configuration if it's a child logger to prevent
         # multiple handlers being attached as well as different sampling mechanisms
         # and multiple messages from being logged as handlers can be duplicated

tests/functional/test_logger.py

@@ -359,3 +359,20 @@ def test_logger_record_caller_location(stdout):
     caller_fn_name = inspect.currentframe().f_code.co_name
     log = capture_logging_output(stdout)
     assert caller_fn_name in log["location"]
+
+
+def test_logger_do_not_log_twice(stdout):
+    # GIVEN Lambda configures the root logger with a handler
+    logging.basicConfig(format="%(asctime)-15s %(clientip)s %(user)-8s %(message)s", level="INFO")
+    root_logger = logging.getLogger()
+    root_logger.addHandler(logging.StreamHandler(stream=stdout))
+
+    # WHEN we create a new Logger
+    logger = Logger(stream=stdout)
+    logger.info("hello")
+
+    # THEN it should fail to unpack because root logger handler
+    # should be removed as part of our Logger initialization
+    assert not root_logger.handlers
+    with pytest.raises(ValueError, match=r".*expected 2, got 1.*"):
+        [log_one, log_two] = stdout.getvalue().strip().split("\n")