Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bug: Child logger output does not reflect 'location' argument #5412

Closed
danieljandey opened this issue Oct 21, 2024 · 7 comments
Closed

Bug: Child logger output does not reflect 'location' argument #5412

danieljandey opened this issue Oct 21, 2024 · 7 comments
Assignees
Labels
bug Something isn't working help wanted Could use a second pair of eyes/hands logger

Comments

@danieljandey
Copy link

danieljandey commented Oct 21, 2024

Logger allows you to either change the format or suppress the following keys at initialization: location, timestamp, xray_trace_id.

https://docs.powertools.aws.dev/lambda/python/latest/core/logger/#overriding-log-records

Code provided are just examples. In real-world new loggers are being defined in classes. The 'service_name' needs to stay the same for all the loggers (Through the environment variable) as the Lambda context needs to be included in all loggers (which will be defined at the entrypoint / above 'lambda_handler')

Documentation example code:
https://docs.powertools.aws.dev/lambda/python/2.21.0/core/logger/#set_correlation_id-method

from aws_lambda_powertools import Logger
from aws_lambda_powertools.logging import correlation_paths
from aws_lambda_powertools.utilities.typing import LambdaContext

logger = Logger()

@logger.inject_lambda_context(correlation_id_path=correlation_paths.API_GATEWAY_REST)
def lambda_handler(event: dict, context: LambdaContext) -> str:
    pass

Expected Behaviour

Expected Output:

See 'location' key:

{"level":"INFO","location":"Test1","message":"Test1","timestamp":"2024-10-21 05:38:47,710+0000","service":"payment"}
{"level":"INFO","location":"Test2","message":"Test2","timestamp":"2024-10-21 05:38:47,710+0000","service":"payment"}

Current Behaviour

Actual Output:

See 'location' key:

{"level":"INFO","location":"Test1","message":"Test1","timestamp":"2024-10-21 05:38:47,710+0000","service":"payment"}
{"level":"INFO","location":"Test1","message":"Test2","timestamp":"2024-10-21 05:38:47,710+0000","service":"payment"}

Code snippet

from aws_lambda_powertools import Logger

logger = Logger(
    service="payment",
    location="Test1"
)

logger.info("Test1")

logger = Logger(
    service="payment",
    child=True,
    location="Test2"
)

logger.info("Test2")

Possible Solution

Unsure - need to fork and package locally, but am looking at the code:

https://github.com/aws-powertools/powertools-lambda-python/blob/develop/aws_lambda_powertools/logging/logger.py#L295C1-L297C19

 def _init_logger(
        self,
        formatter_options: dict | None = None,
        log_level: str | int | None = None,
        **kwargs,
    ) -> None:
        """Configures new logger"""

        # Skip configuration if it's a child logger or a pre-configured logger
        # to prevent the following:
        #   a) multiple handlers being attached
        #   b) different sampling mechanisms
        #   c) multiple messages from being logged as handlers can be duplicated
        is_logger_preconfigured = getattr(self._logger, LOGGER_ATTRIBUTE_PRECONFIGURED, False)
        if self.child or is_logger_preconfigured:
            return

Steps to Reproduce

See code snippet above

Powertools for AWS Lambda (Python) version

latest

AWS Lambda function runtime

3.12

Packaging format used

PyPi

Debugging logs

No response

@danieljandey danieljandey added bug Something isn't working triage Pending triage from maintainers labels Oct 21, 2024
Copy link

boring-cyborg bot commented Oct 21, 2024

Thanks for opening your first issue here! We'll come back to you as soon as we can.
In the meantime, check out the #python channel on our Powertools for AWS Lambda Discord: Invite link

@leandrodamascena
Copy link
Contributor

Hey @danieljandey thanks for opening this issue! I'll take a look this week and come back here with some update.

@leandrodamascena leandrodamascena removed the triage Pending triage from maintainers label Oct 22, 2024
@leandrodamascena leandrodamascena moved this from Triage to Pending review in Powertools for AWS Lambda (Python) Oct 22, 2024
@leandrodamascena
Copy link
Contributor

Hi @danieljandey! I managed to reproduce the scenario and I'm working on a solution for it. I hope to have a PR somewhere this week or next week.

@leandrodamascena
Copy link
Contributor

You are right and I can confirm that the problem is in this part of the code @danieljandey

https://github.com/aws-powertools/powertools-lambda-python/blob/develop/aws_lambda_powertools/logging/logger.py#L295C1-L297C19

I also found a few other bugs when working with child loggers. The standard Python logging library allows you to change the log level, for example, but we don't. Our child logger implementation inherits all the properties of the parent logger and add the filename to the parent name, which is sufficient in most cases, but creates a limitation in other cases.

Default Python Library

import logging

parent_logger = logging.getLogger('parent')
parent_logger.setLevel(logging.DEBUG)

parent_handler = logging.StreamHandler()
parent_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
parent_handler.setFormatter(parent_formatter)
parent_logger.addHandler(parent_handler)
parent_logger.setLevel("INFO")

child_logger = logging.getLogger('parent.child')

child_handler = logging.StreamHandler()
child_formatter = logging.Formatter('%(name)s [%(filename)s:%(lineno)d] - %(levelname)s - %(message)s')
child_handler.setFormatter(child_formatter)
child_logger.addHandler(child_handler)
child_logger.setLevel("DEBUG")

parent_logger.debug("This is a parent logger message") # LogLevel of "parent" is INFO, won't be printed
child_logger.debug("This is a child logger message") # LogLevel of "parent.child" is DEBUG, will be printed

Powertools

from aws_lambda_powertools import Logger

logger = Logger(
    service="payment",
    location="Test1",
    level="INFO"
)

logger2 = Logger(
    service="payment",
    child=True,
    location="Test2",
    level="DEBUG" # This doesn't take effect
)

I don't know if I can fix this issue with our current implementation and without making breaking changes, but while I research how to fix this bug, I will fix other possible bugs like this logLevel.

@leandrodamascena
Copy link
Contributor

I didn't make any progress on this issue and will try to have a final decision on whether we'll assume this is a known bug and fix it in v4 or if I have some sort of workaround. I'm adding this issue to our the next iteration, starting next week.

@leandrodamascena leandrodamascena self-assigned this Feb 17, 2025
@leandrodamascena
Copy link
Contributor

Hi everyone! I was trying to make it work with our current implementation, but unfortunately I can't make it work with a breaking change or potential regression bug. A child logger instance is basically a copy of the parent instance, but with a different name and optionally you can set a new log level. When it comes to setting things that change the format of the logger, it's not possible because a child logger must inherit (in our current implementation) the same handler as the parent logger instance and things like location are set in the handler. A possibility could be create a specific handler for a child logger, but idk the consequences and we had some bug reports about this in the past.

I'm closing this issue now as can't fix and will add a note to our current discussion about things that will be changed or included in Powertools v4 - #5948.

I'm sorry, but I can't get it to work here in our current implementation.

@leandrodamascena leandrodamascena closed this as not planned Won't fix, can't repro, duplicate, stale Feb 25, 2025
@github-project-automation github-project-automation bot moved this from Backlog to Coming soon in Powertools for AWS Lambda (Python) Feb 25, 2025
Copy link
Contributor

⚠️COMMENT VISIBILITY WARNING⚠️

This issue is now closed. Please be mindful that future comments are hard for our team to see.

If you need more assistance, please either tag a team member or open a new issue that references this one.

If you wish to keep having a conversation with other community members under this issue feel free to do so.

@leandrodamascena leandrodamascena moved this from Coming soon to Closed in Powertools for AWS Lambda (Python) Feb 27, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working help wanted Could use a second pair of eyes/hands logger
Projects
Development

No branches or pull requests

4 participants