15
1

More than 1 year has passed since last update.

AWS lambdaでログが重複して出力される理由と対処法(Python)

Posted at

はじめに

AWS lambda上で、Pythonのloggingモジュールを使い、ログを表示させていたところ、重複してログが表示されていることに気づいたので、重複してログが出力される理由とその対処法を調査した。

ログが重複する理由

lambdaのlogging仕様

lambda上では、デフォルトで、ルートロガーにLambdaLoggerHandlerというハンドラが登録されている。(参照記事)
つまり、自分で新たなハンドラを登録すると、ハンドラが複数存在することになり、ログが重複して出力されてしまう。

コード

デフォルトで存在するハンドラの確認

from logging import getLogger, StreamHandler, DEBUG, Formatter

def lambda_handler(event, context):
    logger = getLogger()
    logger.setLevel(DEBUG)
    print(logger.handlers)
    logger.info("ログだよ")
    return "success"

結果


[<LambdaLoggerHandler (NOTSET)>] #デフォルトでこのハンドラが存在している
[INFO]	2022-03-16T04:34:03.082Z	ce98337d-0404-4562-be66-3d6292ea20f6	ログだよ

コード

ハンドラが重複したとき

from logging import getLogger, StreamHandler, DEBUG, Formatter

def lambda_handler(event, context):
    logger = getLogger()
    logger.setLevel(DEBUG)
    handler = StreamHandler()
    handler.setFormatter(Formatter('%(asctime)s - %(levelname)s - %(name)s: %(message)s', datefmt='%Y-%m-%d %H:%M:%S'))
    logger.addHandler(handler) #ハンドラの追加
    print(logger.handlers)
    logger.info("ログだよ")
    return "success"

結果


[<LambdaLoggerHandler (NOTSET)>, <StreamHandler <stderr> (NOTSET)>]
[INFO]	2022-03-16T04:42:32.347Z	bf22b961-fada-447d-a0cb-74e501e1621e	ログだよ  # LambdaLoggerHandlerによる出力
2022-03-16 04:42:32 - INFO - root: ログだよ  # StreamHandlerによる出力

対処法

その1:デフォルトのハンドラをそのまま使用する

1つ目の対処法は、デフォルトのハンドラをそのまま使用すること。lambda内で複数のハンドラを使う必要がないときは、この方法で十分かも。

コード


from logging import getLogger, StreamHandler, DEBUG, Formatter

def lambda_handler(event, context):
    logger = getLogger()
    logger.setLevel(DEBUG)
    for handler in logger.handlers: # ここでフォーマッターの変更も可能
        handler.setFormatter(Formatter('%(asctime)s - %(levelname)s - %(name)s: %(message)s', datefmt='%Y-%m-%d %H:%M:%S'))
    print(logger.handlers)
    logger.info("ログだよ")
    return "success"

結果


[<LambdaLoggerHandler (NOTSET)>]
2022-03-16 04:51:51 - INFO - root: ログだよ

デメリット

loggerに名前を付けることができず、%(name)sのところにrootと出てきてしまう(logger名をモジュール名などにしたいときに不便)。

その2:logger.propagateをFalseにする

2つ目の対処法は、logger.propagateをFalseにすること(参照)。これを設定することで、ルートロガーなどの親ロガーへのログ伝搬を制御することができる。つまり、名前付きハンドラを作成し、ログを出力しても、lambdaのデフォルトのハンドラではログが出力されなくなる。

コード

propagateをコメントアウトした場合

from logging import getLogger, StreamHandler, DEBUG, Formatter

def lambda_handler(event, context):
    logger = getLogger('example') # 'example'という名前のロガーを作成
    logger.setLevel(DEBUG)
    # logger.propagate = False
    handler = StreamHandler()
    logger.addHandler(handler)
    for handler in logger.handlers:
        handler.setFormatter(Formatter('%(asctime)s - %(levelname)s - %(name)s: %(message)s', datefmt='%Y-%m-%d %H:%M:%S'))
    print(logger.handlers)
    logger.info("ログだよ")
    return "success"

結果


[<StreamHandler <stderr> (NOTSET)>]
2022-03-16 05:02:19 - INFO - example: ログだよ # 'example'ロガーのログ
[INFO]	2022-03-16T05:02:19.960Z	d10cb690-47f6-45d9-90d6-716329e02889	ログだよ # ルートロガーのログ

この場合、'example'というロガーを作成(ルートロガーとは異なる)したので、このロガーのハンドラにはlambdaのデフォルトのハンドラは存在しないが、ログ情報はルートロガーに存在するlambdaのデフォルトのハンドラにまで伝搬するので、ログ出力の際にログが重複してしまっている。

コード

propagateを設定した場合

from logging import getLogger, StreamHandler, DEBUG, Formatter

def lambda_handler(event, context):
    logger = getLogger('example')
    logger.setLevel(DEBUG)
    logger.propagate = False  # propagateを設定
    handler = StreamHandler()
    logger.addHandler(handler)
    for handler in logger.handlers:
        handler.setFormatter(Formatter('%(asctime)s - %(levelname)s - %(name)s: %(message)s', datefmt='%Y-%m-%d %H:%M:%S'))
    print(logger.handlers)
    logger.info("ログだよ")
    return "success"

結果


[<StreamHandler <stderr> (NOTSET)>]
2022-03-16 05:07:52 - INFO - example: ログだよ  # 'example'ロガーのみが出力

このように、propagateをFalseに設定すると、'example'ロガーからのログのみが出力され、ログの重複もなくなる。

結論

  • lambda上では、デフォルトのハンドラがルートロガーに存在する
  • ログの重複を避けるには
    • デフォルトのハンドラを使用する
    • propagateをFalseにする
15
1
1

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
15
1