Skip to content

improv: keeps Lambda root logger handler, and add log filter instead to prevent child log records duplication #198

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 3 commits into from
Oct 25, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
16 changes: 16 additions & 0 deletions aws_lambda_powertools/logging/filters.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,16 @@
import logging


class SuppressFilter(logging.Filter):
def __init__(self, logger):
self.logger = logger

def filter(self, record): # noqa: A003
"""Suppress Log Records from registered logger

It rejects log records from registered logger e.g. a child logger
otherwise it honours log propagation from any log record
created by loggers who don't have a handler.
"""
logger = record.name
return False if self.logger in logger else True
15 changes: 8 additions & 7 deletions aws_lambda_powertools/logging/logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
from typing import Any, Callable, Dict, Union

from .exceptions import InvalidLoggerSamplingRateError
from .filters import SuppressFilter
from .formatter import JsonFormatter
from .lambda_context import build_lambda_context_model

Expand Down Expand Up @@ -147,13 +148,6 @@ def _get_logger(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
Expand All @@ -163,6 +157,13 @@ def _init_logger(self, **kwargs):
self._logger.addHandler(self._handler)
self.structure_logs(**kwargs)

logger.debug("Adding filter in root logger to suppress child logger records to bubble up")
for handler in logging.root.handlers:
# It'll add a filter to suppress any child logger from self.service
# Where service is Order, it'll reject parent logger Order,
# and child loggers such as Order.checkout, Order.shared
handler.addFilter(SuppressFilter(self.service))

def _configure_sampling(self):
"""Dynamically set log level based on sampling rate

Expand Down
16 changes: 8 additions & 8 deletions tests/functional/test_logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -361,18 +361,18 @@ def test_logger_record_caller_location(stdout):
assert caller_fn_name in log["location"]


def test_logger_do_not_log_twice(stdout):
def test_logger_do_not_log_twice_when_root_logger_is_setup(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
# WHEN we create a new Logger and child Logger
logger = Logger(stream=stdout)
child_logger = Logger(child=True, stream=stdout)
logger.info("hello")
child_logger.info("hello again")

# 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")
# THEN it should only contain only two log entries
# since child's log records propagated to root logger should be rejected
logs = list(stdout.getvalue().strip().split("\n"))
assert len(logs) == 2