AWS Lambda で Python 関数を作ったらログ周りでハマったのでメモ。

困りごと

こういう Lambda 関数を作って実行したが、ログが出力されない。

import logging

# ルートロガーのログレベルを設定する
logging.basicConfig(level=logging.INFO)

logger = logging.getLogger(__name__)

def lambda_handler(event, context):
    logger.info("foo!!!")

似たような Python スクリプトを普通の python コマンドで実行した場合は意図通り出力される
Lambda の Python ランタイムだけでなく、 public.ecr.aws/lambda/python をベースに作った Docker コンテナでも同様の問題が発生する

原因

Lambda の Python ランタイムでは、あらかじめルートロガーに StreamHandler が設定されているのが原因だった。

そもそも basicConfig の挙動は「ルートロガーにデフォルト設定のハンドラを追加する (ただし、既にルートロガーにハンドラが設定済みの場合は何もしない)」¹ なので、ルートロガーのハンドラが事前に設定されているのであれば logging.basicConfig(level=logging.INFO) が無視されるというのは仕方ない。

じゃあなぜ AWS Lambda の Python ランタイムはルートロガーのハンドラがあらかじめ設定済みなのかというと、そのあたりはよくわからなかったのでご存じの方はコメントいただけると嬉しい。

対処方法

いくつかパターンがあるので、状況に応じて選ぶのがよい。

`basicConfig` を使わずにルートロガーのログレベルを設定する

getLogger() は引数を省略するとルートロガーを返すので、これに setLevel すればログレベルを設定できる。

import logging

# ルートロガーのログレベルを設定する
logging.getLogger().setLevel(logging.INFO)

logger = logging.getLogger(__name__)

def lambda_handler(event, context):
    logger.info("foo!!!")

ロガーに対してログレベルを設定する

import logging

logger = logging.getLogger(__name__)

# ロガーのログレベルを設定する
logger.setLevel(logging.INFO)

def lambda_handler(event, context):
    logger.info("foo!!!")

ただしこの場合、ルートロガーのログレベルを書き換えていないため、別のモジュールのロガーのログレベルはデフォルトのままとなる。

`force=True` する (非推奨)

basicConfig に force=True を渡せば、ルートロガーにハンドラが設定済みであっても強制的にログレベルを設定できる。

import logging

# ルートロガーのログレベルを設定する
logging.basicConfig(level=logging.INFO, force=True)

logger = logging.getLogger(__name__)

def lambda_handler(event, context):
    logger.info("foo!!!")

ただし AWS Lambda が事前に設定したハンドラが消えてしまうので、何か挙動がおかしくなってしまうかもしれない。あまりやらないほうがよさそう。

https://docs.python.org/ja/3/library/logging.html#logging.basicConfig ↩