目次
- 目次
- はじめに
- loggingモジュールの基本的な使い方
- コマンドラインからログのレベル変更
- モジュール毎のロガー設定とロギングレベルの変更
- loggingのhandler
- loggingのfilter
- 設定ファイルによるロガーの設定
- 参考資料
- MyEnigma Supporters
はじめに
自分以外の人に使用されるソフトウェアを開発している場合、
自分の手元では発生しない問題や、
たまにしか発生しない問題に悩まされることが多いと思います。
そんな場合は、手元で再現することができないので、
ソフトウェアにロガーを埋め込み、
その問題が発生した時のログファイルを元に
問題解決することになります。
そんな時に重要なのが、
元のソフトウェアを変更することなく、
必要な情報を得るためのロギング機能を実装することです。
今回の記事では、Pythonの標準ライブラリの一つである
ロギング機能用モジュールloggingの基本的な使い方や、
ユースケースに基づく、逆引きメモを紹介したいと思います。
loggingモジュールの基本的な使い方
基本的には、下記の公式ドキュメントが最も参考になります。
コマンドラインからログのレベル変更
非常にシンプルなロガーの使い方として、
単体で動くPythonスクリプトを、
実行時の引数からロガーレベルを変更することを考えます。
残念ながら、loggingモジュールは、
実行時の引数から直接ロギングレベルを変更することはできないので、
同じ公式ライブラリであるargparseと併用すると便利です。
import logging import argparse def get_log_level_from_args(): parser = argparse.ArgumentParser() parser.add_argument("--log", type=str, default="Warn") return logging.getLevelName(parser.parse_args().log.upper()) logging.basicConfig(level=get_log_level_from_args()) logging.debug('debug') logging.info('info') logging.warning('warning') logging.error('error') logging.critical('critical')
上記のコードのように、
argparseで取得した--logの値をbasicConfigに与えることで、
何も指定しないと、defaultのwarnレベル以上が表示されますが、
--log=Debugを指定すると、すべてのレベルのログが表示されます。
今回使用したbasicConfigにfilenameを指定することで、
ログをファイルに保存したり、
formatにログフォーマットを指定することで、
ログに時刻を追加することができます。
モジュール毎のロガー設定とロギングレベルの変更
前述のbasicConfigを使うと、
実行しているすべてのロガーのログレベルを変更してしまいます。
もし、規模の大きいシステムを開発している時は、
あるモジュールのみのロガーレベルを変更してデバックをしたくなります。
そんなときは、それぞれのモジュール個別のロガーを設定しておくと、
モジュール毎にログレベルやログの設定を変更できます。
例えば、moduleA.pyとmoduleB.pyを下記のようにします。
moduleA.py
from logging import getLogger, StreamHandler logger = getLogger(__name__) handler = StreamHandler() logger.addHandler(handler) logger.propagate = False def process(): logger.debug('debug') logger.info('info') logger.warning('warning') logger.error('error') logger.critical('critical')
moduleB.py
from logging import getLogger, StreamHandler logger = getLogger(__name__) handler = StreamHandler() logger.addHandler(handler) logger.propagate = False def process(): logger.debug('debug') logger.info('info') logger.warning('warning') logger.error('error') logger.critical('critical')
そして、これら２つのモジュールを利用するスクリプトがある場合、
下記のように、あるモジュールだけのログレベルを変更することができます。
from logging import getLogger, DEBUG import moduleA import moduleB print("======") moduleA.process() print("======") moduleB.process() # Only change moduleA logger level alogger = getLogger("moduleA") alogger.setLevel(DEBUG) print("======") moduleA.process() print("======") moduleB.process()
上記を実行すると、
片方のモジュールだけログレベルを変更できます。
ちなみに、getLoggerで渡すロガーの名前が同じ場合、
同じ名前のloggerの参照が渡されます。
これにより、複数のモジュールから一つのロガーに
ログを送信することが可能です。
加えて、loggingのログ出力機能は、
スレッドセーフです。
したがって、単一プロセスの複数のスレッドから
一つの出力先にログを出力することができます。
しかし、複数のプロセスから、
一つのファイルに書き込むことはできないため、
そのような場合は、SocketやHTTPのHandlerを使うか、
QueueHandlerを使って、Queue Comsumterとして
ログを保存させる必要があります。
loggingのhandler
Pythonのloggingで混乱しやすい所は、handlerだと思います。
このhandlerは、それぞれのloggerにaddHandler()やremoveHandler()で
複数設定でき、それぞれのhandlerの設定方法によって、
別々のログの処理を実施することができます。
それぞれのhandlerは個別のロガーレベルを持っているため、
例えば、一つのloggerで、
info以上のログは標準出力に
warn以上のログはファイル保存し、
critical以上のログはメール送信する
といったような、設定をすることができます。
また、それぞれのhandlerにformatterを設定できるので、
それぞれのログのフォーマットを別々に設定することができます。
loggingで使えるhandler
下記は代表的なloggingのハンドラです。
ハンドラを受け取るハンドラなども存在します。
StreamHandler: 標準出力など、様々なストリームにログを出力
FileHandler: ファイルにログを出力
NullHandler: 何も出力しない (ライブラリなどで意図的にデフォルトでログを出力したくない時に使います)
RotatingFileHandler: ログファイルのサイズをベースにRotateするログファイルを出力
TimedRotatingFileHandler: ロギングの時間をベースにRotateするログファイルを出力
WatchedFileHandler: newsyslogやlogrotateなどで変更されるログファイルにログを出力
SocketHandler: ログをTCPソケットベースで送信
DatagramHandler: ログをUDPソケットベースで送信
SysLogHandler: ログをローカル or 遠隔のUnix syslogに出力
NTEventLogHandler: ログをWindows NT, 2000, Windows XP のイベントログに送信
SMTPHandle: ログをSMTPベースのメール送信
MemoryHandler: ログの内容を一度、メモリにバッファし、定期的に別のハンドラに送信
HTTPHandler: ログをHTTPのgetやpostで、HTTPサーバに送信
QueueHandler: 別スレッドでハンドラを実行するハンドラ
loggingモジュールで利用可能なhandlerは、
下記のAPIドキュメントから、参照できます。
loggingのfilter
loggingのfilterは、ある条件にあったログのみを保存したり、
ログに、ログ出力した以外の情報を追加して、
ログ送信したいときに便利です。
例えば、passwordという文字列が入っているログを
保存 or 出力しないようにしたり、
複数のスレッドでログを出力したいときに、
スレッドの番号などをログに追加できます。
filterの設定は、logging.Filterを継承するクラスを作り、
そのクラスの中でログに含めるかを判断する
booleanを返すfilter関数を定義し、
ハンドラにaddFilter(filter)すればOKです。
from logging import Filter, INFO, basicConfig, getLogger basicConfig(level=INFO) class NoPasswordFilter(Filter): def filter(self, record): log_message = record.getMessage() return 'password' not in log_message logger = getLogger(__name__) logger.addFilter(NoPasswordFilter()) logger.info('User: tom') logger.info('User: andy, password = pass')
上記のコードを実行すると、
passwordという文字が入っていないログだけが
表示されます。
設定ファイルによるロガーの設定
前述の通り、Pythonの標準ライブラリであるloggingを使えば、
非常に細かいロギングの設定が可能です。
しかし、デバックの際に、それぞれのモジュールのログレベルを制御するのに、
それぞれのモジュールのコードに設定を書き込むのは、大変な場合もありますし、
アプリケーション全体のロギングの設定を
一つの設定ファイルで管理したいときもあります。
そんなときは、logging.config.dictConfigの機能を使えば、
jsonやyamlファイルなどに書かれた、アプリケーション全体のロギング設定を
読み込むだけで、設定を変更することができます。
例えば、moduleAとmoduleBのソースコードそのものは、
下記のように、モジュール名を元にloggerを作って利用するだけにしておき、
from logging import getLogger logger = getLogger(__name__) def process(): logger.debug('debug_A') logger.info('info_A') logger.warning('warning_A') logger.error('error_A') logger.critical('critical_A')
from logging import getLogger logger = getLogger(__name__) def process(): logger.debug('debug_B') logger.info('info_B') logger.warning('warning_B') logger.error('error_B') logger.critical('critical_B')
下記のような、アプリケーション全体のロギング設定ファイルを作成します。
一つの設定ファイルにすべてのモジュールのロギングの設定や、
フォーマッタ、ハンドラを定義できます。
{ "version": 1, "formatters": { "simple": { "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s" }, "notime": { "format": "%(name)s - %(levelname)s - %(message)s" } }, "handlers": { "console": { "class": "logging.StreamHandler", "level": "DEBUG", "formatter": "simple", "stream": "ext://sys.stdout" }, "console_notime": { "class": "logging.StreamHandler", "level": "DEBUG", "formatter": "notime", "stream": "ext://sys.stdout" } }, "loggers": { "moduleA": { "level": "DEBUG", "handlers": [ "console" ], "propagate": "no" }, "moduleB": { "level": "ERROR", "handlers": [ "console_notime" ], "propagate": "no" } } }
そして、アプリケーションの起動の最初で、
このファイルを読み込んで、
logging.config.dictConfigでロギングを設定すると、
from logging.config import dictConfig import moduleA import moduleB import json print("======") moduleA.process() print("======") moduleB.process() with open("logconf.json", "r") as f: dictConfig(json.load(f)) print("======") moduleA.process() print("======") moduleB.process()
下記のように、
アプリケーション全体のロギング設定を変更できます。
dictConfig関数は、Pythonの辞書型で設定が定義されていれば良いため、
辞書型に変換できるファイルであれば、
どんなファイルフォーマットでも設定ファイルとして利用できます。
また、このように設定ファイルとソースコードを
別ファイルとして管理することで、
プログラミングがわからない、利用者にでも
ロギングレベルを変更して、ログを取ってもらうことなどが
簡単に依頼できるようになります。
参考資料
ログ出力のための print と import logging はやめてほしい - Qiita
Python Logging Best Practices ~ Pieces of Mind
Logging クックブック — Python 3.8.2 ドキュメント
MyEnigma Supporters
もしこの記事が参考になり、
ブログをサポートしたいと思われた方は、
こちらからよろしくお願いします。
