Lambdaのログ出力にオススメしたいPythonのライブラリLambda Powertools
CX事業本部@大阪の岩田です。
皆さんはLambda Functionからログを出力する際に、どんな形式でログを出力していますか?後々CloudWatch Logs Insightsで分析することを考えると、やはりログはJSON形式で出力しておきたいところです。出力する項目に関して考えると、リクエストIDなんかは必須と言えるのではないでしょうか?今回紹介するLambda Powertoolsを使うと、このあたりのログ戦略が簡素化できるので良ければお試し下さい。
環境
今回利用した環境です
- ランタイム: Python3.8
- Lambda Powertools: 0.3.0
- AWS Lambda Logging:0.1.1
Lambda Powertoolsとは?
Python3.6以上で利用できるAWS Lambda用のユーティリティライブラリです。
- 構造化ログ(JSONログ)を出力するためのユーティリティ
- X-Rayのトレースを容易にするユーティリティ
- SAR-async-lambda-metricsによる非同期でのカスタムメトリクス作成を支援するユーティリティ
が利用可能です。ログ出力に関しては内部的にAWS Lambda Loggingを利用しており、今回試したバージョンでは自力でAWS Lambda Loggingを導入しておかないと正常に動作しませんでした。※issueも上がってました。
なお、こちらのライブラリですが現段階でベータ版です。今後破壊的な変更が入る可能性が高いので、本番利用の際は十分ご注意下さい。
やってみる
実際にやってみましょう。まずはLambdaからaws-lambda-powertoolsとaws-lambda-loggingを利用するためにレイヤーを作成します。レイヤーを作成する詳細な手順は割愛するので、分からなければこちらのブログを参考にして下さい。
準備ができたら早速ログ出力を試してみます。
import os from aws_lambda_powertools.logging import logger_setup, logger_inject_lambda_context os.environ['POWERTOOLS_SERVICE_NAME'] = 'sample_service' logger = logger_setup() @logger_inject_lambda_context def handler(event, context): logger.info({ 'key1': 'val1', 'key2': 'val2', 'key3': 'val3', }) return
ポイントはlogger_setup()
とhandlerに付与している@logger_inject_lambda_context
のデコレータです。logger_setup()
でログフォーマットをJSONに変更しつつ、@logger_inject_lambda_context
のデコレータがLambdaのコンテキスト情報から諸々の情報をログに自動付与してくれます。環境変数のPOWERTOOLS_SERVICE_NAME
は必須ではありませんが、この環境変数をセットしておくと出力されるロ グのservice
に反映されるようになります。今回は分かりやすいようにソースコードからセットしましたが、本来はSAMテンプレート等を介してLambdaの設定から設定するのが良いでしょう。もしくはlogger_setup(service='sample_service')
のようにlogger_setup
の引数で指定することも可能です。
ソースコードの準備ができたらテストイベントからLambdaを実行し、Cloud Watch Logsに出力されたログを確認してみましょう。
{ "timestamp": "2020-01-05 07:52:02,789", "level": "INFO", "location": "sample_service.handler:9", "service": "sample_service", "cold_start": "true", "function_name": "logging_test", "function_memory_size": "128", "function_arn": "arn:aws:lambda:ap-northeast-1:123456789012:function:logging_test", "function_request_id": "41898e79-0075-4b3a-8718-1b3d5d69b1ae", "message": { "key1": "val1", "key2": "val2", "key3": "val3" } }
バッチリJSON形式のログが出力されています。他にもコールドスタートかどうかを表すcold_start
という項目や、どのバージョン(エイリアス)のLambdaが出力したログか確認するのに使えそうなfunction_arn
といった項目も出力されています。これでCloudWatch Logs Insightsを使った調査が捗りそうです。
ログに項目を追加してみる
先程出力されたログには必要そうな情報が色々と自動付与されていますが、システムの要件次第ではさらに項目を追加で出力したいこともあるでしょう。例えばCognitoユーザープールオーソライザーでアクセス制限をかけたAPI GWからLambdaを起動する場合はCognitoユーザープールのsub
をログに出力したい場面がありそうです。他にはX-RayのトレースIDなんかも出力しておくと、有事の調査に役立ちそうです。今度は自分でログに出力する項目を変更してみましょう。
import os from aws_lambda_powertools.logging import logger_setup, logger_inject_lambda_context os.environ['POWERTOOLS_SERVICE_NAME'] = 'sample_service' logger = logger_setup( attr1='attr1', attr2='attr2', attr3='attr3', ) def handler(event, context): logger.info({ 'key1': 'val1', 'key2': 'val2', 'key3': 'val3', }) return
ログに出力する項目はlogger_setup
の名前付き引数を利用することで制御が可能です。この例では、attr1
~attr3
という項目をログフォーマットに追加しています。先程使用した@logger_inject_lambda_context
のデコレータも内部的にはLambdaのコンテキスト情報を使ってlogger_setup
を呼び出すことでログフォーマットを調整しています。
再度テストイベントを実装し、Cloud Watch Logsに出力されたログを確認してみましょう。
{ "timestamp": "2020-01-05 07:53:44,941", "level": "INFO", "location": "sample_service.handler:14", "service": "sample_service", "attr1": "attr1", "attr2": "attr2", "attr3": "attr3", "message": { "key1": "val1", "key2": "val2", "key3": "val3" } }
これでログのカスタマイズもバッチリですね!
例外が発生した際のログ出力
今度は例外が発生した際のログ出力を確認してみましょう。以下のコードで意図的に例外を発生させ、logger.exception(e)
でエラーログを出力してみます。
import os from aws_lambda_powertools.logging import logger_setup, logger_inject_lambda_context os.environ['POWERTOOLS_SERVICE_NAME'] = 'sample_service' logger = logger_setup() @logger_inject_lambda_context def handler(event, context): try: 1 / 0 except Exception as e: logger.exception(e) raise e return
テストイベントの実行結果です。
{ "timestamp": "2020-01-05 07:54:54,909", "level": "ERROR", "location": "sample_service.handler:14", "service": "sample_service", "cold_start": "true", "function_name": "logging_test", "function_memory_size": "128", "function_arn": "arn:aws:lambda:ap-northeast-1:123456789012:function:logging_test", "function_request_id": "0ed6a4b9-a5d0-48bd-b94f-94185686cdaa", "message": "division by zero", "exception": "Traceback (most recent call last):\n File \"/var/task/lambda_function.py\", line 12, in handler\n 1 / 0\nZeroDivisionError: division by zero" }
出力されたログにexception
という項目が追加されており、この項目を参照することでスタックトレースが確認できます。これで例外発生時の調査もバッチリですね。
まとめ
LambdaのLogFormatを簡単にJSON化できるLambda Powertoolsの紹介でした。今回は紹介していませんが、JSONログの出力以外にも便利機能があるので色々と試してみると面白そうです。
ちなみに、自分の案件ではX-RayのトレースID等もログに残したかったので、Lambda Powertoolsが内部的に利用しているAWS Lambda Loggingだけを導入し、自動出力するログの項目を少し自分好みにカスタマイズして利用することにしました。