Skip to content

Commit b808b1a

Browse files
authored
feat: add support for logger inheritance (#99)
* chore: uppercase env var log level value Signed-off-by: heitorlessa <[email protected]> * feat: add keys to existing formatter Signed-off-by: heitorlessa <[email protected]> * chore: remove duplicate parameters docstring Signed-off-by: heitorlessa <[email protected]> * feat: add name parameter Signed-off-by: heitorlessa <[email protected]> * feat: support logging inheritance * chore: spelling Signed-off-by: heitorlessa <[email protected]> * improv: make handler prop private Signed-off-by: heitorlessa <[email protected]> * feat: fetch random logger; remove dead loc * improv: cover child logger independence * improv: addresses nico feedback on missing test Signed-off-by: heitorlessa <[email protected]> * fix: docstring name parameter short description Signed-off-by: heitorlessa <[email protected]> * improv: logger inheritance via child param Signed-off-by: heitorlessa <[email protected]> * improv: update tests Signed-off-by: heitorlessa <[email protected]> * improv: logger test utility no longer necessary Signed-off-by: heitorlessa <[email protected]> * improv: make test name more descriptive Signed-off-by: heitorlessa <[email protected]> * fix: remove logger utility as it's no longer used Signed-off-by: heitorlessa <[email protected]> * fix: address feedback on consistency Signed-off-by: heitorlessa <[email protected]> * improv: turn log_level input case insensitive * chore: add unreleased changes to Logger * docs: adds reusing logger across your code section Documents new Logger feature to support logging inheritance using the new `child` parameter.
1 parent 40972d2 commit b808b1a

File tree

6 files changed

+191
-77
lines changed

6 files changed

+191
-77
lines changed

CHANGELOG.md

+5
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,11 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
55
and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html).
66

77
## [Unreleased]
8+
### Added
9+
- **Logger**: Support for logger inheritance with `child` parameter
10+
11+
### Fixed
12+
- **Logger**: Log level is now case insensitive via params and env var
813

914
## [1.0.2] - 2020-07-16
1015
### Fixed

aws_lambda_powertools/logging/formatter.py

+3
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,9 @@ def __init__(self, **kwargs):
5656
self.format_dict.update(kwargs)
5757
self.default_json_formatter = kwargs.pop("json_default", json_formatter)
5858

59+
def update_formatter(self, **kwargs):
60+
self.format_dict.update(kwargs)
61+
5962
def format(self, record): # noqa: A003
6063
record_dict = record.__dict__.copy()
6164
record_dict["asctime"] = self.formatTime(record, self.datefmt)

aws_lambda_powertools/logging/logger.py

+85-33
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
1-
import copy
21
import functools
2+
import inspect
33
import logging
44
import os
55
import random
@@ -34,7 +34,7 @@ def _is_cold_start() -> bool:
3434
return cold_start
3535

3636

37-
class Logger(logging.Logger):
37+
class Logger:
3838
"""Creates and setups a logger to format statements in JSON.
3939
4040
Includes service name and any additional key=value into logs
@@ -55,6 +55,8 @@ class Logger(logging.Logger):
5555
service name to be appended in logs, by default "service_undefined"
5656
level : str, optional
5757
logging.level, by default "INFO"
58+
child: bool, optional
59+
create a child Logger named <service>.<caller_file_name>, False by default
5860
sample_rate: float, optional
5961
sample rate for debug calls within execution context defaults to 0.0
6062
stream: sys.stdout, optional
@@ -80,7 +82,7 @@ class Logger(logging.Logger):
8082
>>> def handler(event, context):
8183
logger.info("Hello")
8284
83-
**Append payment_id to previously setup structured log logger**
85+
**Append payment_id to previously setup logger**
8486
8587
>>> from aws_lambda_powertools import Logger
8688
>>> logger = Logger(service="payment")
@@ -89,18 +91,16 @@ class Logger(logging.Logger):
8991
logger.structure_logs(append=True, payment_id=event["payment_id"])
9092
logger.info("Hello")
9193
92-
Parameters
93-
----------
94-
logging : logging.Logger
95-
Inherits Logger
96-
service: str
97-
name of the service to create the logger for, "service_undefined" by default
98-
level: str, int
99-
log level, INFO by default
100-
sampling_rate: float
101-
debug log sampling rate, 0.0 by default
102-
stream: sys.stdout
103-
log stream, stdout by default
94+
**Create child Logger using logging inheritance via child param**
95+
96+
>>> # app.py
97+
>>> import another_file
98+
>>> from aws_lambda_powertools import Logger
99+
>>> logger = Logger(service="payment")
100+
>>>
101+
>>> # another_file.py
102+
>>> from aws_lambda_powertools import Logger
103+
>>> logger = Logger(service="payment", child=True)
104104
105105
Raises
106106
------
@@ -112,19 +112,72 @@ def __init__(
112112
self,
113113
service: str = None,
114114
level: Union[str, int] = None,
115+
child: bool = False,
115116
sampling_rate: float = None,
116117
stream: sys.stdout = None,
117118
**kwargs,
118119
):
119120
self.service = service or os.getenv("POWERTOOLS_SERVICE_NAME") or "service_undefined"
120121
self.sampling_rate = sampling_rate or os.getenv("POWERTOOLS_LOGGER_SAMPLE_RATE") or 0.0
121-
self.log_level = level or os.getenv("LOG_LEVEL") or logging.INFO
122-
self.handler = logging.StreamHandler(stream) if stream is not None else logging.StreamHandler(sys.stdout)
122+
self.log_level = self._get_log_level(level)
123+
self.child = child
124+
self._handler = logging.StreamHandler(stream) if stream is not None else logging.StreamHandler(sys.stdout)
123125
self._default_log_keys = {"service": self.service, "sampling_rate": self.sampling_rate}
124-
self.log_keys = copy.copy(self._default_log_keys)
125-
126-
super().__init__(name=self.service, level=self.log_level)
127-
126+
self._logger = self._get_logger()
127+
128+
self._init_logger(**kwargs)
129+
130+
def __getattr__(self, name):
131+
# Proxy attributes not found to actual logger to support backward compatibility
132+
# https://github.com/awslabs/aws-lambda-powertools-python/issues/97
133+
return getattr(self._logger, name)
134+
135+
def _get_log_level(self, level: str):
136+
""" Returns preferred log level set by the customer in upper case """
137+
log_level: str = level or os.getenv("LOG_LEVEL")
138+
log_level = log_level.upper() if log_level is not None else logging.INFO
139+
140+
return log_level
141+
142+
def _get_logger(self):
143+
""" Returns a Logger named {self.service}, or {self.service.filename} for child loggers"""
144+
logger_name = self.service
145+
if self.child:
146+
logger_name = f"{self.service}.{self._get_caller_filename()}"
147+
148+
return logging.getLogger(logger_name)
149+
150+
def _get_caller_filename(self):
151+
""" Return caller filename by finding the caller frame """
152+
# Current frame => _get_logger()
153+
# Previous frame => logger.py
154+
# Before previous frame => Caller
155+
frame = inspect.currentframe()
156+
caller_frame = frame.f_back.f_back.f_back
157+
filename = caller_frame.f_globals["__name__"]
158+
159+
return filename
160+
161+
def _init_logger(self, **kwargs):
162+
"""Configures new logger"""
163+
164+
# Skip configuration if it's a child logger to prevent
165+
# multiple handlers being attached as well as different sampling mechanisms
166+
# and multiple messages from being logged as handlers can be duplicated
167+
if not self.child:
168+
self._configure_sampling()
169+
self._logger.setLevel(self.log_level)
170+
self._logger.addHandler(self._handler)
171+
self.structure_logs(**kwargs)
172+
173+
def _configure_sampling(self):
174+
"""Dynamically set log level based on sampling rate
175+
176+
Raises
177+
------
178+
InvalidLoggerSamplingRateError
179+
When sampling rate provided is not a float
180+
"""
128181
try:
129182
if self.sampling_rate and random.random() <= float(self.sampling_rate):
130183
logger.debug("Setting log level to Debug due to sampling rate")
@@ -134,12 +187,8 @@ def __init__(
134187
f"Expected a float value ranging 0 to 1, but received {self.sampling_rate} instead. Please review POWERTOOLS_LOGGER_SAMPLE_RATE environment variable." # noqa E501
135188
)
136189

137-
self.setLevel(self.log_level)
138-
self.structure_logs(**kwargs)
139-
self.addHandler(self.handler)
140-
141190
def inject_lambda_context(self, lambda_handler: Callable[[Dict, Any], Any] = None, log_event: bool = False):
142-
"""Decorator to capture Lambda contextual info and inject into struct logging
191+
"""Decorator to capture Lambda contextual info and inject into logger
143192
144193
Parameters
145194
----------
@@ -216,21 +265,24 @@ def structure_logs(self, append: bool = False, **kwargs):
216265
append : bool, optional
217266
[description], by default False
218267
"""
219-
self.handler.setFormatter(JsonFormatter(**self._default_log_keys, **kwargs))
220-
221-
if append:
222-
new_keys = {**self.log_keys, **kwargs}
223-
self.handler.setFormatter(JsonFormatter(**new_keys))
224268

225-
self.log_keys.update(**kwargs)
269+
# Child loggers don't have handlers attached, use its parent handlers
270+
handlers = self._logger.parent.handlers if self.child else self._logger.handlers
271+
for handler in handlers:
272+
if append:
273+
# Update existing formatter in an existing logger handler
274+
handler.formatter.update_formatter(**kwargs)
275+
else:
276+
# Set a new formatter for a logger handler
277+
handler.setFormatter(JsonFormatter(**self._default_log_keys, **kwargs))
226278

227279

228280
def set_package_logger(
229281
level: Union[str, int] = logging.DEBUG, stream: sys.stdout = None, formatter: logging.Formatter = None
230282
):
231283
"""Set an additional stream handler, formatter, and log level for aws_lambda_powertools package logger.
232284
233-
**Package log by default is supressed (NullHandler), this should only used for debugging.
285+
**Package log by default is suppressed (NullHandler), this should only used for debugging.
234286
This is separate from application Logger class utility**
235287
236288
Example

docs/content/core/logger.mdx

+35
Original file line numberDiff line numberDiff line change
@@ -183,6 +183,41 @@ def handler(event, context):
183183
```
184184
</details>
185185

186+
## Reusing Logger across your code
187+
188+
Logger supports inheritance via `child` parameter. This allows you to create multiple Loggers across your code base, and propagate changes such as new keys to all Loggers.
189+
190+
```python:title=collect.py
191+
# POWERTOOLS_SERVICE_NAME: "payment"
192+
import shared # Creates a child logger named "payment.shared"
193+
from aws_lambda_powertools import Logger
194+
195+
logger = Logger()
196+
197+
def handler(event, context):
198+
shared.inject_payment_id(event) # highlight-line
199+
logger.structure_logs(append=True, order_id=event["order_id"]) # highlight-line
200+
...
201+
```
202+
203+
```python:title=shared.py
204+
# POWERTOOLS_SERVICE_NAME: "payment"
205+
from aws_lambda_powertools import Logger
206+
207+
logger = Logger(child=True) # highlight-line
208+
209+
def inject_payment_id(event):
210+
logger.structure_logs(append=True, payment_id=event["payment_id"])
211+
```
212+
213+
In this example, `Logger` will create a parent logger named `payment` and a child logger named `payment.shared`. Any changes in the parent and child `Loggers` will be propagated among them.
214+
215+
If you ever forget to use `child` param, we will return an existing `Logger` with the same `service` name.
216+
217+
<Note type="info">
218+
Child loggers will be named after the following convention <code>service.filename</code>.
219+
</Note><br/>
220+
186221
## Sampling debug logs
187222

188223
You can dynamically set a percentage of your logs to **DEBUG** level using `sample_rate` param or via env var `POWERTOOLS_LOGGER_SAMPLE_RATE`.

tests/functional/test_aws_lambda_logging.py

+6-28
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,6 @@
11
"""aws_lambda_logging tests."""
22
import io
33
import json
4-
import logging
54

65
import pytest
76

@@ -13,25 +12,8 @@ def stdout():
1312
return io.StringIO()
1413

1514

16-
@pytest.fixture
17-
def handler(stdout):
18-
return logging.StreamHandler(stdout)
19-
20-
21-
@pytest.fixture
22-
def logger():
23-
return logging.getLogger(__name__)
24-
25-
26-
@pytest.fixture
27-
def root_logger(handler):
28-
logging.root.addHandler(handler)
29-
yield logging.root
30-
logging.root.removeHandler(handler)
31-
32-
3315
@pytest.mark.parametrize("level", ["DEBUG", "WARNING", "ERROR", "INFO", "CRITICAL"])
34-
def test_setup_with_valid_log_levels(root_logger, stdout, level):
16+
def test_setup_with_valid_log_levels(stdout, level):
3517
logger = Logger(level=level, stream=stdout, request_id="request id!", another="value")
3618
msg = "This is a test"
3719
log_command = {
@@ -55,7 +37,7 @@ def test_setup_with_valid_log_levels(root_logger, stdout, level):
5537
assert "exception" not in log_dict
5638

5739

58-
def test_logging_exception_traceback(root_logger, stdout):
40+
def test_logging_exception_traceback(stdout):
5941
logger = Logger(level="DEBUG", stream=stdout, request_id="request id!", another="value")
6042

6143
try:
@@ -69,7 +51,7 @@ def test_logging_exception_traceback(root_logger, stdout):
6951
assert "exception" in log_dict
7052

7153

72-
def test_setup_with_invalid_log_level(root_logger, logger, stdout):
54+
def test_setup_with_invalid_log_level(stdout):
7355
with pytest.raises(ValueError) as e:
7456
Logger(level="not a valid log level")
7557
assert "Unknown level" in e.value.args[0]
@@ -82,11 +64,7 @@ def check_log_dict(log_dict):
8264
assert "message" in log_dict
8365

8466

85-
def test_setup_with_bad_level_does_not_fail():
86-
Logger("DBGG", request_id="request id!", another="value")
87-
88-
89-
def test_with_dict_message(root_logger, stdout):
67+
def test_with_dict_message(stdout):
9068
logger = Logger(level="DEBUG", stream=stdout)
9169

9270
msg = {"x": "isx"}
@@ -97,7 +75,7 @@ def test_with_dict_message(root_logger, stdout):
9775
assert msg == log_dict["message"]
9876

9977

100-
def test_with_json_message(root_logger, stdout):
78+
def test_with_json_message(stdout):
10179
logger = Logger(stream=stdout)
10280

10381
msg = {"x": "isx"}
@@ -108,7 +86,7 @@ def test_with_json_message(root_logger, stdout):
10886
assert msg == log_dict["message"]
10987

11088

111-
def test_with_unserialisable_value_in_message(root_logger, stdout):
89+
def test_with_unserialisable_value_in_message(stdout):
11290
logger = Logger(level="DEBUG", stream=stdout)
11391

11492
class X:

0 commit comments

Comments
 (0)