Pythonでログ出力する方法について

2022-02-05
2022-02-05

本記事では、Python のログの取り方、つまりloggingモジュールの使い方を説明します。

結論としては、Python で logging モジュールを使ってログをとる場合は以下のことを意識すると良いです。

  • import loggingではなくfrom logging import getLoggerを使う
  • 自作のlogger取得関数を作り、必要な設定を書いておく

logging モジュールを使用した Python のログ出力方法

早速 Python で最初から使えるloggingモジュールを試してみます。

以下のスクリプトを実行します。

import logging
def main():
    logging.info("INFO message")
if __name__ == "__main__":
    main()

結果は何も表示されません。

以下のようにwarningにするとメッセージが表示されます。

def main():
    logging.info("INFO message")
    logging.warning("Warning message")

表示メッセージはWARNING:root:Warning messageとなります。

INFOのメッセージが表示されないのはデフォルトのログレベルがwarningに指定されているからです。

Python の logging モジュールでは、重大度ごとにログ出力を切り替えられるようにログレベルが設定されています。 重大度ごとにDEBUG, INFO, WARNING, ERROR, CRITICALです。

メッセージに含まれるrootというのは logging モジュールが root で実行されたということを暗に意味します。 (実際にはそうでなくても root で実行されたように見えてしまう)

loggingモジュール周辺の仕組みは本記事の最後に記載した記事が参考になります。

rootの意味を考える例として、別モジュールの関数を呼び出すケースを試します。

以下がmod1.pyの中身です。

import logging
def test_func():
    logging.warning("warning だよ")

そして以下がmod1.pyを呼び出す側です。

import logging
from mod1 import test_func
def main():
    logging.warning("Warning message")
    test_func()
if __name__ == "__main__":
    main()

このファイルを実行した時の出力は以下のようになります。

WARNING:root:Warning message
WARNING:root:warning だよ

この結果からだとログがどのモジュールで吐き出されたのかわかりません。

ではどうすればいいのかというと、各モジュールで以下のように logger を定義します。

from logging import getLogger
logger = getLogger(__name__)
def test_func():
    logger.warning("warning だよ")

そして先ほどと同じように実行すると以下の出力が得られます。

WARNING:root:Warning message
WARNING:mod1:warning だよ

メッセージのrootmod1に変わりました!

ただ、これだけではログとしては情報が足りません。もう少し細かい設定を行なっていきます。

logger の細かい設定

logging モジュールから生成された logger には handler を設定・追加することができます。 handler とは logger から渡されたログメッセージを指定された場所に送るものです。

ここは具体例を見た方がわかりやすいです。

以下の内容ができるようにloggerhandlerをセットし、出力をformatterでレイアウトします。

  • ログレベルの設定
  • ログを標準出力で表示
  • ログが記録された日時を表示
  • ログが書かれた行数表示
  • ログのファイルへの書き出し

こちらが実際のコードです。ハンドラー等を定義したloggerを各 Python ファイルから呼べるようにしてあります。

import os
import datetime
from logging import getLogger, StreamHandler, FileHandler, Formatter, DEBUG
def get_my_logger(module_name: str):
    # 呼び出したモジュール名がセットされるようにする
    logger = getLogger(module_name)
    # ログレベルの定義
    logger.setLevel(DEBUG)
    # 出力されるログの表示内容を定義
    formatter = Formatter(
        "%(asctime)s : %(name)s : %(levelname)s : %(lineno)s : %(message)s"
    )
    # 標準出力のhandlerをセット
    stream_handler = StreamHandler()
    stream_handler.setLevel(DEBUG)
    stream_handler.setFormatter(formatter)
    logger.addHandler(stream_handler)
    # ファイル出力のhandlerをセット
    logs_dir_name = "logs"
    os.makedirs(logs_dir_name, exist_ok=True)
    dt_now_jst_aware = datetime.datetime.now(
        datetime.timezone(datetime.timedelta(hours=9))
    )
    file_name = dt_now_jst_aware.strftime("%Y%m%d_%H%M%S") + ".log"
    file_path = os.path.join(logs_dir_name, file_name)
    file_handler = FileHandler(file_path)
    file_handler.setLevel(DEBUG)
    file_handler.setFormatter(formatter)
    logger.addHandler(file_handler)
    return logger

ログを記述するファイルで以下のように呼び出し使用します。

from my_logger import get_my_logger
logger = get_my_logger(__name__)
def test_func():
    logger.debug("debug だよ")

こちらが出力です。

2022-02-11 17:43:25,961 : mod1 : DEBUG : 7 : debug だよ

そしてこの出力はlogs/20220211_174325.logにファイルとして保存されています。

Jupyter Notebook でも表示されます。

logger

logger 出力と print どっちがいい?

小規模かつ個人で実験するだけの Python コードであればprintで良いと思います。

一方で、規模の大きいコードや会社で使用するコードを書く場合はloggerを使った方が良いと感じています。

会社の場合は何かと説明が必要になるので、時刻やどこまでうまくいってるかの情報が残っている方が何かと便利です。

参考

以下に参考サイトを記載します。 特に 2, 4 つ目の情報は非常に参考になりました。

  1. 公式ドキュメント
  2. "Logging モジュールではじめるログ出力入門" で PyCon JP 2021 に登壇した
  3. ログ出力のための print と import logging はやめてほしい
  4. 【Python】仕組みを理解してログ出力を使いこなす