feat: logger inheritance

[heitorlessa]

Issue #, if available: #97

Description of changes:

This addresses a common issue when trying to use Logger across multiple modules while wanting to:

• Create a new child Logger to inherit parent Logger's configuration (handler, formatter, custom keys, sampling)
• Reuse the same Logger, where Logger is enriched iteratively across the code base

For this, we've introduced a new parameter, child, when initializing a new Logger, and some internal changes while keeping the same UX and backwards compatibility.

• [Internal] Direct access to methods, handlers, etc work as before, except that we proxy properties access to ._logger

UX

Key aspects:

• We support logging inheritance via the child parameter, and the Logger will be named after <service>.<caller_file_name>
• Calling Logger with the same service name (explicit or via environment variable) returns the same Logger
• Changes to either Child Logger or Parent Logger will be propagated to all instances

Creating a child Logger

Child logger can be created in any other as long as a parent is created too - This supports customers using Layers or different file names to create child loggers.

# lambda_handler.py
from aws_lambda_powertools import Logger
import collect

logger = Logger(service="payment") # parent Logger just like before, named 'payment'
...

# collect.py
from aws_lambda_powertools import Logger

logger = Logger(service="payment", child=True) # child Logger named 'payment.collect'

# a_new_key will now be available both in this child logger as well as the parent
logger.structure_logs(append=True, a_new_key="value") 
...

Reusing the same Logger

# lambda_handler.py
from aws_lambda_powertools import Logger
import collect

logger = Logger(service="payment") # parent Logger just like before, named 'payment'

# collect.py
from aws_lambda_powertools import Logger

logger = Logger(service="payment") # returns the existing 'payment' Logger
...

Checklist

• Meet tenets criteria
• Update tests
• Update docs
• PR title follows conventional commit semantics

Changes

• Register logger via getLogger to allow inheritance
• Encapsulate logger initialization/config in a new method
• Remove Logger sub-classing
  • Proxy calls to underneath Logger instead
• Create name parameter for hierarchy
  • Use service if name is empty
• Test on Lambda locally
  • Single Logger, no code changes
  • Two Loggers in different files
  • Additional Logger in a package that is imported on main entry-point
  • Lambda Layer
• Only add a handler if there isn't one
• Only add a handler if parent is root
• Update Formatter to append new keys
• Make handler private
• Remove log_keys
• Remove duplicate Parameters in docstring
• Double check Debug w/ getattr perf impact
• Docs: Document inheriting Loggers
• Docs: Changelog (doc random logger for tests)
• Test: Logger hierarchy via logger.parent
• Remove name parameter
• Allow logger child propagation
• Introduce child boolean param
• Don't add a handler nor evaluate sampling if it's a child Logger
• Name child Loggers based on <service>.<caller_file_name> to mimick getLogger(__name__)
• Update tests to remove Handler on every test
• Update tests to remove getRandomLogger utility function

Optional

• Ensure log level input is case insensitive

Benchmark

TL;DR: For the average use case we have a slight performance decrease, but all negligible in all cases (0.10 nano seconds).

Quick checks as we've removed logging.Logger sub-classing, respect Logging inheritance, and are proxying calls to inner Logger.

Basic logger

• Script: python -m timeit -s 'from aws_lambda_powertools import Logger; logger = Logger(); logger.info("hello world")'
• Before: 50000000 loops, best of 5: 6.12 nsec per loop
• After with Logger proxy object, no sub-classing: 50000000 loops, best of 5: 6.22 nsec per loop

Inheritance

• Script: python -m timeit -s 'from aws_lambda_powertools import Logger; logger = Logger(); l = Logger(); l.info("hello world")'
• Same logger: 50000000 loops, best of 5: 6.28 nsec per loop
• Random child logger name + fixup: 50000000 loops, best of 5: 6.14 nsec per loop
  • Script: python -m timeit -s 'from aws_lambda_powertools import Logger; logger = Logger(child=True); l = Logger(); l.info("hello world")'

Breaking change checklist

RFC issue #:

• Migration process documented
• Implement warnings (if it can live side by side)

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

[codecov-commenter]

Codecov Report

Merging #99 into develop will not change coverage.
The diff coverage is 100.00%.

@@            Coverage Diff            @@
##           develop       #99   +/-   ##
=========================================
  Coverage   100.00%   100.00%           
=========================================
  Files           17        17           
  Lines          467       497   +30     
  Branches        42        45    +3     
=========================================
+ Hits           467       497   +30     

Impacted Files	Coverage Δ
aws_lambda_powertools/logging/formatter.py	100.00% <100.00%> (ø)
aws_lambda_powertools/logging/logger.py	100.00% <100.00%> (ø)
aws_lambda_powertools/tracing/tracer.py	100.00% <0.00%> (ø)
aws_lambda_powertools/metrics/metrics.py	100.00% <0.00%> (ø)
...ws_lambda_powertools/middleware_factory/factory.py	100.00% <0.00%> (ø)

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 0c75ef1...490119f. Read the comment docs.

[alexanderluiscampino]

Superb work overall. Can't wait to use it!

[heitorlessa]

Just addressed @alexanderluiscampino commentson consistency, and took the opportunity to turnlog level input to case insensitive to prevent common mistakes for newcomers.

I'll start working on the docs this afternoon or tomorrow, and should release a minor version by EOW

[heitorlessa]

Yep it’s fixed in the latest commit ;)

…

On Wed, 12 Aug 2020 at 09:32, Alexandre Campino ***@***.***> wrote: ***@***.**** commented on this pull request. ------------------------------ In aws_lambda_powertools/logging/logger.py <#99 (comment)> : > @@ -118,7 +118,7 @@ def __init__( ): self.service = service or os.getenv("POWERTOOLS_SERVICE_NAME") or "service_undefined" self.sampling_rate = sampling_rate or os.getenv("POWERTOOLS_LOGGER_SAMPLE_RATE") or 0.0 - self.log_level = level or os.getenv("LOG_LEVEL") or logging.INFO + self.log_level = level or os.getenv("LOG_LEVEL".upper()) or logging.INFO Gotcha, your explanation makes sense, then you need the .upper outside of the getenv(LOG_LEVEL).UPPER() — You are receiving this because you were assigned. Reply to this email directly, view it on GitHub <#99 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAZPQBH7FMGNN2SRN76WK2TSAJAQDANCNFSM4PZATT2Q> .