Lambda + Python3.7のログをJSON形式で出力してみる(行ごとに分割されない形で)

どうも!大阪オフィスの西村祐二です。

LambdaのログはCloudWatch Logsに出力されますが、別のサービスで参照するときや見やすくするためにJSON形式で出力したいときってあると思います。

簡単にできると思ったら少しハマってしまったので、ブログにしておきます。

はじめ、下記ブログを参考にloggingを使ったのですが、ログが行毎に分割されてしまいました。

【小ネタ】AWS Lambdaで複数行のログを送るときの挙動を調べてみた

環境

Python 3.7

最終的なコード

最終的なコードは下記のようなコードになりました。見せ方の関係で一つのファイルに記載していますが、別ファイルから呼び出すなどして使いやすくしてください。

下記リンク先を大いに参考させていただきました。

https://stackoverflow.com/questions/50233013/aws-lambda-logs-to-one-json-line

リンク先でも記載されていますが、

Lambda内部のログ出力する部分のLambdaLoggerHandlerが標準クラスのlogging.Formatterを使用しているようなので、JSONを出力するカスタムクラスを作ってFormatterを置き換えようということをしています。

また、追加でevent情報などをログに含めたい場合があります。extra=dict(data)とすることで、logrecordプロパティとの競合を回避します。

import json
import logging
import traceback


class FormatterJSON(logging.Formatter):
    def format(self, record):
        record.message = record.getMessage()
        if self.usesTime():
            record.asctime = self.formatTime(record, self.datefmt)
        j = {
            'logLevel': record.levelname,
            'timestamp': '%(asctime)s.%(msecs)dZ' % dict(asctime=record.asctime, msecs=record.msecs),
            'timestamp_epoch': record.created,
            'aws_request_id': getattr(record, 'aws_request_id', '00000000-0000-0000-0000-000000000000'),
            'message': record.message,
            'module': record.module,
            'filename': record.filename,
            'funcName': record.funcName,
            'levelno': record.levelno,
            'lineno': record.lineno,
            'traceback': {},
            'extra_data': record.__dict__.get('extra_data', {}),
            'event': record.__dict__.get('event', {}),
        }
        if record.exc_info:
            exception_data = traceback.format_exc().splitlines()
            j['traceback'] = exception_data

        return json.dumps(j, ensure_ascii=False)


logger = logging.getLogger()
logger.setLevel('INFO')

formatter = FormatterJSON(
    '[%(levelname)s]\t%(asctime)s.%(msecs)dZ\t%(levelno)s\t%(message)s\n',
    '%Y-%m-%dT%H:%M:%S'
)
# Replace the LambdaLoggerHandler formatter :
logger.handlers[0].setFormatter(formatter)


def hello(event, context):
    try:
        # ログに表示させたい情報をdataに入れる
        value = dict(a='abc', b='def', c=123)
        data = {"event": event}
        data['extra_data'] = value
        logger.info('Start hello Func', extra=dict(data))

        # 例外を発生させる
        print(1 / 0)

    except ZeroDivisionError as error:
        data = {"event": event}
        logging.exception(error, extra=dict(data))

出力結果

上記ではinfoのログと、意図的に例外を発生させたときのログを出力させています。

▼ログが行ごとに分割されず、infoとerrorでそれぞれ一行として出力されています。

▼infoのログがjsonの形で出力されています。

▼errorのログもjsonの形式で出力され、かつstacktraceも一緒に出力されます。

ちょっと工夫した点

例外が発生したとき、自動的にstacktraceをログに含みたかったので、exc_infoの中身を確認するような処理をいれています。exc_infoは例外が起こっていない場合はNoneが返り、ある場合はタプルで情報が格納されます。

ただ、例外情報の取得はtracebackモジュールが簡単なので、そちらをつかっています。

細かいですが、例外情報を取得したときに、\nが含まれた形になるので、少し見にくいかなと思って、traceback.format_exc().splitlines()にして\nが入らないように一行ごとに出力するようにしています。

https://docs.python.org/ja/3/library/traceback.html

出力項目をカスタマイズしたい

11-24行目でkeyとvalueを追加してください。

どんな情報がrecordに入ってくるかは下記のPythonのドキュメントを参照ください。

https://docs.python.jp/3/library/logging.html#logrecord-attributes

さいごに

いかがだったでしょうか。

Lambdaのログ出力を行ごとに分割されないようにJSON形式で出力してみました。

もっといい方法があるよ、こうしたほうがいいよとかあればコメントいただけると幸いです。