標準モジュールのloggingについて紹介(基本編)

f:id:monozukuri-bu:20190218213229p:plain — jupyter_notebook

はじめまして、モノづくり部のokadaです。

皆さんPython書いてますか。Pythonって便利ですよね。
小さな自動化ツールを作成したり、Webアプリを作成したり、
データ解析したり、機械学習のプログラムを作成したりと幅広いですよね。

モノづくり部のお仕事の内、30%~40%はPythonのお仕事です。
斯く言う私も普段業務でPythonを読んだり書いたりしております。

さて私の記事ではPython関連の情報を書いていきたいと思います。
内容としてはPythonの入門書にあまり書いていないが、
業務では当たり前のように使用する情報を書きたいと思います。
故にPythonの基本的な文法については紹介しません。
他のサイトやPython チュートリアルを参照ください。

Python環境

以下の環境で動作確認しています。

Ubuntu 18.04
Python 3.6.5

今回の内容はloggingです。
loggingの基本的な機能や書き方について書きたいと思います。
尚、ログ内容や設計については詳細に記載せず、あくまでloggingの紹介です。

loggingによるログ出力

まずは下記コードをlog.pyという名前で保存します。

import logging

logging.critical('critical')
logging.error('error')
logging.warning('warning')
logging.info('info')
logging.debug('debug')

実行してみましょう。

> python log.py

CRITICAL:root:critical
ERROR:root:error
WARNING:root:warning

ログメッセージがコンソールに出力されましたね。

ログレベル

ログレベルはイベントのレベルや重大度から名前を付けられています。

レベル	いつ使うか
DEBUG	おもに問題を診断するときにのみ関心があるような、詳細な情報。
INFO	想定された通りのことが起こったことの確認。
WARNING	想定外のことが起こった、または問題が近く起こりそうである (例えば、'disk space low') ことの表示。
ERROR	より重大な問題により、ソフトウェアがある機能を実行できないこと。
CRITICAL	プログラム自体が実行を続けられないことを表す、重大なエラー。

デフォルト設定ではWARNING以上のレベルのログメッセージが出力されます。
ではログレベルをDEBUGに変更してみましょう。
basicConfigにレベルを指定します。

import logging

logging.basicConfig(level=logging.DEBUG)

logging.critical('critical')
logging.error('error')
logging.warning('warning')
logging.info('info')
logging.debug('debug')

実行してみます。

> python log.py

CRITICAL:root:critical
ERROR:root:error
WARNING:root:warning
INFO:root:info
DEBUG:root:debug

DEBUG以上のレベルのログメッセージが出力されましたね。

フォーマット

アプリケーションログの情報では何が必要でしょうか。
例えばマルチプロセス、マルチスレッドのプログラムでDEBUG時に
左記IDなど分かるとテストしやすいなど色々考えられますね。
ここでは最低限の時刻とログレベルとメッセージを出力するようにします。

loggingでは上記のログ情報を出力する際、決まったフォーマットが準備されています。

フォーマット	説明
%(asctime)s	時刻を人間が読める書式で表したもの
%(levelname)s	メッセージのための文字のロギングレベル
%(message)s	ログメッセージ

上記以外のフォーマットについては公式ドキュメントを参照ください。
https://docs.python.jp/3/library/logging.html#logrecord-attributes

それではbasicConfigにフォーマットを設定してみます。

import logging

log_fmt = "[%(asctime)s %(levelname)s] %(message)s"
logging.basicConfig(level=logging.DEBUG, format=log_fmt)

logging.critical('critical')
logging.error('error')
logging.warning('warning')
logging.info('info')
logging.debug('debug')

実行してみましょう。

> python log.py

[2019-02-17 22:55:24,095 CRITICAL] critical
[2019-02-17 22:55:24,095 ERROR] error
[2019-02-17 22:55:24,095 WARNING] warning
[2019-02-17 22:55:24,095 INFO] info
[2019-02-17 22:55:24,095 DEBUG] debug

指定したフォーマットで、時刻、ログレベル、メッセージが出力されていますね。

さらにファイルに出力してみましょう。
basicConfigのfilenameにtest.logを指定します。

import logging

log_fmt = "[%(asctime)s %(levelname)s] %(message)s"
logging.basicConfig(filename='test.log', level=logging.DEBUG, format=log_fmt)

logging.critical('critical')
logging.error('error')
logging.warning('warning')
logging.info('info')
logging.debug('debug')

実行してみましょう。