定期的に実行されるバッチスクリプトなどで問題が起きたときの記録や、問題が起きていなくても、実行したことを記録したいときなどには、ログを出力することが一般的です。
また、デバッグ用に特別なログを入れておき、不具合の原因を探すということもあります。
ログは、管理と問題発生時の原因究明や障害回復には必須となるプログラムの基盤の一つです。
Pythonでログを出力するには、loggingモジュールを使います。
最も単純なログ出力
最も単純なログを出力することは次の通りです。
import logging
logging.basicConfig(level=logging.INFO)
logging.info("Most Simple Log. The Value is %d.", 10)
次のようにして実行すると、ログが出力されます。
$ python3 demo.py
INFO:root:Most Simple Log. The Value is 10.
ログの出力方法
ログを出力するには、次のログ出力用の関数を呼びます。
ログの種類別に次のような関数が用意されています。出力したいログに合わせて使い分けてください。
- info()
- warning()
- error()
- critical()
- exception()
- debug()
引数に渡す文字列はフォーマット文字列です。
ログレベル
ログの種類によって重要度が異なります。この重要度はログレベルとして定義されています。
例えば、実際の運用ではdebug()で出力されるログは必要ありません。しかし、開発時の開発者には必要な情報です。
どのレベル以上のログを実際に出力するか指定することができるようになっています。
出力されるログレベルの変更
サンプルコードの中で呼んでいるbasicConfig()メソッドのlevel引数で出力するコードレベルの下限を指定できます。サンプルコードではINFO以上を出力するように指定しています。
ログレベルは、高い方から順に以下のものが定義されています。
- CRITICAL
- ERROR
- WARNING
- INFO
- DEBUG
- NOTSET
DEBUGはINFOよりも低いので、basicConfig()メソッドでINFOを指定していると、DEBUGレベルのログは出力されません。
import logging
logging.basicConfig(level=logging.INFO)
logging.info("This is an INFO level log.")
logging.debug("This is an DEBUG level log.")
このコードを実行すると、次のように出力されます。
INFO:root:This is an INFO level log.
次のように、出力レベルをDEBUGに変更すると、debug()で出力したログも出力されるようになります。
import logging
logging.basicConfig(level=logging.DEBUG)
logging.info("This is an INFO level log.")
logging.debug("This is an DEBUG level log.")
INFO:root:This is an INFO level log.
DEBUG:root:This is an DEBUG level log.
ログの出力先
ログのデフォルト出力先は標準エラー (stderr) になっています。記録として残すなら、ファイルに出力した方が良いでしょう。
ログの出力先をファイルに変更するには、basicConfig()のfilename引数でファイルパスを指定します。
import logging
logging.basicConfig(level=logging.INFO, filename="example.log")
logging.info("This is an INFO level log.")
実行すると、カレントディレクトリにexample.logファイルが作られて、ログが出力されます。ログはファイルに追記出力されます。ファイルが既にある場合は、ファイルの後ろに追記されていきます。
ログに日時を出力する
ログをファイルに記録するようにしたときに、役に立つログにするには、日時が不可欠です。いつ実行されたのか？ログとログの間にどれくらいの時間がかかっているのか？など、ログの出力日時は重要な情報です。
ログに日時を出力するには、ログの出力フォーマットを変更して、日時を含めるようにします。
出力フォーマットの変更は、basicConfig()のformat引数で指定します。
import logging
logging.basicConfig(level=logging.INFO, filename="example.log",
format="%(asctime)s %(levelname)s:%(name)s:%(message)s")
logging.info("This is an INFO level log.")
実行すると、次のように日時が行頭に出力されます。
2020-03-10 15:41:22,772 INFO:root:This is an INFO level log.
format引数に指定した%(asctime)sが出力時に置き換えられます。
日時の他に、デフォルトの出力結果と同じになるように出力する情報を指定しています。
%(levelname)sはログレベルの名前、%(name)sはロガーの名前、%(message)sはログ文字列に置き換えられます。
名前付きのロガーを使用していないので、rootという名前が出力されています。
basicConfigを実行するタイミング
Pythonのloggingモジュールはスレッドセーフになっています。複数のスレッドからログ出力を行うことができます。
ただし、basicConfig()メソッドについてはメインスレッドで、別のスレッドからloggingモジュールを使用する前に実行することとなっています。
そのため、プログラムを実行した直後のできるだけ早いタイミングでbasicConfig()メソッドでログの設定を行った方が良いでしょう。
