Repository navigation
Clarify logger.structure_logs behavior #195
Description
What were you initially searching for in the docs?
Understand if logger.structure_logs affects the behavior of all requests or only the current one.
The documentation here shows an example of an order_id being appended to the logs:
def handler(event, context):
if "order_id" in event:
logger.structure_logs(append=True, order_id=event["order_id"])
logger.info("Collecting payment")Looking at the source code for the structure_logs method, I can see the existing formatters are going to be updated with the new arguments:
handlers = self._logger.parent.handlers if self.child else self._logger.handlers
for handler in handlers:
if append:
# Update existing formatter in an existing logger handler
handler.formatter.update_formatter(**kwargs)
else:
# Set a new formatter for a logger handler
handler.setFormatter(JsonFormatter(**self._default_log_keys, **kwargs))If I have a parent Logger object being initialized inside my package init.py like this:
import os
from logging import DEBUG
from aws_lambda_powertools import Logger
service_name = os.environ.get("POWERTOOLS_SERVICE_NAME", "my-app-name")
log_level = os.environ.get("LOG_LEVEL", DEBUG)
logger = Logger(service=service_name, level=log_level)Does it mean that the logger will be initialized once (in the cold start) and every call to logger.structure_logs will update the existing formatters, causing logging calls from different requests to be mixed up? For example, if I have something like this in my handler:
from aws_lambda_powertools import Logger
logger = Logger(child=True)
def handler(event, context):
if "order_id" in event:
logger.structure_logs(append=True, order_id=event["order_id"])
logger.info("Collecting payment")
else:
logger.structure_logs(append=True, other_param=event["other_param"])
logger.info("Missing order ID")And I receive two requests:
- First request has order_id parameter
- Second doesn't have order_id parameter
Questions
-
Does it mean the second request will also have the order_id included in the logs (because it was set by the first request, and the existing formatter was updated), even if this second one is expected not to have it logged?
-
If 2the two requests have the order_id parameter, and they are different, what is the expected behavior.
-
If the description above correctly describes the logging behavior, and this is by design, is there a recommended way to add structured log keys conditionally on a per-request basis?
Thanks in advance for any help you can provide on this matter.
Activity
heitorlessa commentedon Oct 21, 2020
Hey @ivamluz - Thank you for raising a high quality issue, and for using Powertools :)
Background. Your assumption is correct, as it also applies for anything outside the handler as it can be persisted across invocations when the execution context (Lambda container/process) is reused.
Recommended solution. You could solve your use case with good defaults by always including both keys. Any key added to the logger with an empty value will be discarded - Here's your last snippet updated.
Let us know if that makes sense - If it does, I'll mark this to update the docs to clarify this use case.
Thank you / Obrigado ;)
ivamluz commentedon Oct 21, 2020
Thanks for your support, @heitorlessa . I'll give it a try soon.
docs: add more info on conditional keys #195
Merge pull request #199 from heitorlessa/docs/clarify-dynamic-log-keys
heitorlessa commentedon Oct 25, 2020
hey @ivamluz,
We're preparing for 1.7.0 release tomorrow with a new parser, and I've just merged a documentation fix to address your original question- Here's a screenshot of how it'll look like tomorrow
Thank you (once again) for reporting it :)
heitorlessa commentedon Oct 26, 2020
Hey @ivamluz - I'm gonna close this as I can reproduce it, and docs have been updated as part of the 1.7.0 release with some exciting news too
Full release details: https://github.com/awslabs/aws-lambda-powertools-python/releases/tag/v1.7.0
ivamluz commentedon Oct 26, 2020
Hey, @heitorlessa , sorry for the delay in getting back to you.
I just tested your solution and it works. Thanks again for your support and congrats to the team for the great library. Just love how easy it is to implement custom middlewares with the help of it :)