AWS Lambda/PythonでJSON形式でログを出すベストプラクティス

Lambdaはログを CloudWatch Logs に自動保存しますが、CloudWatch Logs にはJSON形式のログを自動でパースして整形表示したり検索したりする機能があります。是非とも、ログをJSON形式にしたいところです。

しかし、「python lambda logging json」でググって見つかる記事は、いずれも内容に不備があるようでしたので、自分がベストだと思う方法を紹介するのがこの記事です。

お断り

Pythonのログ出力は標準ライブラリのloggingがスタンダードなので、この記事ではloggingを前提にしています。

printを使うべきではない理由・logging の正しい使い方については「ログ出力のための print と import logging はやめてほしい 」という記事が分かりやすいです（文体は辛辣ですけど）

これが（きっと）ベストプラクティスだ！

import logging
import json


# 冒頭に、独自のフォーマッタの定義と、ルートロガーの設定を書く
class JsonFormatter:
    def format(self, record):
        return json.dumps(vars(record))

# ルートロガーの設定
logging.basicConfig() # 標準エラーに出力するハンドラーをセット
logging.getLogger().handlers[0].setFormatter(JsonFormatter()) # ハンドラーの出力フォーマットを自作のものに変更

# 以降は普通にloggerを取得して処理を関数を書く
logger = logging.getLogger(__name__)
logger.setLevel(os.environ.get('LOG_LEVEL', 'INFO')) # 余談： 環境変数でログレベルを変更可能にしとくと便利


def lambda_handler(event: dict, context):
   # ログに付加情報をもたせたいときは、`extra=` に dict を渡す。
   # もちろん、 dict は2要素以上でもOK
   logger.info("sample", extra={"foo": 12, "bar": "Hello World!"})

CloudWatch Logsに保存されるログ：
logger.info の出力がJSONになっています。なお、START RequestId:... などのログはAWS Lambda自体が出しているものなので変更できません。

START RequestId: 3ba9c9dd-0758-482e-8aa4-f5496fa49f04 Version: $LATEST
{
    "name": "lambda_function",
    "msg": "sample",
    "args": [],
    "levelname": "INFO",
    "levelno": 20,
    "pathname": "/var/task/lambda_function.py",
    "filename": "lambda_function.py",
    "module": "lambda_function",
    "exc_info": null,
    "exc_text": null,
    "stack_info": null,
    "lineno": 23,
    "funcName": "lambda_handler",
    "created": 1577152740.1250498,
    "msecs": 125.04982948303223,
    "relativeCreated": 64.58139419555664,
    "thread": 140315591210816,
    "threadName": "MainThread",
    "processName": "MainProcess",
    "process": 7,
    "foo": 12,
    "bar": "Hello World!",
    "aws_request_id": "3ba9c9dd-0758-482e-8aa4-f5496fa49f04"
}
END RequestId: 3ba9c9dd-0758-482e-8aa4-f5496fa49f04
REPORT RequestId: 3ba9c9dd-0758-482e-8aa4-f5496fa49f04	Duration: 1.76 ms	Billed Duration: 100 ms	Memory Size: 128 MB	Max Memory Used: 55 MB	Init Duration: 113.06 ms	

一応の解説

（詳しくは公式ドキュメントを参照）

logging.Loggerは階層構造になっているので、全体のフォーマットを変えたいならルートロガー(logging.getLogger())を変更すればOK。logging.basicConfig()でルートロガーにハンドラーがセットされるので、あとは .setFormatter() で独自のフォーマッタをセットします。

.format(record)にはlogging.LogRecordが渡されます。このオブジェクトは諸々の情報を属性として持っているので、vars(record)で取得して、JSONに変換しています。

logger.infoのextra=で渡した値は、LogRecordの属性としてセットされます。ここで、msg, funcName などのキーを使うと、本来の値を上書きしてしまいます。
どうしても上書きを避けたい場合は、.makeRecordをオーバーライドした独自のロガーを定義することもできます。
ただ、私はコードが複雑になるので気が進みません。

ね、簡単でしょ？

ライブラリを使うべき？

ところで、GithubにはログをJSONにフォーマットするライブラリがいくつも転がっています。

しかし、私はそういったライブラリを使うのはオススメしません。ライブラリを導入すると依存関係が生じ、バージョンアップの手間やセキュリティ上のリスクが生じるからです（2016年の left-pad を思い出せ！）。

上述のようにJsonFormatterはたった３行で書けるので、コードをコピペするのが結局ベストではないかと思います。

どっとはらい。