Pythonでログ管理をする際に使用するloggingモジュールで設定ファイルを用いて制御する使い方を解説します。
Contents
loggingモジュール
プログラムを開発する際にはログを出力して、実行時や障害が発生した時に何が起こっているのか把握することが非常に重要です。Pythonでログ出力する場合にはloggingモジュールを使用することができます。
本記事ではloggingモジュールを使う際に、設定ファイルを用意して制御をする方法について紹介します。なお、よりシンプルにloggingを使う方法については「loggingの基本的な使い方」にまとめていますので参考にしてもらえればと思います。
以下で説明する設定ファイルやロギングの使用例をコピーして利用いただくだけでも、基本的なログ出力については対応できるかと思いますので、参考に使ってみていただければと思います。
loggingの設定ファイルの用意
loggingを使用する場合には、「logging.ini」といった形でログ設定ファイルを用意しておくと便利です。以下のサンプル例を使って内容を説明します。
# ===== logging settings [loggers] keys=root,simpleExample [handlers] keys=logFileHandler,streamHandler [formatters] keys=logFileFormatter,simpleFormatter # ===== logger settings [logger_root] level=INFO handlers=logFileHandler [logger_simpleExample] level=DEBUG handlers=streamHandler qualname=simpleExample propagate=0 # ===== log handler settings [handler_logFileHandler] class=FileHandler level=INFO formatter=logFileFormatter args=('app.log', 'a', 'utf-8') [handler_streamHandler] class=StreamHandler level=DEBUG formatter=simpleFormatter args=(sys.stdout,) # ===== log handler settings [formatter_logFileFormatter] format=%(asctime)s - %(name)s - %(levelname)s - %(message)s [formatter_simpleFormatter] format=%(asctime)s - %(levelname)s - %(message)s
logging設定
# ===== logging settings [loggers] keys=root,simpleExample [handlers] keys=logFileHandler,streamHandler [formatters] keys=logFileFormatter,simpleFormatter
上記の部分は、ログに関する要素として何があるかを列挙して定義している部分です。
- loggers:ロガーはログを出力するためのものです。ロガーの種類としてどのようなものがあるかを列挙します。
- handlers: 各ロガーがログをどのように扱うかといったハンドラーの種類を列挙します。
- formatters: ログ出力の際にどのような情報をどういったフォーマットで出力するかのフォーマッタの種類を列挙します。
それぞれkeysとして指定している項目については、以降で個別設定方法についての説明をしていきます。
logger設定
# ===== logger settings [logger_root] level=INFO handlers=logFileHandler [logger_simpleExample] level=DEBUG handlers=streamHandler qualname=simpleExample propagate=0
loggerの部分は、各ロガーの設定を定義します。まず、ロガーで理解しておいてもらいたいのはログレベルについてです。ログレベルには以下の種類があります。
- CRITICAL
- ERROR
- WARNING
- INFO
- DEBUG
言葉の意味からも分かるように、上位に記載したレベルの方が緊急度が高いログレベルということなります。プログラムでログレベルを設定すると指定したログレベルより緊急度が高いレベルのログが出力されるようになります。
例えば、ログレベルをINFOにしたとしましょう。その際には、ログとして出力されるのはCRITICAL, ERROR, WARNING, INFOです。DEBUGログは出力されません。
DEBUGログは開発者がデバッグする際に使うログで、すべて出してしまうとログが大量に出力されてしまい、ログファイルの肥大化を招いてしまいます。そのため、通常アプリケーションを稼働する場合はINFOやWARNINGレベルに設定します。
では、logging.iniの設定内容を見ていきましょう。[logger_ロガー名]という記載でそれぞれの定義を記載します。
- level: ログレベルを定義します。上記例では、rootロガーはINFO, simpelExampleロガーはDEBUGとしています。
- handlers: ロガーが使用するログハンドラーを指定します。ハンドラーの詳細は後述します。
- qualname: ロガーの名前を定義します。
- propagate: この値が真の場合は、ロガーに取り付けられたハンドラに加えて、上位のハンドラーにもイベントが渡されます。今回の例では0(偽)としているため、上位ハンドラーには渡されません。公式ドキュメントの説明はこちらに記載があります。
handler設定
# ===== log handler settings [handler_logFileHandler] class=FileHandler level=INFO formatter=logFileFormatter args=('app.log', 'a', 'utf-8') [handler_streamHandler] class=StreamHandler level=DEBUG formatter=simpleFormatter args=(sys.stdout,)
handlerの部分はログハンドラーの設定を定義します。
Pythonにはログハンドラーというものがいくつも定義されています。詳しくは公式ドキュメントのこちらに記載があります。ファイルに出力するFileHandlerやストリームに出力するStreamHandlerの他、ログをメールで送信するSMTPHandlerなど色々とあります。
ハンドラー設定は[handler_ハンドラー名]という記載で、それぞれのハンドラーの挙動を定義します。
- class: ハンドラーのクラスを指定します。上記の例では、logFileHandlerは「FileHandler」でapp.logにutf-8で追記出力、streamHandlerは「StreamHandler」で標準出力へ出力という設定になっています。
- level: ハンドラーのログレベルを指定します。指定レベルよりも深刻ではないログメッセージは無視されます。
- formatter: ログ出力フォーマットを規定するフォーマッタを指定します。フォーマッタの設定は後述します。
- args: 各ハンドラーの入力引数を指定します。引数は各ハンドラの記載がある公式ドキュメントのこちらを参照してください。
formatter設定
# ===== log handler settings [formatter_logFileFormatter] format=%(asctime)s - %(name)s - %(levelname)s - %(message)s [formatter_simpleFormatter] format=%(asctime)s - %(levelname)s - %(message)s
formatterの部分はログ出力フォーマットを指定するフォーマッタの設定を定義をしています。
フォーマッタ設定は、[formatter_フォーマッタ名]という記載でそれぞれのフォーマットを定義します。
「format=」で指定していますが、%で書かれた部分はLogRecord属性というもので、その部分は属性に該当する情報で補完してログ出力してくれます。上記の例に出てくる項目の意味は以下の通りです。
- asctime: ログが生成された時刻を表示する(例: 2022-02-10 00:00:00,000 ※カンマ以降はミリ秒)
- names: ロギングに使われたロガーの名称
- levelname: ロギングレベル
- message: ログメッセージ
フォーマットで指定できるLogRecord属性名は他にも色々ありますので、公式ドキュメントのこちらを参照して自分に必要な情報を組み合わせてみてください。
loggingの使い方
上記で説明してきた「logging.ini」を用意すると後は開発したプログラム側でログを出力するコードを書くことでログが出力できます。以降で開発プログラム側でのログ出力方法について説明します。
ログの出力方法
以下のサンプルプログラムのように記載することでログ出力することができます。
import logging import logging.config def main(): logging.config.fileConfig('logging.ini') # ===== ルートロガーを使用する場合 logger = logging.getLogger(__name__) # アプリケーション内でのログ記載方法 logger.debug('デバッグメッセージ') logger.info('インフォメッセージ') logger.warning('ワーニングメッセージ') logger.error('エラーメッセージ') logger.critical('クリティカルメッセージ') # ===== simpleExampleロガーを使用する場合 logger_s = logging.getLogger('simpleExample') # アプリケーション内での記載方法 logger_s.debug('デバッグメッセージ') logger_s.info('インフォメッセージ') logger_s.warning('ワーニングメッセージ') logger_s.error('エラーメッセージ') logger_s.critical('クリティカルメッセージ') if __name__ == '__main__': main()
【app.log出力内容】 2022-02-10 12:27:28,961 - __main__ - INFO - インフォメッセージ 2022-02-10 12:27:28,961 - __main__ - WARNING - ワーニングメッセージ 2022-02-10 12:27:28,961 - __main__ - ERROR - エラーメッセージ 2022-02-10 12:27:28,961 - __main__ - CRITICAL - クリティカルメッセージ
【コンソールへの標準出力内容】 2022-02-10 12:27:28,962 - DEBUG - デバッグメッセージ 2022-02-10 12:27:28,962 - INFO - インフォメッセージ 2022-02-10 12:27:28,962 - WARNING - ワーニングメッセージ 2022-02-10 12:27:28,962 - ERROR - エラーメッセージ 2022-02-10 12:27:28,962 - CRITICAL - クリティカルメッセージ
使用方法としては以下の手順で行います。まずは、loggingとlogging.configをインポートします。
import logging import logging.config
次に、ログ設定ファイル「logging.ini」を読み込みます。
logging.config.fileConfig('logging.ini')
これで設定ファイルの内容が読み込まれます。次に、getLoggerを使って、使用するロガーのインスタンスを作成します。作成している場所は以下の部分です。
# ===== ルートロガーを使用する場合 logger = logging.getLogger(__name__) # ===== simpleExampleロガーを使用する場合 logger_s = logging.getLogger('simpleExample')
よく使うのは引数に「__name__」を指定する方法です。これによりメインで動いているときはログに”__main__”と出力されますし、パッケージなどを呼び出している際には該当するプログラム名が入ります。
また、個別にsimpleExampleロガーをlogger_sの方でインスタンス化しています。
ここまででログを出力する準備が整いました。ログを出力する場合には、以下のコードのように使用します。
# アプリケーション内でのログ記載方法 logger.debug('デバッグメッセージ') logger.info('インフォメッセージ') logger.warning('ワーニングメッセージ') logger.error('エラーメッセージ') logger.critical('クリティカルメッセージ')
メソッド名を見ていただければわかるように、メソッド名がそのままログレベルを表していますので、debugメソッドを使えばDEBUGレベルとして出力をします。
ログ出力結果を確認してみましょう。まず、ルートロガーはFileHandlerを使っているためapp.logに出力されます。また、INFOレベルの設定のためDEBUGは出力されていないことが分かるでしょう。
一方で、simpleExampleロガーの方は、StreamHandlerを使って標準出力に出力する設定となっているため、ターミナルに結果が表示されます。またDEBUGレベルの設定のためDEBUG以上の全てのレベルが表示されていることが分かるかと思います。
以上のようにすることで簡単にログを出力することができます。
応用:ログフィルタ
応用編として、ログの出力内容をフィルタリングする例を見てみましょう。
方法としてはlogging.Filterを継承したフィルタ用のクラスを作成して、ロガーをインスタンス化する際にaddFilterメソッドで設定をしてあげることで実現がきます。
以下は’password’という文字列が入っているメッセージをログ出力しないようにするためのフィルタ作成例です。passwordのような出力されては問題となるようなものを誤ってプログラムに書いてしまった時の対策として使用できます。
import logging import logging.config class LogPwFilterSample(logging.Filter): """ログ出力のフィルタ例 例)passwordというテキストが入るログメッセージは出力しない """ def filter(self, record: str) -> None: """ :param record: ログレコード :return: None """ log_message = record.getMessage() return 'password' not in log_message def main(): logging.config.fileConfig('logging.ini') # ===== simpleExampleロガーを使用する場合 logger_s = logging.getLogger('simpleExample') logger_s.addFilter(LogPwFilterSample()) # アプリケーション内での記載方法 logger_s.debug('デバッグメッセージ') logger_s.info('インフォメッセージ') logger_s.warning('ワーニングメッセージ') logger_s.error('エラーメッセージ') logger_s.critical('クリティカルメッセージ') # ログフィルタを設定しているので以下は出力されない logger_s.info('password = xxxxxx') if __name__ == '__main__': main()
【実行結果】 2022-02-10 17:50:46,178 - DEBUG - デバッグメッセージ 2022-02-10 17:50:46,178 - INFO - インフォメッセージ 2022-02-10 17:50:46,178 - WARNING - ワーニングメッセージ 2022-02-10 17:50:46,178 - ERROR - エラーメッセージ 2022-02-10 17:50:46,178 - CRITICAL - クリティカルメッセージ
確認しやすいように標準出力のストリームに出力するsimpleExampleロガーの方だけで確認しています。
結果を見てもわかるように最後に記載している’password’という記載があるログについては出力されていないことが分かります。
他にも色々なフィルタを試しに作ってみてください。
loggingの使い方をより細かく知る
上記でloggingの基本的な使用方法を紹介してきましたが、より細かく設定について調べたい場合は、公式ドキュメントの「Logging HOWTO」を読むことがおすすめです。
基本的なloggingチュートリアルから上級ロギングチュートリアルということで色々と記載されていますので、是非確認してみてもらえればと思います。本記事の内容は上級ロギングチュートリアルの内容を参考にしております。
上記で紹介しているソースコードについてはgithubにて公開しています。参考にしていただければと思います。