CODEWITHSUNDEEP
pythonpython-3.xamazon-web-servicesaws-lambda
rodrigocf
rodrigocf

Reputation: 2099

Custom log file in Lambda with Python

I have some requirements for which I need my lambda functions to generate a text file with logs in json format and upload it to S3, from S3 we have a Spectrum table which run later processes on. I know there might be different ways of doing this using cloudwatch, but we have to stick to this because of the later processes we run on the logs. Now... the problem is, I got the code working fine on my machine. When I test the function, it works... only the first time. After some troubleshooting, here is a way to replicate it:

import json
import os
import os
import platform
from urllib.request import urlopen
import logging
import sys
from datetime import datetime
from os import listdir
from os.path import isfile, join

def log_start(log_prefix):
    now = datetime.now()
    log_id = str(now).replace(':', '').replace(' ', '').replace('.', '').replace('-', '')[:14]
    log_name = '/tmp/{}_{}.txt'.format(log_prefix, log_id)

    root = logging.getLogger()
    if root.handlers:
        for handler in root.handlers:
            root.removeHandler(handler)

    logging.basicConfig(level=logging.INFO, filename=log_name, filemode='a+',
                        format='''{{"log_id":"{}", "created_date":"%(asctime)s.%(msecs)03d", "action_text":"%(message)s"}}'''.format(
                            log_id),
                        datefmt="%Y-%m-%dT%H:%M:%S")
    root = logging.getLogger()
    root.setLevel(logging.INFO)

    handler = logging.StreamHandler(sys.stdout)
    handler.setLevel(logging.INFO)
    formatter = logging.Formatter(
        '''{{"log_id":"{}", "created_date":"%(asctime)s.%(msecs)03d", "action_text":"%(message)s"}}'''.format(
            log_id),
        datefmt="%Y-%m-%dT%H:%M:%S")
    handler.setFormatter(formatter)
    root.addHandler(handler)

    return log_name, log_id

def lambda_handler(event, context):
    
    log_name, log_id = log_start('log_prefix')
    logging.info('test')
    print(log_name)
    print(log_id)
    print(isfile(log_name))

If you run this several times, you will notice that the last print statement returns true the first time, and then it is always false. If i run it again in say, an hour, same thing, first true then false all the time. Why is this happening? Why does it work just one time?

EDIT: This can't be because of /tmp running out of space. This issue also happens if I mount an EFS drive and try to direct the log file to the EFS drive.

Upvotes: 2

Views: 1668

Answers (1)

rodrigocf
rodrigocf

Reputation: 2099

After a lot of troubleshooting, I realized the problem was here:

if root.handlers:
    for handler in root.handlers:
        root.removeHandler(handler)

The reason being, removeHandler removes an item from handlers (a list) in the middle of the loop. So in the second run, it doesn't remove all the handlers correctly. The solution was to change it to:

if root.handlers:
    handlers = []

And problem solved. :)

Upvotes: 2

Related Questions