fix(logger-utils): ensure external loggers doesn't propagate logs on config copy

aws_lambda_powertools/logging/utils.py

@@ -3,6 +3,8 @@
 
 from .logger import Logger
 
+PACKAGE_LOGGER = "aws_lambda_powertools"
+
 
 def copy_config_to_registered_loggers(
     source_logger: Logger,
@@ -24,7 +26,6 @@ def copy_config_to_registered_loggers(
     exclude : Optional[Set[str]], optional
         List of logger names to exclude, by default None
     """
-
     level = log_level or source_logger.level
 
     # Assumptions: Only take parent loggers not children (dot notation rule)
@@ -34,11 +35,15 @@ def copy_config_to_registered_loggers(
     # 3. Include and exclude set? Add Logger if it’s in include and not in exclude
     # 4. Only exclude set? Ignore Logger in the excluding list
 
-    # Exclude source logger by default
+    # Exclude source and powertools package logger by default
+    # If source logger is a child ensure we exclude parent logger to not break child logger
+    # from receiving/pushing updates to keys being added/removed
+    source_logger_name = source_logger.name.split(".")[0] if source_logger.child else source_logger.name
+
     if exclude:
-        exclude.add(source_logger.name)
+        exclude.update(source_logger_name, PACKAGE_LOGGER)
     else:
-        exclude = {source_logger.name}
+        exclude = {source_logger_name, PACKAGE_LOGGER}
 
     # Prepare loggers set
     if include:
@@ -75,6 +80,7 @@ def _find_registered_loggers(
 def _configure_logger(source_logger: Logger, logger: logging.Logger, level: Union[int, str]) -> None:
     logger.handlers = []
     logger.setLevel(level)
+    logger.propagate = False  # ensure we don't propagate logs to existing loggers, #1073
     source_logger.debug(f"Logger {logger} reconfigured to use logging level {level}")
     for source_handler in source_logger.handlers:
         logger.addHandler(source_handler)

tests/functional/test_logger_utils.py

@@ -184,7 +184,7 @@ def test_copy_config_to_ext_loggers_custom_log_level(stdout, logger, log_level):
     assert log["level"] == log_level.WARNING.name
 
 
-def test_copy_config_to_ext_loggers_should_not_break_append_keys(stdout, logger, log_level):
+def test_copy_config_to_ext_loggers_should_not_break_append_keys(stdout, log_level):
     # GIVEN powertools logger initialized
     powertools_logger = Logger(service=service_name(), level=log_level.INFO.value, stream=stdout)
 
@@ -193,3 +193,82 @@ def test_copy_config_to_ext_loggers_should_not_break_append_keys(stdout, logger,
 
     # THEN append_keys should not raise an exception
     powertools_logger.append_keys(key="value")
+
+
+def test_copy_child_config_to_ext_loggers_should_not_break_append_keys(stdout):
+    # GIVEN powertools logger AND  child initialized AND
+
+    # GIVEN Loggers are initialized
+    # create child logger before parent to mimick
+    # importing logger from another module/file
+    # as loggers are created in global scope
+    service = service_name()
+    child = Logger(stream=stdout, service=service, child=True)
+    parent = Logger(stream=stdout, service=service)
+
+    # WHEN a child Logger adds an additional key AND child logger adds additional key
+    # AND configuration copied from powertools child logger
+    # AND powertools logger and child logger used
+    child.structure_logs(append=True, customer_id="value")
+    parent.structure_logs(append=True, user_id="value")
+    utils.copy_config_to_registered_loggers(source_logger=child)
+    parent.warning("Logger message")
+    child.warning("Child logger message")
+
+    # THEN both custom keys should be propagated bi-directionally in parent and child loggers
+    # as parent logger won't be touched when config is being copied
+    parent_log, child_log = capture_multiple_logging_statements_output(stdout)
+    assert "customer_id" in parent_log
+    assert "customer_id" in child_log
+    assert "user_id" in parent_log
+    assert "user_id" in child_log
+    assert "Child Logger message" not in parent_log
+    assert child.parent.name == service
+
+
+def test_copy_config_to_parent_loggers_only(stdout):
+    # GIVEN Powertools Logger and Child Logger are initialized
+    # and Powertools Logger config is copied over
+    service = service_name()
+    child = Logger(stream=stdout, service=service, child=True)
+    parent = Logger(stream=stdout, service=service)
+    utils.copy_config_to_registered_loggers(source_logger=parent)
+
+    # WHEN either parent or child logger append keys
+    child.append_keys(customer_id="value")
+    parent.append_keys(user_id="value")
+    parent.info("Logger message")
+    child.info("Child logger message")
+
+    # THEN both custom keys should be propagated bi-directionally in parent and child loggers
+    # as child logger won't be touched when config is being copied
+    parent_log, child_log = capture_multiple_logging_statements_output(stdout)
+    assert "customer_id" in parent_log, child_log
+    assert "user_id" in parent_log, child_log
+    assert child.parent.name == service
+
+
+def test_copy_config_to_ext_loggers_no_duplicate_logs(stdout, logger, log_level):
+    # GIVEN an root logger, external logger and powertools logger initialized
+
+    root_logger = logging.getLogger()
+    handler = logging.StreamHandler(stdout)
+    formatter = logging.Formatter('{"message": "%(message)s"}')
+    handler.setFormatter(formatter)
+    root_logger.addHandler(handler)
+
+    logger = logger()
+
+    powertools_logger = Logger(service=service_name(), level=log_level.CRITICAL.value, stream=stdout)
+    level = log_level.WARNING.name
+
+    # WHEN configuration copied from powertools logger
+    # AND external logger used with custom log_level
+    utils.copy_config_to_registered_loggers(source_logger=powertools_logger, include={logger.name}, log_level=level)
+    msg = "test message4"
+    logger.warning(msg)
+
+    # THEN no root logger logs AND log is not duplicated
+    logs = capture_multiple_logging_statements_output(stdout)
+    assert {"message": msg} not in logs
+    assert sum(msg in log.values() for log in logs) == 1