Pythonでログ管理をする際に使用するloggingモジュールの基本的な使い方を解説します。
Contents
loggingモジュール
プログラムを開発する際にはログ出力して、実行時や障害発生時に何が起こっているかを把握することが非常に重要です。Pythonでログを出力する場合にはloggingモジュールを使用することができます。
本記事ではloggingモジュールの基本的な考え方と使い方について紹介します。
ログレベル
loggingモジュールでは、ログの重要度によって以下の5つのログレベルを使用できます。
- CRITICAL
- ERROR
- WARNING
- INFO
- DEBUG
ログの重要度としては、1のCRITICALの方が重要度が高く、システムとしては重大な問題が発生していることを意味しています。通常のアプリケーションでは、WARNING以上もしくはアプリケーションによってはINFO以上を出力するということが多いかと思います。後ほど例を紹介しますがloggingモジュールでは、デフォルトでWARNING以上のログを出力する設定となります。
常にすべてのログを出しているとログファイルサイズが大きくなってディスクを圧迫したり、重要なログが埋もれてしまったりといったことがあります。ただ、不具合が起こった際には調査のために詳細な情報が必要です。そのような場合には、DEBUGモードに設定を変更して詳細な情報を出力して調査するといったことをします。
プログラマーは目的に応じて出力するメッセージレベルをどうするかよく考えてコーディングをする必要があります。
loggingモジュールの基本的な使い方
基本的な出力方法
loggingモジュールを使うには以下の例のように使用します。
import logging
# デフォルトで出力されるのはWARNING以上
logging.critical('クリティカル')
logging.error('エラー')
logging.warning('ワーニング')
logging.info('インフォ')
logging.debug('デバッグ')【コンソール出力結果】 CRITICAL:root:クリティカル ERROR:root:エラー WARNING:root:ワーニング
まずは、loggingモジュールを使用するためにimportする必要があります。
その後ログを出力するためには、ログレベルと同じ名称であるメソッド(critical, error, warning, info, debug)に出力したいログメッセージの文字列を引数として渡します。
デフォルトではログレベルはWARNINGとなっているため、WARNING以上のログレベルのログしか出力されていないことが分かります。
basicConfig関数による設定
loggingモジュールの設定を変更する場合には、basicConfig関数を使用します。loggingモジュールにおいて、basicConfig関数はロギング制御をする重要なものなのでしっかり覚えておきましょう。
ログレベルの指定方法 (level)
INFOやDEBUGレベルでログを出力したい場合には、以下のようにbasicConfig関数のlevel引数で指定することで出力するログレベルを変更することができます。
import logging
# ロギングレベルの設定(DEBUG以上を出力する)
logging.basicConfig(level=logging.DEBUG)
logging.critical('クリティカル')
logging.error('エラー')
logging.warning('ワーニング')
logging.info('インフォ')
logging.debug('デバッグ')【コンソール出力結果】 CRITICAL:root:クリティカル ERROR:root:エラー WARNING:root:ワーニング INFO:root:インフォ DEBUG:root:デバッグ
上記の例では、ログレベルをDEBUGに変更しています。出力ではDEBUG以上のログが出力されていることが分かります。
ログをファイルに出力する方法 (filename)
ログをファイルに出力したい場合には、以下のようにbasicConfig関数のfilename引数で出力ファイルを指定します。
import logging
# ファイルにログ情報を出力する
logging.basicConfig(filename='test.log', encoding='utf_8')
logging.critical('クリティカル')
logging.error('エラー')
logging.warning('ワーニング')
logging.info('インフォ')
logging.debug('デバッグ')【test.logの出力結果】 CRITICAL:root:クリティカル ERROR:root:エラー WARNING:root:ワーニング
実行するとtest.logファイルにログメッセージが出力されます。
フォーマットの指定方法 (format)
ログ出力フォーマットは、アプリケーションごとに変更することが可能です。ログ出力フォーマットを指定する場合には、basicConfig関数のformat引数にフォーマットを指定する文字列を指定します。
import logging
# フォーマットの設定
formatter = '%(asctime)s:%(levelname)s:%(name)s:%(message)s'
logging.basicConfig(format=formatter)
# フォーマットに従って出力される
logging.critical('クリティカル')
logging.error('エラー')
logging.warning('ワーニング')
logging.info('インフォ')
logging.debug('デバッグ')【コンソール出力結果】 2022-04-06 06:59:47,964:CRITICAL:root:クリティカル 2022-04-06 06:59:47,964:ERROR:root:エラー 2022-04-06 06:59:47,964:WARNING:root:ワーニング
上記のようにformatterという文字列で出力する形式を指定し、basicConfigのformat引数に渡します。
formatter文字列のところでは%(xxxxx)sという形式で出力したい情報を指定しています。xxxxxのところにはどういった情報出したいかで指定を変えます。例えば上記例で、「asctime」を指定しているところには出力時点の日時が出力されます。
フォーマットで指定できるものは他にも色々ありますので、公式ドキュメントのこちらを参照して必要な情報を組み合わせてみてください。
複数モジュールでのログ出力
Pythonプログラミングでは複数モジュールを作って連携させるということが一般的です。そのような際にログ出力はどうするべきでしょうか。例えば以下のような例を考えます。
この例では、logmain.pyというプログラムからlogtest.py内で定義されているsimple_func()という関数を使用しています。このような場合にはどのモジュールで出力されたかログで分かるようにしたいですね。また、モジュールごとにログ出力レベルを変えたいといったようなこともあると思います。
このような例での基本的な考え方は以下とするのが良いかと思います。
- メイン側でbasicConfigによるログの基本的な設定を実施する。
- 使用モジュール側ではロガーやハンドラーを個別に設定して使用する。
これを実現するためには、ロガー(logger)やハンドラ(handler)を使用します。以降で上記のような構成でロガーやハンドラを使用するプログラム例をご紹介します。
ロガーの使用 (logger)
loggingモジュールはロガー(logger)というものを用意することで、ログ出力の動きをモジュールごとに分けることができます。以下の例で見てみましょう。
[logmain.py]
import logging
import logtest
# ロギングの基本設定
formatter = '%(asctime)s:%(levelname)s:%(name)s:%(message)s'
logging.basicConfig(level=logging.INFO,
format=formatter,
filename='logmain.log',
encoding='utf_8')
logger = logging.getLogger(__name__)
logger.info('mainログ１')
logger.debug('mainログ２')
# モジュールを呼び出し
logtest.simple_func()[logtest.py]
import logging
# モジュール用のロガーを設定 DEBUGに設定
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
def simple_func():
logger.info('logtestログ１')
logger.debug('logtestログ２')
def main():
pass
if __name__ == '__main__':
main()[出力結果]
【logmain.logの出力結果】 2022-04-06 07:16:47,006:INFO:__main__:mainログ１ 2022-04-06 07:16:47,006:INFO:logtest:logtestログ１ 2022-04-06 07:16:47,006:DEBUG:logtest:logtestログ２
内容について詳細に説明していきます。この例では、logmain.pyでlogtestをimportして、logtest.py内で定義しているsimple_func()を呼び出しています。
logmain.pyではまず以下の部分のbasicConfig関数でログ出力の基本設定を行います。この例では、formatter文字列で指定したフォーマットでlogmain.logにINFO以上の出力をするように指定しています。
# ロギングの基本設定
formatter = '%(asctime)s:%(levelname)s:%(name)s:%(message)s'
logging.basicConfig(level=logging.INFO,
format=formatter,
filename='logmain.log',
encoding='utf_8')次にlogmain.py側で以下のようにロガーというものを作成しています。
logger = logging.getLogger(__name__)
logger.info('mainログ１')
logger.debug('mainログ２')ロガーは、getLogger関数で生成できます。getLoggerで生成したロガーのログ出力メソッド(critical, error, warning, info, debug)を呼び出すことでログ出力ができます。
次に、logtest.pyの方を見てみましょう。logtest側でもモジュール用のロガーを用意していますが、こちらはsetLevelメソッドでログレベルをDEBUGに設定しています（main側はINFOです）。出力フォーマットについては結果を見てみればわかりますが、logmain側のbasicConfigで設定されたフォーマットに従います。
# モジュール用のロガーを設定 DEBUGに設定 logger = logging.getLogger(__name__) logger.setLevel(logging.DEBUG)
上記を踏まえて結果を見てみましょう。
【logmain.logの出力結果】 2022-04-06 07:16:47,006:INFO:__main__:mainログ１ 2022-04-06 07:16:47,006:INFO:logtest:logtestログ１ 2022-04-06 07:16:47,006:DEBUG:logtest:logtestログ２
結果を見ると、main側のログはINFO以上のためdebugで出力している「logger.debug(‘mainログ２’)」については出力されていません。一方で、logtest側のログについてはDEBUGとしているためINFO、DEBUGともに出力されていることが分かるかと思います。
また、この例で引数に__name__を指定していることも一つのポイントです。出力結果を見てみると分かりますが、%(name)sの部分にロガーの名前として__name__の値が入っています。これにより、main側で出力されたログなのか、呼び出し先のモジュールで出力されたログなのかを判別することができます。
上記例のようにロガーを活用することで複数モジュールでのログ出力についても対応できます。
ハンドラの使用 (handler)
loggingモジュールにはハンドラー(handler)というものが定義されています。ファイルに出力するFileHandlerやストリームに出力するStreamHandlerの他、ログをメールで送信するSMTPHandlerのようなものもあります。
ハンドラーを設定することで、ログの出力動作を変更することができます。以下の例を見ていきましょう。この例は上記のロガーの説明と同じようにlogmain.pyと呼び出すモジュールのlogtest.pyがあるという構成になっています。
[logmain.py]
import logging
import logtest
# ロギングの基本設定
formatter = '%(asctime)s:%(levelname)s:%(name)s:%(message)s'
logging.basicConfig(level=logging.INFO,
format=formatter,
filename='logmain.log',
encoding='utf_8')
logger = logging.getLogger(__name__)
logger.info('mainログ１')
logger.debug('mainログ２')
# モジュールを呼び出し
logtest.simple_func()[logtest.py]
import logging
# モジュール用のロガーを設定 DEBUGに設定
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
# ハンドラーを設定
h = logging.FileHandler('logtest.log', encoding='utf_8')
logger.addHandler(h)
def simple_func():
logger.info('logtestログ１')
logger.debug('logtestログ２')
def main():
pass
if __name__ == '__main__':
main()[出力結果]
[logmain.logの出力結果] 2022-04-07 06:32:16,907:INFO:__main__:mainログ１ 2022-04-07 06:32:16,907:INFO:logtest:logtestログ１ 2022-04-07 06:32:16,907:DEBUG:logtest:logtestログ２
[logtest.logの出力結果] logtestログ１ logtestログ２
以降で内容について説明します。logtest.pyの方で以下の部分でハンドラーを設定しています。
# ハンドラーを設定
h = logging.FileHandler('logtest.log', encoding='utf_8')
logger.addHandler(h)ハンドラーは種類によってクラスが用意されていて、上記はFileHandlerを使用しています。ハンドラーはロガーに設定することで使用することができ、対象ロガーのaddHandlerメソッドで設定します。この例では、’logtest.log’というファイルに出力するというハンドラーを設定しています。
結果を見てみると’logmain.log’の方はmain及びlogtest側のログが’logmain.log’に出力されることが分かります。一方で、’logtest.log’にはlogtest.py側のログのみが出力されていることが分かります。
このようにハンドラーを追加することで、各モジュール個別にログ出力の挙動を変えることができます。モジュール個別にログ調査や個別の処理を実施したい場合などに便利です。
ログハンドラーについては、詳しくは公式ドキュメントのこちらを参照してください。
設定ファイルで制御したい場合
簡単なスクリプトや小規模なシステムであれば上記に記載の使用方法で十分なログ出力ができるかと思います。しかし、大規模なシステムになってくるとログ出力制御を設定ファイルで実施したくなってくるかもしれません。
設定ファイルを使ってloggingの制御をする基本的な使い方について「loggingの基本的な使い方 ~設定ファイル編~」を参考にしてください。
loggingの使い方をより細かく知る
上記でloggingの基本的な使用方法を紹介してきましたが、より細かく設定について調べたい場合は、公式ドキュメントの「Logging HOWTO」を読むことがおすすめです。
基本的なloggingチュートリアルから上級ロギングチュートリアルということで色々と記載されていますので、是非確認してみてもらえればと思います。本記事の内容は基本ロギングチュートリアルの内容を参考にしております。
上記で紹介しているソースコードについてはgithubにて公開しています。参考にしていただければと思います。
