AWS Cloudwatch Logs Multiple Times from single log call

Question

I wrote a wrapper logging library on top of another logging library that uses Python's built in logging library. Below is a snippet.

import logging


class Foo(Bar):
    def __init__(self):
        self.logger.propagate = False
        ...

    def info(self, msg, *args, **kwargs):
        ...
        super().info(msg, *args, **kwargs)
    
class Bar:
    def __init__(self):
        self.logger = logging.getLogger("logger name")

    def info(self, msg, *args, **kwargs):
        ...
        self.logger.info(msg, *args, **kwargs)

### In handler.py ###
def lambda_handler(event, context):
    foo = Foo()
    foo.info("my msg")

However, when I use Foo in the AWS Lambda, I end up with multiple logs like so:

I understand that the final [INFO] log is from AWS, but why are my logs still being outputted the 2 additional times? I set propagate = False as recommended by other questions, but it does not appear to have an effect.

Answer 1

The cause of my bug was a bit of a perfect storm. Firstly, an instance AWS Lambda, as many know, will continue running even after the request is handled. This results in some persistence of objects already created, in particular, the logger.

I later found this question which told me that every time I call logging.getLogger(...), I am adding a handler to the logger. Each of these handlers would then proceed to create a log line, resulting in multiple log lines.

I wasn't sure of the proper way to handle this, as the solution required me to clear all handlers and create my own each time, which I was not in favour of as I don't understand the internal workings of the logger and handler.

In the end, I did the following to ensure I only ever had the one handler:

class Foo(Bar):
    def __init__(self):
        self.logger.propagate = False
        self.logger.handlers = self.logger.handlers[:1] # add this line
        ...

    def info(self, msg, *args, **kwargs):
        ...
        super().info(msg, *args, **kwargs)