LambdaとPythonでカスタムログレベルをJSON出力したい（+ログが2つ出る事象の対処）

Last updated at 2025-05-22Posted at 2025-05-22

この記事の概要

AWS LambdaでPythonを実行する際に、ログをJSON出力し、カスタムログレベルを定義したいことがありました。

Lambdaのロギング設定のログフォーマットをJSONに変更し、logging.addLevelNameでカスタムログレベルを追加すれば良いと思ったが上手くいかない事象に遭遇。その対処法と発生理由についてまとめます。

結論：対処法

下記のコードで実現できます。

ポイントは以下2つです。

Lambdaのログ出力設定をText→JSONに変更するだけではダメ、自分でJSON出力するFormatterを用意
- カスタムログレベル名が出力されない事象が解決可能
logger.propagate = Falseで親のLoggerに流さない
- ログが2つ出力される事象が解決可能

import logging
import json
import logging.handlers

# カスタムログレベルを指定
ALERT = 45
EMERGENCY = 55
logging.addLevelName(ALERT, "ALERT")
logging.addLevelName(EMERGENCY, "EMERGENCY")

from logging import root
print(root.handlers, 'root.handlers') # ローカルだと空だが、Lambda上だとLambdaLoggerHandle

# loggerを定義
logger = logging.getLogger(__name__)
logger.propagate = False # Root Loggerに流さない
logger.setLevel(logging.INFO)

# JSON出力するFormatterを用意
class JsonFormatter(logging.Formatter):
  def format(self, record):
    return json.dumps(record.__dict__) # recordの属性を全て出力

handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logger.addHandler(handler)


def lambda_handler(event, context):
  logger.info("Lambda function started", extra={"event": "hoge"})
  logger.warning("This is a warning message", extra={"event": "hoge"})
  logger.error("This is an error message", extra={"event": "hoge"})
  logger.log(ALERT, "This is an alert message", extra={"event": "hoge"})
  logger.critical("This is a critical message", extra={"event": "hoge"})
  logger.log(EMERGENCY, "This is an emergency message", extra={"event": "hoge"})
  logger.fatal("This is a fatal message. Fatalの顔をしたCritical", extra={"event": "hoge"})

これにより、自分で定義したログレベルが出力出来ました。

ちなみに、ログの出力設定は「Text」でも「JSON」でも、どちらでも良いです。

問題発生理由

カスタムログレベルを設定したかった経緯

DataDogでステータスに応じたロジックを用意していた
DataDogはレベルの先頭の文字に応じて自動でステータスをマッピングする
DataDogは「WARNING」「ERROR」「ALERT」「CRITICAL」「EMERGENCY」のレベルがあるが、Pythonは「WARNING」「ERROR」「CRITICAL」のみで足りない

上記から、Pythonで「ALERT」「EMERGENCY」のレベルを設定したかった。

発生していた課題

LambdaでJSONログフォーマットを指定できるため、ロギング設定をJSONに変更した。

下記のように、カスタムログレベルを定義した。

import logging
import json
import logging.handlers

ALERT = 45
EMERGENCY = 55
logging.addLevelName(ALERT, "ALERT")
logging.addLevelName(EMERGENCY, "EMERGENCY")

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


def lambda_handler(event, context):
  logger.info("Lambda function started", extra={"event": "hoge"})
  logger.warning("This is a warning message", extra={"event": "hoge"})
  logger.error("This is an error message", extra={"event": "hoge"})
  logger.log(ALERT, "This is an alert message", extra={"event": "hoge"})
  logger.critical("This is a critical message", extra={"event": "hoge"})
  logger.log(EMERGENCY, "This is an emergency message", extra={"event": "hoge"})
  logger.fatal("This is a fatal message. Fatalの顔をしたCritical", extra={"event": "hoge"})

すると、下記のような問題が起こりました。

ALERTに設定しているはずがERROR
EMERGENCYに設定しているはずがCRITICAL

試しにフォーマットをTextに変更して再度実行してみると普通にカスタムログレベル名が出力されました。

JSON出力の場合にカスタムログレベルが使えなかった理由

AWS LambdaではLambdaLoggerHandlerというハンドラがルートロガーに設定されています。

また、PythonのLoggingのドキュメントより、propageteフラグがfalseでない場合上位のロガーに関連付けられたハンドラが処理されます。

各ロガーは 0 個以上のハンドラを (Logger の addHandler() メソッド) で関連付けることができます。ロガーに直接関連付けられたハンドラに加えて、ロガーの上位にあるロガーすべてに関連付けられたハンドラがメッセージを処理する際に呼び出されます (ただしロガーの propagate フラグが false 値にセットされている場合を除きます。その場合は、祖先ハンドラへの伝搬はそこで止まります)。

LambdaLoggerHandlerのフォーマット処理が怪しそうです。ソースコードを発見し、見てみました。

以下の記述から、フォーマットがJSONでない（Text）の場合はlevelnameをそのまま出力していることから、Textの場合はカスタムログレベルが出力されていることが分かります。次は、JsonFormatter()の部分を見てみます。

if log_format == LogFormat.JSON:
    logger_handler.setFormatter(JsonFormatter())
else:
    logger_handler.setFormatter(
        logging.Formatter(
            "[%(levelname)s]\t%(asctime)s.%(msecs)03dZ\t%(aws_request_id)s\t%(message)s\n",
            "%Y-%m-%dT%H:%M:%S",
        )
    )

JsonFormatter()のformat処理を見ると、JSONの場合はlevelnoを_format_log_levelで変換しています。変換ロジックを見ると、0, 10, 20, 30, 40, 50のいずれかに変換されていることが分かりました。

45の場合は40、55の場合は50となるため、ALERT→ERROR、EMERGENCY→CRITICALにログレベルが勝手に変換されてしまっていました。

def format(self, record: logging.LogRecord) -> str:
    record.levelno = _format_log_level(record)
    record.levelname = logging.getLevelName(record.levelno)
    record._frame_type = _JSON_FRAME_TYPES.get(
        record.levelno, _JSON_FRAME_TYPES[logging.NOTSET]
    )
    ...

##########

def _format_log_level(record: logging.LogRecord) -> int:
    return min(50, max(0, record.levelno)) // 10 * 10

まとめると以下の理由でカスタムログレベルをJSON出力出来ていませんでした。

Lambdaでloggingを使うとデフォルトでLambdaLoggerHandlerが使用されている
LambdaLoggerHandlerはログ出力時にログレベルを0, 10, 20, 30, 40, 50のいずれかに変換する

カスタムログレベルをJSON出力する方法

ここまでで、デフォルトのLambdaLoggerHandlerを使うとカスタムログレベルを出力出来ないことが分かりました。

そのため、自分で定義したハンドラを使えばカスタムログレベルを出力出来そうだと言えます。そこで、下記のコードのようにJSON形式で出力するハンドラを追加します。

import logging
import json
import logging.handlers

ALERT = 45
EMERGENCY = 55
logging.addLevelName(ALERT, "ALERT")
logging.addLevelName(EMERGENCY, "EMERGENCY")

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

### ここから追加：JSON形式で出力するハンドラを追加
class JsonFormatter(logging.Formatter):
  def format(self, record):
    return json.dumps(record.__dict__) # recordの属性を全て出力

handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logger.addHandler(handler)
### ここまで追加

def lambda_handler(event, context):
  logger.info("Lambda function started", extra={"event": "hoge"})
  logger.warning("This is a warning message", extra={"event": "hoge"})
  logger.error("This is an error message", extra={"event": "hoge"})
  logger.log(ALERT, "This is an alert message", extra={"event": "hoge"})
  logger.critical("This is a critical message", extra={"event": "hoge"})
  logger.log(EMERGENCY, "This is an emergency message", extra={"event": "hoge"})
  logger.fatal("This is a fatal message. Fatalの顔をしたCritical", extra={"event": "hoge"})

その結果、カスタムログレベルが出力されるようになりました。しかし、ログが2つずつ出力されるという別の問題が発生します。

これは、先ほども説明したようにルートロガーに設定されたLambdaLoggerHandlerの処理も走ってしまうため、ログが2つずつ出力されてしまっています。