Celery のロギングをカスタマイズする方法

• 概要
• 環境
• after_setup_logger と after_setup_task_logger を使う
• 解説
• タスク側で使用するロガーは get_task_logger を使う
• 動作確認
• 最後に
• 参考サイト

概要

Celery のロギングにはワーカの開始ログなどを出力するルートロガーとタスクが出力するタスクロガーがあります
それぞれのロガーは個別に設定するためのメソッドが用意されているのでそれを使ってカスタマイズします

今回はおすすめのロガーカスタマイズを簡単に紹介します

環境

• macOS 10.15.7
• Python 3.8.5
  
  • Celery 4.4.7

after_setup_logger と after_setup_task_logger を使う

前者がルートロガーをカスタマイズできるメソッドで後者がタスクロガーをカスタマイズできるロガーです
それを踏まえた上で以下のようにロガーをカスタマイズします

• vim sub_tasks.py

import logging

from celery import Celery
from celery.signals import after_setup_logger, after_setup_task_logger
from celery.utils.log import get_task_logger

app = Celery('sub_tasks', backend='redis://localhost', broker='redis://localhost')
logger = get_task_logger(__name__)


@after_setup_logger.connect
def setup_root_logger(logger, *args, **kwargs):
    logger.handlers = []
    handler = logging.StreamHandler()
    handler.setLevel(logging.INFO)
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    handler.setFormatter(formatter)
    logger.addHandler(handler)


@after_setup_task_logger.connect
def setup_task_logger(logger, *args, **kwargs):
    logger.handlers = []
    handler = logging.StreamHandler()
    handler.setLevel(logging.INFO)
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    handler.setFormatter(formatter)
    logger.addHandler(handler)


@app.task
def add(x, y):
    logger.info("add")
    return x + y

解説

setup_root_logger と setup_task_logger の引数で受け取れる logger はそれぞれ Celery がデフォルトで用意しているルートロガーとタスクロガーになります
それぞれハンドラが登録されているので一旦空にしましょう
そしてそのあとで独自のハンドラを登録することでデフォルトのログを非表示しつつ独自のログを出力できるようになります

今回はルートロガーにもタスクロガーにも同じハンドラを設定していますがルートロガーはファイルハンドラを使うとかもできます
ちなみにルートロガーは celery.worker などのモジュール用のロガーになります
ワーカーの起動やタスクの開始と終了時に表示されるデフォルトのログなどを管理しています

タスク側で使用するロガーは get_task_logger を使う

上記のサンプルでは実際にタスク内でログを出力する際のロガーは get_task_logger を使って取得しています
こうすることで after_setup_task_logger で設定したタスクロガーを適切に取得することができます

動作確認

• vim main.py

from sub_tasks import add

add.delay(100, 1)

これでタスクを起動して動作確認しましょう

• pipenv run celery -A sub_tasks worker --loglevel=info
• pipenv run python main.py

以下のようなログが表示されるようになります

2020-12-04 11:40:29,144 - celery.worker.consumer.connection - INFO - Connected to redis://localhost:6379// 2020-12-04 11:40:29,155 - celery.worker.consumer.mingle - INFO - mingle: searching for neighbors 2020-12-04 11:40:30,211 - celery.worker.consumer.mingle - INFO - mingle: all alone 2020-12-04 11:40:30,308 - celery.apps.worker - INFO - celery@local ready. 2020-12-04 11:40:33,235 - celery.worker.strategy - INFO - Received task: sub_tasks.add[ec404b76-2e26-4ed9-a266-0031f351c0f5] 2020-12-04 11:40:33,238 - sub_tasks - INFO - add 2020-12-04 11:40:33,246 - celery.app.trace - INFO - Task sub_tasks.add[ec404b76-2e26-4ed9-a266-0031f351c0f5] succeeded in 0.009275625999999981s: 101

最後に

Celery のロガーをカスタマイズする方法を紹介しました
getLogger などを使ってもできそうですがちゃんと Celery 側で設定するためのメソッドを用意してくれているのでそれを使ったほうが良いと思います

参考サイト

• https://docs.celeryproject.org/en/stable/userguide/signals.html#after-setup-logger