いつもprintでデバッグしていたけど、もっと良い方法無いかな……
Pythonでログ出力をする方法が知りたい。
configファイルでログのフォーマットを設定したい。
あなたは普段ソースコードをデバッグする時、どのように行っていますか？
print()で行っているという方。もちろん小規模なプログラムであればそれで問題ありませんが、規模が大きくなってくるとデバッグ後に消し忘れたりしてしまいがちですよね。
また、正常時も異常時も、全体の処理の流れを掴みたいと思ったことはありませんか？
上記のような場合、loggingモジュールでログ出力をすることをおすすめします！
この記ことでは、
- ログとは何か？
- loggingモジュールの使い方
- ログのフォーマットをconfigファイルで設定する方法
といった内容についてご紹介します！ 是非最後までお付き合いください。
※なお、この記ことはPython 3.7.3で動作確認致しました。
本記事を読む前に、Pythonがどんなプログラミング言語なのかをおさらいしておきたい人は次の記事を参考にしてください。
→ Pythonとは？特徴やできること、活用例をわかりやすく簡単に解説
なお、その他のPythonの記事についてはこちらにまとめています。
前提知識：ログについて
ログとは
まずはじめに、ログについて簡単にご説明致します。
ログを一言で表すと、プログラムの実行中に起こった出来事の記録です。ログが残ることで、バグが起きたときにエラーが発生した理由を特定したり、ある時点での変数の値を確認したりといったことができます。
開発の現場でログは必須です。「一日の作業がログ解析だけで終わった……」なんてこともざらにあるぐらい、エンジニアにとって身近な存在となります。
ロギングとは
ログを取ること(出力すること)を、ロギング（logging）と言います。
「print()でも良いんじゃないの？」と思う方も居るかも知れませんね。たしかにprint()で処理の流れを把握することも可能ですが、loggingモジュールでロギングをすることで以下のような利点があります。
- ログ出力なのか、ユーザ(プログラム実行者)に伝えたい情報としての出力なのかを切り分けられる
- ログの種類をErrorやDebugのように、レベル分けが出来る
- フォーマットを指定すれば、簡単に統一化された出力の仕方ができる
ログレベルとは
ログの種類をErrorやDebugのようにレベル分けが出来ると言いましたが、ログに出力される情報には以下のような種類があります。
- 使っている設定値や詳細な情報表示などのデバッグ用の表示
- 正常動作の記録
- 警告を出しておきたい動作の記録
- エラーなどの問題の記録、停止してしまうような致命的なエラー
これらの内容は、実行時に悪影響を及ぼす度合いによって以下のようにレベル分けがされています。
| 名前 | 設定値 | 役割 |
|---|---|---|
| NOTSET | 0 | 設定値などの記録（全ての記録） |
| DEBUG | 10 | 動作確認などデバッグの記録 |
| INFO | 20 | 正常動作の記録 |
| WARNING | 30 | ログの定義名 |
| ERROR | 40 | エラーなど重大な問題 |
| CRITICAL | 50 | 停止など致命的な問題 |
loggingモジュールを使うと、どのレベルからログとして残すかを選択出来ます。
例えば開発中はDebugまでの全てを出力し、プログラムが出来てからはInfo以降を出力するといった具合です。
loggingモジュールの使い方
loggingモジュールの基本的な使い方
必要な知識が分かった所で、実際にロギングをしてみましょう。
まず、ロギング機能を使うためにはloggingモジュールをインポートする必要があります。
import logging
loggingは外部モジュールをインストールしなくても、すぐにimportで記述可能です！
それでは、実際に以下の「sample.py」というサンプルコードを元に使い方を確認しましょう。
import logging
# ログの出力名を設定（1）
logger = logging.getLogger('LoggingTest')
# ログをコンソール出力するための設定（2）
sh = logging.StreamHandler()
logger.addHandler(sh)
# log関数でログ出力処理（3）
logger.log(20, 'info')
logger.log(30, 'warning')
logger.log(100, 'test')
これをコンソールで実行すると、
python sample.py
実行結果
warning test
このサンプルコードでは、以下のような点がポイントになります。
(1)：getLoggerメソッドを使ってloggerオブジェクトを生成する
引数に文字列を入れることでログの出力名を設定することが可能
(2)：StreamHandlerクラスを使ってコンソールにログを出力するよう設定する
第1引数には、前章のログレベルの数値を渡す
第2引数にはメッセージとしてログに出力する文字列を入力
(3)：log関数を使ってログを出力させる
ここで一点覚えていただきたいのですが、ログ出力を行うものの総称をロガー（logger）といいます。
ここではLoggerオブジェクトがロガーに当たります。開発をしているとしばしば出てくる言葉なので、ここで覚えておきましょう。
話は戻りますが、ここで実行結果を確認してください。ログレベル20の出力が表示されていませんね。これはデフォルトの設定でログレベル20(INFO)以下は出力しないようになっているためです。
出力するログレベルを変更するには”setLevel()“を呼びます。
import logging
# ログの出力名を設定
logger = logging.getLogger('LoggingTest')
#ログレベルを設定
logger.setLevel(20)
#ログをコンソール出力するための設定
sh = logging.StreamHandler()
logger.addHandler(sh)
logger.log(20, 'info')
logger.log(30, 'warning')
logger.log(100, 'test')
実行結果
info warning test
ここまで、log()によってログを出力していましたが、それぞれのレベルのログを出力させる関数もあります。
import logging
logger = logging.getLogger('LoggingTest')
#ログレベルを指定
logger.setLevel(20)
#ログをコンソール出力するための設定
sh = logging.StreamHandler()
logger.addHandler(sh)
#それぞれのログレベルに応じた関数を呼び出す
logger.info('info')
logger.warning('warning')
logger.error('test')
実行結果は一つ前のlog()で出力したときと同じです。
ログをファイルに出力する
ここまでのサンプルコードでは、ロギング機能の基本的な使い方について解説しました。しかし、これまでのサンプルコードでは、ログファイルの出力先などを決めることは出来ません。
そこで、ログファイルに出力する設定方法について解説します。それではサンプルコードを確認していきましょう。
import logging
# ログの出力名を設定（1）
logger = logging.getLogger('LoggingTest')
# ログレベルの設定（2）
logger.setLevel(10)
# ログのコンソール出力の設定（3）
sh = logging.StreamHandler()
logger.addHandler(sh)
# ログのファイル出力先を設定（4）
fh = logging.FileHandler('test.log')
logger.addHandler(fh)
logger.log(20, 'info')
logger.log(30, 'warning')
logger.log(100, 'test')
logger.info('info')
logger.warning('warning')
実行結果
info warning test info warning
(1)から(3)までは、前の章で先ほど説明した通りです。ここで新たに記述された(4)を確認してください。
(4)では、ログのファイル出力先が設定されています。このようにファイル名を指定しておくことにより、ログをファイルに出力することができるようになります。
ファイル出力されているので、コンソールに表示する必要が無いという場合は(3)の2行を削除すると、ファイル出力のみとなります。
ログのフォーマットを指定する
これまでのサンプルコードでは、ログの出力形式の設定はしていませんでした。ログとして、実行時刻やログの出力した場所、ログレベル名、メッセージなどがそろって出力されなければ、見やすいログとは言えませんよね。
そこでログの出力形式を設定してみましょう。ログの出力形式を設定するためには、loggingモジュールのFormatterクラスを使います。
それではサンプルコードを確認しながら使い方をみていきましょう。
import logging
# ログの出力名を設定
logger = logging.getLogger('LoggingTest')
# ログレベルの設定
logger.setLevel(10)
# ログのコンソール出力の設定
sh = logging.StreamHandler()
logger.addHandler(sh)
# ログのファイル出力先を設定
fh = logging.FileHandler('test.log')
logger.addHandler(fh)
# ログの出力形式の設定
formatter = logging.Formatter('%(asctime)s:%(lineno)d:%(levelname)s:%(message)s')
fh.setFormatter(formatter)
sh.setFormatter(formatter)
logger.log(20, 'info')
logger.log(30, 'warning')
logger.log(100, 'test')
logger.info('info')
logger.warning('warning')
実行結果
2017-05-16 12:14:49,510:27:INFO:info 2017-05-16 12:14:49,511:28:WARNING:warning 2017-05-16 12:14:49,511:29:Level 100:test 2017-05-16 12:14:49,511:31:INFO:info 2017-05-16 12:14:49,511:32:WARNING:warning
このサンプルコードではFormatterクラスを使って、ログの出力形式の設定をしています。Formatterクラスの引数に出力形式を渡して、formatterのインスタンスを作成しています。この例では、
の形式で出力されるような設定になっています。形式のフォーマットはこのようになっています。
| フォーマット | 役割 |
|---|---|
| %(asctime)s | 実行時刻 |
| %(filename)s | ファイル名 |
| %(funcName)s | 行番号 |
| %(levelname)s | ログの定義 |
| %(lineno)d | ログレベル名 |
| %(message)s | ログメッセージ |
| %(module)s | モジュール名 |
| %(name)s | 関数名 |
| %(process)d | プロセスID |
| %(thread)d | スレッドID |
configファイルでログのフォーマットを指定する
ログの設定は文字数（コードの量）が増えがちです。そして文字数が増えると、コードが読みにくくなる原因にもなってしまいます。
そこでlogging.configモジュールを使って、ログの設定を「.conf」ファイルのような設定ファイルにまとめて書くことで管理がしやすくなります。
この章では少し高度な内容になるので、ステップアップしたい方はぜひご覧ください！
ここからは実際にlogging.confという設定ファイルを作って、その仕組みを見ていきましょう。まずはこちらのサンプルコードをご覧ください。
logging.conf
[loggers] keys=root
[handlers]
keys=consoleHandler, fileHandler
[logger_root]
handlers=consoleHandler, fileHandler level=DEBUG [handler_consoleHandler] class=StreamHandler level=DEBUG formatter=logFormatter args=(sys.stdout, ) [handler_fileHandler] class=FileHandler level=DEBUG formatter=logFormatter args=(‘test.log’, )
[formatters]
keys=logFormatter [formatter_logFormatter] class=logging.Formatter format=%(asctime)s:%(lineno)d:%(levelname)s:%(message)s
サンプルコード
import logging.config
# ログ設定ファイルからログ設定を読み込み
logging.config.fileConfig('logging.conf')
logger = logging.getLogger()
logger.log(20, 'info')
logger.log(30, 'warning')
logger.log(100, 'test')
logger.info('info')
logger.warning('warning')
実行結果
2019-08-06 16:33:57,169:8:INFO:info 2019-08-06 16:33:57,169:9:WARNING:warning 2019-08-06 16:33:57,169:10:Level 100:test 2019-08-06 16:33:57,169:12:INFO:info 2019-08-06 16:33:57,169:13:WARNING:warning
まずはlogging.confファイルの記述から見ていきましょう。設定ファイルにはこの項目が必要になります。
- [loggers] 「keys=」の後に任意のlogger名を記述。「root」は必須
- [handlers] 「keys=」の後に任意のhandler名を記述
- [formatters] 「keys=」の後に任意のformatter名を記述
複数設定する場合は「,」（カンマ）で区切りましょう。次にこれまで記述したそれぞれの名称に対して設定を記述していきます。
[logger_logger名] ロガーにハンドラーの追加
handlersの設定を行います。この例では[logger_root]として「handlers=」句の後にhandlerの名前を書いています。
[handler_handler名] ハンドラーの設定
class、level、formatter、argsなどの設定をします。この例の[handler_consoleHandler]ではコンソールへのログ出力について設定しています。
argsには、コンソール出力の場合は出力先に「sys.stdout」を入力します。argsには引数を複数設定する必要があり、引数が1つの場合であっても「,」で区切る必要があります。
この例の[handler_fileHandler]ではファイルへのログ表示について設定しています。クラスにはファイルへ出力するためのlogging.FileHandlerクラスのクラス名を入力しています。
argsにはファイル出力の場合は出力先のアドレス名「test.log」を入力しています。
[formatter_formatter名] フォーマッターの設定
class、format、datefmtなどの設定を行います。この例では[formatter_logFormatter]として「format=」句の後に出力形式のフォーマットを入力しています。
ログ設定ファイルの読み込みにはlogging.configモジュールのfileConfigメソッドを使用します。fileConfigメソッドの引数にログ設定ファイルのアドレスを入力しています。
logging.getLoggerメソッドを使用してloggerオブジェクトを生成し、あとはこれまでのサンプルコードと同様にログ出力のメソッドを記述しています。
まとめ
この記ことでは、以下のような点について解説致しました。
- ログ・ロギングについて
- loggingモジュールの使い方について
- ログのファイル出力について
- configファイルでフォーマットを指定する方法について
Pythonのロギング機能を使うことで、いつどんな処理が実行されどのような結果になったかをさかのぼって確認することができます。トラブルが発生した時にどんなエラーがどの箇所で発生したか把握できるので、後々の対応がしやすくなり便利です。
この記事を参考にして、ぜひ便利なロギング機能を使いこなしてくださいね！
