目次
3. ハンドラの応用(logging.handlers.XXXHandler)
0. はじめに
0.1. 環境に関して
loggingモジュールは実行環境によっては最初からハンドラというものが入っている事がある．この場合，意図せぬ出力の重複が出るかもしれない．
参考：
その時は上記記事にもあるが，以下のコードのようにルートロガーへの伝播を切ると良い．
logger = logging.getLogger(__name__)
logger.propagate = False
0.2. 背景，動機
loggingモジュールを調べるにあたった理由は，自動化プログラムを組んでいる際にログを取得する必要に気付いたからだ．
以下の章では文体が崩れる．
1. ログ出力と出力レベル
loggingはモジュールであり，python.exe1つに対して1つしか存在しない制約がある．そのためオブジェクト(logger)を作り用いると良い．
python
import logging
logger_1 = logging.getLogger("Alice")
# __name__にするとモジュール，実行ファイル名が出力されるため，より分かりやすくなる．
# logger_1 = logging.getLogger(__name__)
# ログ出力
logger_1.debug('Debug') # 出力されないはず
logger_1.info('Informarion') # 出力されないはず
logger_1.warning('Warning')
logger_1.error('Error')
logger_1.critical('Critical')
出力
WARNING:Alice:Warning
ERROR:Alice:Error
CRITICAL:Alice:Critical
debug，infoが出力されないのは出力レベルが設定されていないからである．設定にはsetLevel()メソッドを使う．
python
logger_1 = logging.getLogger("Alice")
# ログの出力レベルを設定
logger_1.setLevel(level=logging.INFO)
# ログ出力
logger_1.debug('Debug') # ここだけ出力されないはず
logger_1.info('Informarion')
logger_1.warning('Warning')
logger_1.error('Error')
logger_1.critical('Critical')
出力
INFO:Alice:Informarion
WARNING:Alice:Warning
ERROR:Alice:Error
CRITICAL:Alice:Critical
INFOの中身には20というint型の値が入っている．各レベルには以下の数値が入っている．
| レベル名 | 数値 |
|---|---|
| DEBUG | 10 |
| INFO | 20 |
| WARNING | 30 |
| ERROR | 40 |
| CRITICAL | 50 |
2. ハンドラとは
2.1. ハンドラのイメージ
ハンドラはloggerがログ出力の際に使用する道具のようなもの．
| ハンドラインスタンス | loggerに付与される機能 |
|---|---|
| StreamHandler | ターミナルへの出力 |
| FileHandler | ファイルへの出力 |
| SMTPHandler | 特定のメールアドレスへの送信出力 |
| HTTPHandler | HTTPサーバへの出力 |
python
logger_2_1 = logging.getLogger("Bob_1")
logger_2_1.setLevel(level=logging.INFO)
logger_2_1.propagate = False
# ハンドラクラスをインスタンス化
stream_handler = logging.StreamHandler()
file_handler = logging.FileHandler(filename="test_S2_1.log", mode="w", encoding="utf-8")
# インスタンス化したハンドラをlogger(Bob_1)に渡す
logger_2_1.addHandler(stream_handler)
logger_2_1.addHandler(file_handler)
logger_2_1.debug('Debug')
logger_2_1.info('Informarion')
logger_2_1.warning('Warning')
logger_2_1.error('Error')
logger_2_1.critical('Critical')
# fileログの表示
print("-----"*5)
with open("test_S2_1.log", mode="r", encoding="utf-8") as rf:
for line in rf.readlines():
print(line, end="")
出力(ターミナル)
Informarion
Warning
Error
Critical
-------------------------
Informarion
Warning
Error
Critical
2.2. ハンドラのレベル
ハンドラにもそれぞれに出力レベルが存在する．設定方法は1章と同様である．
python
logger_2_2 = logging.getLogger("Bob_2")
logger_2_2.setLevel(level=logging.INFO)
logger_2_2.propagate = False
stream_handler = logging.StreamHandler()
file_handler = logging.FileHandler(filename="test_S2_2.log", mode="w", encoding="utf-8")
# ハンドラの出力レベル設定
stream_handler.setLevel(level=logging.INFO)
file_handler.setLevel(level=logging.WARNING)
logger_2_2.addHandler(stream_handler)
logger_2_2.addHandler(file_handler)
logger_2_2.debug('Debug')
logger_2_2.info('Informarion')
logger_2_2.warning('Warning')
logger_2_2.error('Error')
logger_2_2.critical('Critical')
print("-----"*5)
# ファイルへの出力レベルをWarning以上に設定したため，INFOが出力されないことを確認する
with open("test_S2_2.log", mode="r", encoding="utf-8") as rf:
for line in rf.readlines():
print(line, end="")
出力(ターミナル)
Informarion
Warning
Error
Critical
-------------------------
Warning
Error
Critical
2.3. ハンドラの出力フォーマット
loggingには出力フォーマットがあり，logging.Formatter(fmt, datefmt)で設定できる．
フォーマットのパラメータは以下の通り．
| パラメータ名 | 説明 |
|---|---|
| name | ロガーの名前 |
| asctime | タイムスタンプの文字列表現 |
| created | タイムスタンプ（秒単位） |
| levelname | ログレベル名（INFO, WARNING, etc.） |
| levelno | ログレベル番号（10, 20, etc.） |
| message | ログメッセージ |
| module | ログ発生モジュール名 |
| filename | ログ発生ファイル名 |
| pathname | ログ発生ファイルのフルパス |
| funcName | ログ発生関数名 |
| lineno | ログ発生行番号 |
| process | プロセスID |
| thread | スレッドID |
| threadName | スレッド名 |
| msecs | タイムスタンプのミリ秒部分 |
| relativeCreated | ロガー生成からの経過時間（ミリ秒） |
python
logger_2_3 = logging.getLogger("Bob_3")
logger_2_3.setLevel(level=logging.INFO)
logger_2_3.propagate = False
stream_handler = logging.StreamHandler()
file_handler = logging.FileHandler(filename="test_S2_3.log", mode="w", encoding="utf-8")
stream_handler.setLevel(level=logging.INFO)
file_handler.setLevel(level=logging.INFO)
# ハンドラの出力フォーマット設定
fmt = "%(levelname)-9s %(asctime)s [%(filename)s:%(lineno)d] %(message)s"
stream_handler.setFormatter(logging.Formatter(fmt=fmt))
file_handler.setFormatter(logging.Formatter(fmt=fmt, datefmt="%Y/%m/%d-%H:%M:%S"))
logger_2_3.addHandler(stream_handler)
logger_2_3.addHandler(file_handler)
logger_2_3.debug('Debug')
logger_2_3.info('Informarion')
logger_2_3.warning('Warning')
logger_2_3.error('Error')
logger_2_3.critical('Critical')
print("-----"*5)
with open("test_S2_3.log", mode="r", encoding="utf-8") as rf:
for line in rf.readlines():
print(line, end="")
出力(ターミナル)
INFO 2024-05-18 09:49:10,123 [<ipython-input-15-0fcb01f9fecd>:20] Informarion
WARNING 2024-05-18 09:49:10,127 [<ipython-input-15-0fcb01f9fecd>:21] Warning
ERROR 2024-05-18 09:49:10,131 [<ipython-input-15-0fcb01f9fecd>:22] Error
CRITICAL 2024-05-18 09:49:10,133 [<ipython-input-15-0fcb01f9fecd>:23] Critical
-------------------------
INFO 2024/05/18-09:49:10 [<ipython-input-15-0fcb01f9fecd>:20] Informarion
WARNING 2024/05/18-09:49:10 [<ipython-input-15-0fcb01f9fecd>:21] Warning
ERROR 2024/05/18-09:49:10 [<ipython-input-15-0fcb01f9fecd>:22] Error
CRITICAL 2024/05/18-09:49:10 [<ipython-input-15-0fcb01f9fecd>:23] Critical
3. ハンドラの応用(logging.handlers.XXXHandler)
3.1. RotatingFileHandler(出力先のファイルサイズによる循環)
循環とは：
ログ出力は、その性質上時間経過と共に容量が増え続けるものである。
そこで実際の運用時には、ログファイルの循環についての設定をしておく必要がある。
ログファイルの循環とは、出力先のファイルを容量もしくは経過時間によって新しいものと切り替える設定のことである。
Pythonのloggingをイメージで理解する【Python Logging徹底解説】
設定方法は以下の通り．maxBytesまでのファイルをbackupCount個作る．backupCount=0の場合は作られない．
class logging.handlers.RotatingFileHandler(filename, mode='a', maxBytes=0, backupCount=0, encoding=None, delay=False, errors=None)
python
!mkdir "test_S3_1"
logger_3_1 = logging.getLogger("Charlotte")
logger_3_1.setLevel(level=logging.INFO)
stream_handler = logging.StreamHandler()
# FileHandler => RotatingFileHandler
file_handler = logging.handlers.RotatingFileHandler(filename="test_S3_1/test_S3_1.log", maxBytes=100, backupCount=10, encoding="utf-8")
stream_handler.setLevel(level=logging.INFO)
file_handler.setLevel(level=logging.INFO)
fmt = "%(levelname)-9s %(asctime)s [%(filename)s:%(lineno)d] %(message)s"
stream_handler.setFormatter(logging.Formatter(fmt=fmt))
file_handler.setFormatter(logging.Formatter(fmt=fmt))
logger_3_1.addHandler(stream_handler)
logger_3_1.addHandler(file_handler)
logger_3_1.debug('Debug')
logger_3_1.info('Informarion')
logger_3_1.warning('Warning')
logger_3_1.error('Error')
logger_3_1.critical('Critical')
print("-----"*5)
with open("test_S3_1/test_S3_1.log", mode="r", encoding="utf-8") as rf:
for line in rf.readlines():
print(line, end="")
出力(ターミナル)
INFO 2024-05-18 09:57:02,986 [<ipython-input-16-823db5e116ad>:21] Informarion
WARNING 2024-05-18 09:57:02,990 [<ipython-input-16-823db5e116ad>:22] Warning
ERROR 2024-05-18 09:57:02,993 [<ipython-input-16-823db5e116ad>:23] Error
CRITICAL 2024-05-18 09:57:02,997 [<ipython-input-16-823db5e116ad>:24] Critical
-------------------------
CRITICAL 2024-05-18 09:57:02,997 [<ipython-input-16-823db5e116ad>:24] Critical
作業ディレクトリに複数のログファイルが出来ていることが分かる．
3.2. TimedRotatingFileHandler(経過時間による循環)
設定方法は以下の通り．
class logging.handlers.TimedRotatingFileHandler(filename, when='h', interval=1, backupCount=0, encoding=None, delay=False, utc=False, atTime=None, errors=None)
| when | interval の単位 | atTime の使用有無/使用方法 |
|---|---|---|
| 'S' | 秒 | 無視 |
| 'M' | 分 | 無視 |
| 'H' | 時間 | 無視 |
| 'D' | 日 | 無視 |
| 'W0'-'W6' | 曜日 (0=月曜)(interval is unused) | 初期のロールオーバー時刻の算出に使用 |
| 'midnight' | atTime が指定されなかった場合は深夜に、そうでない場合は atTime の時刻にロールオーバーされます | 初期のロールオーバー時刻の算出に使用 |
[when="S", interval=10]なら10秒経過後に別ログファイルが作られる．
python
!mkdir "test_S3_2"
logger_3_2 = logging.getLogger("Charlotte")
logger_3_2.setLevel(level=logging.INFO)
logger_3_2.propagate = False
stream_handler = logging.StreamHandler()
# FileHandler => TimedRotatingFileHandler
file_handler = logging.handlers.TimedRotatingFileHandler(filename="test_S3_2/test_S3_2.log", when="S", interval=1, backupCount=10, encoding="utf-8")
stream_handler.setLevel(level=logging.INFO)
file_handler.setLevel(level=logging.INFO)
fmt = "%(levelname)-9s %(asctime)s [%(filename)s:%(lineno)d] %(message)s"
stream_handler.setFormatter(logging.Formatter(fmt=fmt))
file_handler.setFormatter(logging.Formatter(fmt=fmt))
logger_3_2.addHandler(stream_handler)
logger_3_2.addHandler(file_handler)
logger_3_2.debug('Debug')
logger_3_2.info('Informarion')
logger_3_2.warning('Warning')
logger_3_2.error('Error')
logger_3_2.critical('Critical')
print("-----"*5)
with open("test_S3_2/test_S3_2.log", mode="r", encoding="utf-8") as rf:
for line in rf.readlines():
print(line, end="")
出力(ターミナル)
INFO 2024-05-18 10:04:48,149 [<ipython-input-17-7d071b68b122>:21] Informarion
WARNING 2024-05-18 10:04:48,152 [<ipython-input-17-7d071b68b122>:22] Warning
ERROR 2024-05-18 10:04:48,154 [<ipython-input-17-7d071b68b122>:23] Error
CRITICAL 2024-05-18 10:04:48,157 [<ipython-input-17-7d071b68b122>:24] Critical
-------------------------
INFO 2024-05-18 10:04:48,149 [<ipython-input-17-7d071b68b122>:21] Informarion
WARNING 2024-05-18 10:04:48,152 [<ipython-input-17-7d071b68b122>:22] Warning
ERROR 2024-05-18 10:04:48,154 [<ipython-input-17-7d071b68b122>:23] Error
CRITICAL 2024-05-18 10:04:48,157 [<ipython-input-17-7d071b68b122>:24] Critical
実行するごとにログファイルが作られていることが分かる．
3.3. HTTPHandler擬き
HTTPHandlerを使用してDiscordに通知を飛ばそうとしたのですが上手くいかず，他ライブラリで力押ししました．そのため擬きとしました．
python(自作ハンドラ，フィルタ)
class DiscordHandler(logging.Handler):
def __init__(self, url):
super().__init__()
self.url = url
def emit(self, record:logging.LogRecord):
if (type(record.msg) is str):
data = {"content": self.format(record),
"username": "Taro",
}
res = requests.post(url=self.url, data=data)
elif (type(record.msg) is bytes):
data = {"username": "Taro",}
files = {"file": ("test.png", record.msg)}
res = requests.post(url=self.url, files=files, data=data)
class BytesFilter(logging.Filter):
def __init__(self):
super().__init__()
def filter(self, record):
return not (type(record.msg) is bytes)
python
import json
import requests
from google.colab import drive
drive.mount("/content/drive")
URL = "<YOUR DISCORD WEBHOOK URL>"
logger_3_3 = logging.getLogger("Dom")
logger_3_3.setLevel(logging.INFO)
logger_3_3.propagate = False
formatter = logging.Formatter("%(levelname)-9s%(asctime)s [%(pathname)s:line%(lineno)d]%(message)s", datefmt="%Y/%m/%d-%H:%M:%S")
discord_handler = DiscordHandler(url=URL)
discord_handler.setFormatter(formatter)
discord_handler.setLevel(level=logging.CRITICAL)
logger_3_3.addHandler(discord_handler)
stream_handler = logging.StreamHandler()
stream_handler.setLevel(level=logging.INFO)
stream_handler.setFormatter(formatter)
stream_handler.addFilter(BytesFilter())
logger_3_3.addHandler(stream_handler)
logger_3_3.debug('Debug')
logger_3_3.info('Informarion')
logger_3_3.warning('Warning')
logger_3_3.error('Error')
logger_3_3.critical('Critical')
img = None
with open("/content/drive/MyDrive/logger_explain.png", mode="rb") as rbf:
img = rbf.read()
logger_3_3.critical(img)
出力(ターミナル)
INFO 2024/05/18-10:20:45 [<ipython-input-5-34a290deb6fa>:line21]Informarion
WARNING 2024/05/18-10:20:45 [<ipython-input-5-34a290deb6fa>:line22]Warning
ERROR 2024/05/18-10:20:45 [<ipython-input-5-34a290deb6fa>:line23]Error
CRITICAL 2024/05/18-10:20:45 [<ipython-input-5-34a290deb6fa>:line24]Critical
discord側にも上手く送信できています．
4. おわりに
記事を書いていて気付いたのですが，タイムゾーンの設定が上手くいっていませんね．調べた感じでは以下の記事で解決してるみたいです．
初めての記事で至らないところもあると思いますが，お目通しいただきありがとうございます．