Pythonのログ出力をローテーションさせる方法を紹介します。
ログの出力はlogging関連パッケージを使うことで柔軟に制御できます。ただ、柔軟性の高さが仇となりドキュメントを読んで理解しないと使いこなすのは難しいです。
この記事はlogging関連パッケージのお勉強の内容ではなく、ログをファイルに出力するシチュエーションを想定して、気軽にコピペしてあなたのプログラムに流用できることを意識した内容になっています。
カスタマイズが必要な箇所の説明も気持ちばかししているので、コピペ＆カスタム推奨です。
ハンドラについてさらっと説明
Pythonのloggingパッケージは、大きく分けてロガー・ハンドラ・フォーマッター・フィルタという4つの機能から成り立っています。
このうち、今回のテーマとなっているログローテーションに大きく関わってくるのがハンドラの部分です。ハンドラは主に書き出し先を制御する機能を担っています。
デフォルトのハンドラはコンソールに出力するStreamHandlerですが、この記事ではファイルローテーションさせるためのハンドラとして用意されているRotatingFileHandlerやTimedRotatingFileHandlerを使用していきます。
ファイルサイズでローテーション
まずはファイルサイズが一定に達したら新しいファイルに切り替える方式から紹介します。
この方式は、Linuxのsyslogをはじめとして広く用いられていて、一般的に100K Byteごとにローテートされ、古いファイルを4〜7ファイルだけ残す設定になっています。
ということでsyslogとほぼ同じようにローテーションするログの設定例です。ログの設定と出力確認の両方を行うプログラムですが、設定を行っているのはinit_logging()関数の中です。
from logging import Formatter, getLogger, INFO
from logging.handlers import RotatingFileHandler
root = getLogger()
def init_logging():
""" ログのローテーション設定 """
global root
# ローテーションのタイミングを100キロバイト
max_bytes = 100 * 1024
# 保持する旧ファイル数
backup_count = 4
handler = RotatingFileHandler(
'log/myapp.log', # logフォルダが存在しないとエラーになるので注意
maxBytes=max_bytes,
backupCount=backup_count,
encoding='utf-8')
# フォーマッタでログ文字列の出力を指定しています。
# ほぼ全てのプロジェクトで文句なしで使えるのでコピペすればOK。
formatter = Formatter('{asctime} {name:<8s} {levelname:<8s} {message}', style='{')
handler.setFormatter(formatter)
root.addHandler(handler)
# rootロガーのデフォルトはlogging.WARNなのでINFOに変更
root.setLevel(INFO)
def main():
""" ログを出力して動作確認。Ctrl+Cで終了。 """
global root
# ログ出力をしまくってローテーションを確認
while True:
root.info('サンプルログ出力')
if __name__ == '__main__':
init_logging()
main()
RotatingFileHandlerはログファイルのサイズが一定サイズを超えるとローテーションしてくれるハンドラです。このハンドラをインスタンス化する際に、maxBytesにログが切り替わるサイズの目安を、backupCountに古いファイルをいくつ残すかを指定します。
このプログラムを実際に実行すると、こんな感じでファイルが作成されます。
$ ls -l
total 960
-rw-r--r-- 1 jimaru staff 79596 10 16 14:08 myapp.log
-rw-r--r-- 1 jimaru staff 102376 10 16 14:08 myapp.log.1
-rw-r--r-- 1 jimaru staff 102376 10 16 14:08 myapp.log.2
-rw-r--r-- 1 jimaru staff 102376 10 16 14:08 myapp.log.3
-rw-r--r-- 1 jimaru staff 102376 10 16 14:08 myapp.log.4
ファイルの中身をheadコマンドで10行だけチラ見るしてみると、中身はログで埋め尽くされているのがわかりますね。
$ head -n 10 myapp.log
2021-10-16 14:08:13,782 root INFO サンプルログ出力
2021-10-16 14:08:13,782 root INFO サンプルログ出力
2021-10-16 14:08:13,782 root INFO サンプルログ出力
2021-10-16 14:08:13,782 root INFO サンプルログ出力
2021-10-16 14:08:13,782 root INFO サンプルログ出力
2021-10-16 14:08:13,782 root INFO サンプルログ出力
2021-10-16 14:08:13,782 root INFO サンプルログ出力
2021-10-16 14:08:13,782 root INFO サンプルログ出力
2021-10-16 14:08:13,782 root INFO サンプルログ出力
2021-10-16 14:08:13,782 root INFO サンプルログ出力
myapp.log.1などのフィアルサイズ102376を1024で割ると、ほぼ100となります。つまり100KBごとにログがローテーションされているのがわかります。
時間経過でローテーション
こんどは、ファイルサイズではなく一定時間ごとにローテーションさせるサンプルを紹介します。1日ごとにログファイルをローテーションするサンプルにしましょう。
プログラムは先ほどのサイズローテーションとほぼ同じ構成です。異なるのは次の点です。
- RotatingFileHandlerではなくTimeRotatingFileHandlerを使っている（ここが重要）
- sleep(3600)を使って1時間に1度の出力にしている（検証目的です）
- random.choice([True, False])を条件にしてログ出力がランダムになるようにしている（検証目的です）
from logging import Formatter, getLogger, INFO
from logging.handlers import TimedRotatingFileHandler
from time import sleep
import random
root = getLogger()
def init_logging():
""" ログのローテーション設定 """
global root
handler = TimedRotatingFileHandler(
'log/myapp', # logフォルダが存在しないとエラーになるので注意。また、拡張子があると古いファイルが削除されてくれないので注意。
when='midnight', # S=秒, M=分, H=時, D=日, midnight=夜中
backupCount=7, # when='midnight', interval=1だと1ファイルが1日分なので7日分保持することになる
interval=1, # when='midnight'なので1日でローテーションという意味になる
encoding='utf-8')
# フォーマッタでログ文字列の出力を指定しています。
# ほぼ全てのプロジェクトで文句なしで使えるのでコピペすればOK。
formatter = Formatter('{asctime} {name:<8s} {levelname:<8s} {message}', style='{')
handler.setFormatter(formatter)
root.addHandler(handler)
# rootロガーのデフォルトはlogging.WARNなのでINFOに変更
root.setLevel(INFO)
def main():
""" ログを出力して動作確認。Ctrl+Cで終了。 """
global root
# 1時間に1回ずつログを出力した状態を1週間継続すると結果が出る
while True:
# ローテーションのタイミングがファイルサイズとは無関係という確認の目的で、
# ログ出力するかしないかがランダムに決定されるようにした。
if random.choice([True, False]):
root.info('サンプルログ出力')
sleep(3600)
if __name__ == '__main__':
init_logging()
main()
実際にこのプログラムを7日間実行すると、日をまたぐごとにログファイルがローテートされるのを観察することができます。
7日分のローテーションを確認するのはさすがに時間がかりすぎるので😅、いったん10秒ごとローテートの1秒ごとログ出力になるようにプログラムを書き換えて実行しました。これなら、7ローテーションでも7分で検証することができますからね。
$ ls -l
total 64
-rw-r--r-- 1 jimaru staff 134 10 16 16:30 myapp
-rw-r--r-- 1 jimaru staff 402 10 16 16:29 myapp.2021-10-16_16-29-25
-rw-r--r-- 1 jimaru staff 268 10 16 16:29 myapp.2021-10-16_16-29-35
-rw-r--r-- 1 jimaru staff 469 10 16 16:29 myapp.2021-10-16_16-29-46
-rw-r--r-- 1 jimaru staff 335 10 16 16:30 myapp.2021-10-16_16-29-57
-rw-r--r-- 1 jimaru staff 469 10 16 16:30 myapp.2021-10-16_16-30-09
-rw-r--r-- 1 jimaru staff 402 10 16 16:30 myapp.2021-10-16_16-30-19
-rw-r--r-- 1 jimaru staff 268 10 16 16:30 myapp.2021-10-16_16-30-29
実行して生成されたログファイルを見てみると、7ファイルの範囲内でローテートされています。それぞれのファイルサイズもまちまちで、ファイルサイズは関係なしに時間によってローテーションされているということがわかります。
ちなみにローテートされたファイルの末尾についている「2021-10-16_16-29-25」という文字列は、ローテーションの頻度によって必要な情報だけが含まれるようになっています。今回は秒ごとにローテーションさせたので、秒の情報までが含まれました。これが日ごとのローテーションだと、「2021-10-16」といった情報のみ含まれるようになります。
ハマりポイント
この記事書いている時にハマって焦ったポイントがあります。それは、TimedRotatingFileHandlerを使うときは、ログファイル名に拡張子を付けてはいけないということです。
'log/myapp.log'のようにしてはダメで、'log/myapp'としないとダメ。
拡張子が付いていると、ログローテーションされた時に古いファイルが削除されず、どんどん古いファイルが溜まり続けることになります。
設定ファイルを使う
yaml形式の設定ファイルを使って上述したのと同じことができます。設定ファイルで設定できることは、設定ファイルでやったほうがクールだし、Python触ったことない人でもyamlの設定ファイルなら触れるゼ！って人もいますからね。
ということで、yaml設定ファイルを使ったサンプルを紹介します。
準備
サンプルを紹介する前に、あらかじめPyPIから必要パッケージをインストールしておいて下さい。yamlファイルをPythonから読み込むのに必要になります。
$ pip install ruamel.yaml
サイズでローテーション
設定ファイルsize_rotate.ymlを作成します。
version: 1
formatters:
default:
format: '{asctime} {name:<8s} {levelname:<8s} {message}'
style: '{'
handlers:
size-rotate:
class: logging.handlers.RotatingFileHandler
filename: 'log/myapp' # logフォルダが存在しないとエラーになるので注意
maxBytes: 1024e2
backupCount: 4
encoding: utf-8
formatter: default
root:
level: INFO
handlers:
- size-rotate
設定ファイルを使ってサイズローテーションさせるプログラムを作成します。
from logging import getLogger
from pathlib import Path
from logging.config import dictConfig
from ruamel.yaml import YAML
root = getLogger()
def init_logging():
# 設定ファイルのパスを設定
config_path = Path('size_rotate.yml')
# 設定ファイルから読み込んでDict型にしている
config_value = YAML().load(config_path)
# logging.dictConfig()関数に渡すと設定される
dictConfig(config_value)
def main():
""" ログを出力して動作確認。Ctrl+Cで終了。 """
global root
# ログ出力をしまくってローテーションを確認
while True:
root.info('サンプルログ出力')
if __name__ == '__main__':
init_logging()
main()
yamlファイルの読み込みはruamel.yamlというパッケージを使っています。
そして読み込んだものをlogging.config.dictConfig()関数に渡すと設定が完了します。プログラムとしてはかなりスッキリしました。
時間でローテーション
設定ファイルday_rotate.ymlを作成します。
version: 1
formatters:
default:
format: '{asctime} {name:<8s} {levelname:<8s} {message}'
style: '{'
handlers:
day-rotate:
class: logging.handlers.TimedRotatingFileHandler
filename: 'log/myapp'
when: 'midnight'
interval: 1
backupCount: 7
encoding: utf-8
formatter: default
root:
level: INFO
handlers:
- day-rotate
設定ファイルを使って日ごとにローテーションさせるプログラムを作成します。
from logging import getLogger
from logging.config import dictConfig
from ruamel.yaml import YAML
from pathlib import Path
from time import sleep
import random
root = getLogger()
def init_logging():
""" ログのローテーション設定 """
config_path = Path('day_rotate.yml')
config_value = YAML().load(config_path)
dictConfig(config_value)
def main():
""" ログを出力して動作確認。Ctrl+Cで終了。 """
global root
# 1時間に1回ずつログを出力した状態を1週間継続すると結果が出る
while True:
# ランダムにTrueになった時のみログ出力
if random.choice([True, False]):
root.info('サンプルログ出力')
sleep(1)
if __name__ == '__main__':
init_logging()
main()
init_logging()関数の内容は、サイズローテーションのときと全く同じです。
つまり、設定ファイルの内容を変更するだけで、プログラムをいじらなくてもログ出力を切り替えることができるってことですね。
