Change Python logger format in AWS Lambda

change_lambda_logger_format.py

# Python logger in AWS Lambda has a preset format. To change the format of the logging statement, 
# remove the logging handler & add a new handler with the required format

import logging
import sys

def setup_logging():
    logger = logging.getLogger()
    for h in logger.handlers:
      logger.removeHandler(h)
    
    h = logging.StreamHandler(sys.stdout)
    
    # use whatever format you want here
    FORMAT = '%(asctime)s %(message)s'
    h.setFormatter(logging.Formatter(FORMAT))
    logger.addHandler(h)
    logger.setLevel(logging.INFO)
    
    return logger

def lambda_handler(event, context):
    logger = setup_logging()
    logger.info("This is a test log statement!")
    return
    
# Expected output from Lambda:
# 
# START RequestId: 1a2b3c4d-abcd-1234-efgh-1a2b3c4d5e6f Version: $LATEST
# 2017-10-06 22:40:59,653 This is a test log statement!
# END RequestId: 1a2b3c4d-abcd-1234-efgh-1a2b3c4d5e6f
# REPORT RequestId: 1a2b3c4d-abcd-1234-efgh-1a2b3c4d5e6f	Duration: 0.41 ms	Billed Duration: 100 ms 	Memory Size: 128 MB	Max Memory Used: 21 MB

doesn't seem to be working anymore... at least in my case

Still works. I updated the gist to make it a self-contained Python 3.6 function that you can copy & paste in to the AWS Lambda Console in a web browser. Expected output is shown at the bottom. The string "This is a test log statement" should be present in the output. All other output details will differ.

Lambda appears to be doing some additional trickery behind the scenes in its default handler to convert newlines within messages to \r so that CloudWatch groups them together in one log. Replacing the handler loses this behavior, so tracebacks then get split across multiple entries.

In order to preserve the original behavior and keep tracebacks grouped together in one message, you can just update the format of the existing handler like:

FORMAT = "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
logger = logging.getLogger()
for h in logger.handlers:
  h.setFormatter(logging.Formatter(FORMAT))
logger.setLevel(logging.INFO)

I managed to extract the default log format from lambda runtime and it is:

"[%(levelname)s]\t%(asctime)s.%(msecs)dZ\t%(aws_request_id)s\t%(message)s\n"

The most interesting thing here is aws_request_id that is the identifier of the lambda request, injected by the default formatter when running on lambda. So if you like the default format you can just insert %(name)s somewhere in the string above.
For completeness, the default date format is the standard ISO format:

"%Y-%m-%dT%H:%M:%S"

The code to get these two strings:

logger = logging.getLogger()
return [{ 'fmt' : handler.formatter._fmt, 'datefmt': handler.formatter.datefmt } for handler in logger.handlers]

Thanks for pointing in the right direction, but:

You do not need to remove the handler

You can just call setFormatter on an existing handler.

You should not apply a change to all handlers

Regardless of if you remove a handler, or just change the formatter, your loop is overly broad.

If you make a change to all handlers in root.handlers, you run the risk of hitting a handler that you did not intend to. It makes the code brittle and non-portable. At the very least check the type of the handler before applying your change to it.

However, when I do type(handler) I get <class '__main__.LambdaLoggerHandler'> instead of the expected <class 'awslambda.bootstrap.LambdaLoggerHandler'>, not sure what is up with that.

@thnee What is the correct handler to change the formatter for? I would simply like to add the logger name to the handler as @mrtj mentions, so I will have a better idea where an error occurs.

has anyone managed to find a nice way to get "aws_request_id" when using the approach of removing the default handler and using your own?

has anyone managed to find a nice way to get "aws_request_id" when using the approach of removing the default handler and using your own?

It's accessible through second handler parameter usually named as the context:

def handler(event, context):
    aws_request_id = context['aws_request_id']

A bit inefficient but this worked for me:

log = logging.getLogger()
for h in log.handlers:
    h.setFormatter(logging.Formatter("%(aws_request_id)s [%(levelname)s] %(message)s"))

log = logging.getLogger(__name__)
log.setLevel(logging.DEBUG)

Why not just create a logger, add your handler and then set propagate to False?

    FORMAT = '%(asctime)s %(message)s'
    h = logging.StreamHandler(sys.stdout)
    h.setFormatter(logging.Formatter(FORMAT))

    logger = logging.getLogger(__name__)
    logger.addHandler(h)
    logger.setLevel(logging.INFO)
    logger.propagate = False

This would prevent anything being logged using logger from propagating up to parent loggers. In the Lambda case the logger that Lambda adds.

Or... use the aws-lambda-powertools logger which has a lot of this, structured logs, and you get things like setting correlation ids.

And you can customize the formatter if you really need via https://awslabs.github.io/aws-lambda-powertools-python/latest/core/logger/#bring-your-own-formatter

I prefer keep the number of 3rd party dependencies in my lambdas low but I do like to have control of the logging configuration. I have had some success using something similar to the following:

import logging
import logging.config


config = {
    'version': 1,
    'formatters': {
      'lambda': {
        'class': "logging.Formatter",
        'format': "%(asctime)s %(levelname)s %(aws_request_id)s %(module)s:%(lineno)d %(message)s"
      }
    },
    'filters': {
        'lambda': {
            '()': '__main__.LambdaLoggerFilter'
        }
    },
    'handlers': {
      'lambda': {
        'class': "logging.StreamHandler",
        'level': "DEBUG",
        'formatter': "lambda",
        'filters': ['lambda']
      }
    },
    'loggers': {
      'lambda': {
        'level': "DEBUG",
        'handlers': ["lambda"],
        'propagate': False
      }
    }
}

logging.config.dictConfig(config)

LOG = logging.getLogger('lambda')

def handle(event, context):
    LOG.info('Logging from Lambda with Request ID.')

Obviously this comes with the risk of assuming AWS do not change the runtime bootstrapping code (tested on python3.8 runtime).

I was able to retain aws_request_id in the log output:
https://gist.github.com/matthewpick/3aa01abfeda36eae717837a99994d3ed