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

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

![スクリーンショット 2025-05-22 23.51.40.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/728813/33fe1811-8aff-43cd-8511-93dd92a153b5.png)

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

# 結論：対処法
下記のコードで実現できます。

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

```python
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"})

```

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

![スクリーンショット 2025-05-22 23.49.36.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/728813/4f874a6b-aed0-48b6-8418-b536cb9f974c.png)

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

# 問題発生理由
## カスタムログレベルを設定したかった経緯
- DataDogでステータスに応じたロジックを用意していた
- [DataDogはレベルの先頭の文字に応じて自動でステータスをマッピングする](https://docs.datadoghq.com/ja/service_management/events/pipelines_and_processors/status_remapper/)
- DataDogは「WARNING」「ERROR」「ALERT」「CRITICAL」「EMERGENCY」のレベルがあるが、[Pythonは「WARNING」「ERROR」「CRITICAL」](https://docs.python.org/ja/3.13/howto/logging.html#logging-levels)のみで足りない

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

## 発生していた課題
[LambdaでJSONログフォーマットを指定できる](https://docs.aws.amazon.com/ja_jp/lambda/latest/dg/monitoring-cloudwatchlogs-advanced.html#monitoring-cloudwatchlogs-logformat)ため、ロギング設定をJSONに変更した。

![スクリーンショット 2025-05-22 23.51.40.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/728813/c13fc93c-f4bb-4835-92e0-4f2afd70f86b.png)

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

```python
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

![スクリーンショット 2025-05-23 0.05.26.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/728813/6a3c5681-878d-41bc-8d8c-fb103cef4f5c.png)

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

![スクリーンショット 2025-05-23 0.09.06.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/728813/bd8adc3c-8ef7-4797-a965-c9b47d86b096.png)

## JSON出力の場合にカスタムログレベルが使えなかった理由
AWS Lambdaでは`LambdaLoggerHandler`というハンドラがルートロガーに設定されています。

https://qiita.com/fumiya0238/items/825121848eb017d4d452

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

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

https://docs.python.org/ja/3.13/howto/logging.html#logging-levels

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

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

```python
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",
        )
    )
```

https://github.com/aws/aws-lambda-python-runtime-interface-client/blob/main/awslambdaric/bootstrap.py#L465-L474

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

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

```python
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

```

https://github.com/aws/aws-lambda-python-runtime-interface-client/blob/main/awslambdaric/lambda_runtime_log_utils.py#L110-L116

https://github.com/aws/aws-lambda-python-runtime-interface-client/blob/main/awslambdaric/lambda_runtime_log_utils.py#L74-L77

まとめると以下の理由でカスタムログレベルをJSON出力出来ていませんでした。
- Lambdaでloggingを使うとデフォルトで`LambdaLoggerHandler`が使用されている
- `LambdaLoggerHandler`はログ出力時にログレベルを0, 10, 20, 30, 40, 50のいずれかに変換する

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

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

```python
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つずつ出力されるという別の問題が発生します。**

![スクリーンショット 2025-05-23 0.32.10.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/728813/4c85f776-698a-4a05-899d-29c2fd3b38a1.png)

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

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

https://docs.python.org/ja/3.13/howto/logging.html#logging-levels

そのため、定義したロガーの`propagate`属性をFalseにしルートロガーへの伝搬を止めるようにします。

```python
import logging
import json
import logging.handlers

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

logger = logging.getLogger(__name__)
### ここから追加
logger.propagate = False # Root Loggerに流さない
### 追加ここまで
logger.setLevel(logging.INFO)

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つずつ出力される事象の解消もできました。

![スクリーンショット 2025-05-23 0.36.50.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/728813/564a4929-7669-4048-8c01-3809b90d6185.png)


# 関連リンク
https://qiita.com/fumiya0238/items/825121848eb017d4d452

https://qiita.com/amedama/items/b856b2f30c2f38665701#%E4%BD%95%E6%95%85%E3%83%80%E3%83%A1%E3%81%AA%E3%81%AE%E3%81%8B-logging

https://qiita.com/smats-rd/items/c5f4345aca3a452041c7

https://ops-today.com/topics-5571/