Zenn
🐈

Act 09.Pythonでログ出力を行う

2024/10/27に公開
Python
tech

はじめに

Act 01. AIで外国為替を自動売買するまでの道のりをベースに学習を進めて行く。

Act 08. Pythonでエラーハンドリングを行うを書いていて、ログ出力に関する学習もした方が良いなと思ったためこの記事を書いている。

loggingモジュールを使っていくわけだが、簡単な使い方しか知らない。
今回は様々なカスタマイズも行う。

loggerの基本的な使い方

大まかな流れは以下の通り。

  1. loggingモジュールのインポート
  2. ロガーの設定
  3. ログの出力

ということでやっていく。

1. loggingモジュールのインポート

Act09.py
import logging

2. ロガーの設定

Act09.py
logger = logging.getLogger()
logger.setLevel(logging.INFO) # ログレベルの設定

file_hanbler = logging.FileHandler("app.log") # ファイルハンドラーの作成
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") # ログのフォーマット
file_hanbler.setFormatter(formatter)  # ファイルハンドラーにフォーマットを設定

logger.addHandler(file_hanbler) # ロガーにファイルハンドラーを追加

3. ログの出力

Act09.py
logger.error("test")

最終的なコード

Act09.py
import logging

logger = logging.getLogger()
logger.setLevel(logging.INFO) # ログレベルの設定

file_hanbler = logging.FileHandler("app.log") # ファイルハンドラーの作成
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") # ログのフォーマット
file_hanbler.setFormatter(formatter)  # ファイルハンドラーにフォーマットを設定

logger.addHandler(file_hanbler) # ロガーにファイルハンドラーを追加

logger.error("test")

コードを実行すると以下の内容がログに出力される。

2024-10-27 22:15:45,932 - root - ERROR - test

大体はこんな感じでやっておけばOK。
以降でもう少し詳しく説明しようと思う。

複数のloggerを使用する

これは想像がつくだろうが、複数のロガーを定義することが可能。
モジュールごとに異なるロガーを使いたい場合に有効。

Act09.py
import logging

# カスタムロガーの作成
logger1 = logging.getLogger('module1')
logger1.setLevel(logging.DEBUG)

logger2 = logging.getLogger('module2')
logger2.setLevel(logging.INFO)

# ファイルハンドラーの追加
handler = logging.FileHandler('custom.log')
handler.setFormatter(logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s'))
logger1.addHandler(handler)
logger2.addHandler(handler)

logger1.debug("module1のデバッグメッセージ")
logger2.info("module2の情報メッセージ")

後ほど出てくるが、%(name)sはロガーの名前を表すため、ログにロガー名が出力される。
モジュールごとにロガーを定義するのは結構便利かも。

2024-10-27 22:28:20,888 - module1 - DEBUG - module1のデバッグメッセージ
2024-10-27 22:28:20,888 - module2 - INFO - module2の情報メッセージ

ログフォーマットのカスタマイズ

ログメッセージのフォーマットをカスタマイズすることが可能。
フォーマットには以下のような情報を含めることができる。

項目 記述方法
日時 %(asctime)s
ログレベル %(levelname)s
メッセージ %(message)s
ロガー名 %(name)s
ファイル名 %(filename)s
行番号 %(lineno)d

以下のような３つのフォーマットで出力してみた。

Act09.py
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") # ログのフォーマット１
formatter = logging.Formatter("%(asctime)s [%(levelname)s](%(filename)s):  %(message)s") # ログのフォーマット２
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s - %(filename)s - %(lineno)d") # ログのフォーマット３

ログの内容は以下の通り。

2024-10-27 22:15:45,932 - root - ERROR - test
2024-10-27 22:22:41,360 [ERROR](Act09.py):  test
2024-10-27 22:23:16,941 - root - ERROR - test - Act09.py - 14

タイムスタンプを%Y/%m/%d %H:%M:%Sの形式にしたい。。
って場合は以下の通りに記述すればOK。datefmtで指定可能。

Act09.py
formatter = logging.Formatter(
    fmt='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
    datefmt='%Y/%m/%d %H:%M:%S'  # 日付フォーマットを変更
)

ログのローテーション

ログファイルにログを出力していて、定期的にローテーションを行いたい場合があると思う。
その場合は時間ごとにローテーションする方法と、ファイルのサイズでローテーションする方法がある。

時間

まずは時間でローテーションする場合から。
TimedRotatingFileHandlerクラスを使用する。

Act09.py
import time
import logging
from logging.handlers import TimedRotatingFileHandler

logger = logging.getLogger("time_rotate_logger")
logger.setLevel(logging.ERROR)

# whenには以下を指定する
#   S - Seconds
#   M - Minutes
#   H - Hours
#   D - Days
#   midnight - roll over at midnight
#   W{0-6} - roll over on a certain day; 0 - Monday
handler = TimedRotatingFileHandler("./logs/error.log", when="S", interval=5, backupCount=5)
handler.setLevel(logging.ERROR)
formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)

for i in range(30):
  logger.error(f"{i + 1}つ目のテストエラーログ")
  time.sleep(1)

実行すると、以下のようにファイルのローテーションが行われる。

以下のように５秒ごとにローテーションされていることが確認できる。

この状態で再度実行すると、backupCountで設定しているローテーション時に保管するファイル数を超えるため、一番古いファイル（画像の場合は左上のerror.log.2024-10-27_22-43-00）が削除される。

ファイルサイズ

次にファイルサイズでローテーションを行う場合。
RotatingFileHandlerを使用する。

Act09.py
import logging
from logging.handlers import RotatingFileHandler

logger = logging.getLogger("rotate_logger")
logger.setLevel(logging.INFO)

handler = RotatingFileHandler("./logs/access.log", maxBytes=2000, backupCount=3)
handler.setLevel(logging.INFO)
formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)

for i in range(1000):
    logger.info(f"デバッグメッセージ {i}")

実行すると以下の通りローテーションされる。
こっちは時間でローテーションしていないため、末尾に数字が付与されることになる。

さいごに

loggingモジュールは便利だね。
これで一通りPythonについて学習できたから、次は数学を勉強していくよ。

学生以来だからかなり手こずりそう…
ではまた

Discussion