Clarify logger.structure_logs behavior

[ivamluz]

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

1. 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?

2. If 2the two requests have the order_id parameter, and they are different, what is the expected behavior.

3. 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.

[heitorlessa]

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.

from aws_lambda_powertools import Logger

logger = Logger(child=True)

def handler(event, context):
   # It'll default to None if these keys don't exist in event
   order_id = event.get("order_id")
   other_param = event.get("other_param")

   # If order_id or other_param values are None they will be ignored
   # If such key already exists its value will be now overriden with None, and hence dropped from log keys
   logger.structure_logs(append=True, order_id=order_id, other_param=other_param)

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]

Thanks for your support, @heitorlessa . I'll give it a try soon.

[heitorlessa]

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]

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]

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 :)