Skip to content

Clarify logger.structure_logs behavior  #195

Closed
@ivamluz

Description

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

Metadata

Metadata

Assignees

Labels

documentationImprovements or additions to documentation

Type

No type

Projects

Status

Triage

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions