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.

Is that your actual lambda code? You have defined no handler to actually handle the request, that results in the code running during import and execution environment setup once already and will cause all sorts of weird behavior. — luk2302, Mar 22 '22 at 07:36
No, its not the exact lambda code, but a snippet of the logging code that I use in the lambda handler. — Ryan T., Mar 22 '22 at 07:39

score 1 · Accepted Answer · answered Mar 24 '22 at 01:47

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)

A simpler solution would be to instantiate `Foo` outside of the handler. — gshpychka, Mar 24 '22 at 17:02
ah yes, while I was working on this temporary solution, I got the same idea. I'm looking into refactoring `Foo` into a singleton. Thanks for the input! — Ryan T., Mar 28 '22 at 02:22

AWS Cloudwatch Logs Multiple Times from single log call

1 Answers1