こんにちは、将来の夢が最近「ログハウスのサウナ小屋を建てたい」に変わった、とりゅふです。
logという単語は、「丸太」という意味なのですが、ITの世界では、情報の履歴、記録といった意味を持ちます。
blogもweb logの略です。
このlogの語源ですが、時は大航海時代、船乗り達が自分の船の速度を測るために、丸太を船首から海に流し、船尾まで流れる時間を「航海日誌（logbook）」を記録していたことが由来します。
閑話休題、本日のテーマはこちら。
よくPythonのコード書いてデバッグ実行するのに、いろんなところにprint()を書いて確認してしまいがちですが、Pythonを始め、各種プログラミング言語にはログ出力用のモジュールがちゃんと備わっています。
今日はこのロギングについて、改めて真剣に向き合って行こうと思います。
※本記事はPython3.7.11で検証しています。
loggingの基本
ログを出力する
Pythonのログは、loggingモジュールで出力することができます。
import logging logging.basicConfig(level=logging.DEBUG) logging.debug('デバッグ') logging.info('インフォ') logging.warning('ワーニング') logging.error('エラー') logging.critical('クリティカル')
DEBUG:root:デバッグ INFO:root:インフォ WARNING:root:ワーニング ERROR:root:エラー CRITICAL:root:クリティカル
ログレベル
Pythonはprint()で情報をコンソール出力することができますが、このloggingを用いることで、ログレベルを設定し、わかりやすい情報を残すことができます。ログレベルとは、ログの重要度を示すものです。以下公式ドキュメントからの引用です。
| レベル | いつ使うか |
|---|---|
| DEBUG | おもに問題を診断するときにのみ関心があるような、詳細な情報。 |
| INFO | 想定された通りのことが起こったことの確認。 |
| WARNING | 想定外のことが起こった、または問題が近く起こりそうである (例えば、'disk space low') ことの表示。 |
| ERROR | より重大な問題により、ソフトウェアがある機能を実行できないこと。 |
| CRITICAL | プログラム自体が実行を続けられないことを表す、重大なエラー。 |
https://docs.python.org/ja/3/howto/logging.html より引用
ログレベルは、デフォルトではWARNINGのみを表示するようになっています。DEBUGやINFOはそのままではコンソール出力されません。
そのため、先程のプログラムの3行目のlogging.basicConfig(level=logging.DEBUG)の箇所で、DEBUG以上のログレベルを出力するように設定しています。
ログのフォーマット
次にログのフォーマットを変更してみます。
フォーマットは、`logging.basicConfig(format='ここにフォーマットを指定')で設定できます。
日付やログレベルなどのパラメータも設定可能です。パラメータの詳細は下記で確認できます。
logging --- Python 用ロギング機能 — Python 3.10.0b2 ドキュメント
import logging logging.basicConfig( level=logging.DEBUG, format='%(asctime)s [%(levelname)s] %(filename)s, lines %(lineno)d. %(message)s') logging.debug('デバッグ') logging.info('インフォ') logging.warning('ワーニング') logging.error('エラー') logging.critical('クリティカル')
2021-11-15 21:16:20,591 [DEBUG] main.py, lines 7. デバッグ 2021-11-15 21:16:20,591 [INFO] main.py, lines 8. インフォ 2021-11-15 21:16:20,591 [WARNING] main.py, lines 9. ワーニング 2021-11-15 21:16:20,591 [ERROR] main.py, lines 10. エラー 2021-11-15 21:16:20,592 [CRITICAL] main.py, lines 11. クリティカル
ログのファイル出力
デフォルトではログはコンソールに出力されますが、もちろんファイル出力もできます。
、`logging.basicConfig(filename='ここにファイルパスを指定')で設定することで、コンソールには出力されず、ファイルに出力されるようになります。
import logging logging.basicConfig( level=logging.DEBUG, format='%(asctime)s [%(levelname)s] %(filename)s, lines %(lineno)d. %(message)s', filename='logs/test.log') logging.debug('デバッグ') logging.info('インフォ') logging.warning('ワーニング') logging.error('エラー') logging.critical('クリティカル')
Loggerを使う
loggingとLoggerの違い
これまでloggingモジュールの設定をいじってきましたが、
共通モジュールを直接いじらず、logging.Loggerクラスのインスタンスを生成し、利用しましょう。
Loggerクラスの基本
以下サンプルコードです。
Loggerクラスも、loggingと同様にログレベル、フォーマット、出力先などを制御できます。
import logging # ロガーインスタンス生成 logger = logging.getLogger(__name__) # ロガーにログレベル設定（ここをDEBUGに設定しないと、その後ハンドラでDEBUG設定しても出力されない） logger.setLevel(logging.DEBUG) # ログフォーマット設定 format = '%(asctime)s [%(levelname)s] %(filename)s, lines %(lineno)d. %(message)s' date_format = '%Y-%m-%d %H:%M:%S' formatter = logging.Formatter(format, date_format) # コンソール出力ハンドラを設定、DEBUG以上のレベルを出力 stream_handler = logging.StreamHandler() stream_handler.setLevel(logging.DEBUG) stream_handler.setFormatter(formatter) logger.addHandler(stream_handler) # ファイル出力ハンドラを設定、INFO以上のレベルを出力 file_handler = logging.FileHandler('logs/test2.log') file_handler.setLevel(logging.INFO) file_handler.setFormatter(formatter) logger.addHandler(file_handler) # ログ出力 logger.debug('デバッグ') logger.info('インフォ') logger.warning('ワーニング') logger.error('エラー') logger.critical('クリティカル')
2021-11-15 21:30:40 [DEBUG] main2.py, lines 25. デバッグ 2021-11-15 21:30:40 [INFO] main2.py, lines 26. インフォ 2021-11-15 21:30:40 [WARNING] main2.py, lines 27. ワーニング 2021-11-15 21:30:40 [ERROR] main2.py, lines 28. エラー 2021-11-15 21:30:40 [CRITICAL] main2.py, lines 29. クリティカル
2021-11-15 21:30:40 [INFO] main2.py, lines 26. インフォ 2021-11-15 21:30:40 [WARNING] main2.py, lines 27. ワーニング 2021-11-15 21:30:40 [ERROR] main2.py, lines 28. エラー 2021-11-15 21:30:40 [CRITICAL] main2.py, lines 29. クリティカル
例外処理でログ出力する
これまではテキストのみをログ出力してきましたが、例外発生時にエラーの詳細、スタックトレースを出力したい場合はどうなるでしょう？
例外を出力するには、logger.exception(e)を用います。以下サンプルコードです。
import logging # ロガーインスタンス生成 logger = logging.getLogger(__name__) # ロガーにログレベル設定 logger.setLevel(logging.DEBUG) # ログフォーマット設定 format = '%(asctime)s [%(levelname)s] %(filename)s, lines %(lineno)d. %(message)s' date_format = '%Y-%m-%d %H:%M:%S' formatter = logging.Formatter(format, date_format) # ファイル出力ハンドラを設定、INFO以上のレベルを出力 file_handler = logging.FileHandler('logs/test3.log') file_handler.setLevel(logging.INFO) file_handler.setFormatter(formatter) logger.addHandler(file_handler) # ログ出力 try: logger.info('ゼロ乗算をします') n = 1 / 0 except Exception as e: logger.critical('致命的なエラーが発生しました') logger.exception(e)
2021-11-15 21:38:26 [INFO] main3.py, lines 23. ゼロ乗算をします
2021-11-15 21:38:26 [CRITICAL] main3.py, lines 26. 致命的なエラーが発生しました
2021-11-15 21:38:26 [ERROR] main3.py, lines 27. division by zero
Traceback (most recent call last):
File "main3.py", line 24, in <module>
n = 1 / 0
ZeroDivisionError: division by zero
複数のモジュールでloggerを共有する
最後に複数モジュールで1つのloggerを共有してみます。
log.pyでLoggerインスタンスを生成し、main.pyと、sub.pyでログ出力します。
├── log.py ├── logs │ └── common.log ├── main.py └── sub.py
- log.py
import logging # ロガーインスタンス生成 logger = logging.getLogger(__name__) # ロガーにログレベル設定 logger.setLevel(logging.DEBUG) # ログフォーマット設定 format = '%(asctime)s [%(levelname)s] %(filename)s, lines %(lineno)d. %(message)s' date_format = '%Y-%m-%d %H:%M:%S' formatter = logging.Formatter(format, date_format) # ファイル出力ハンドラを設定、INFO以上のレベルを出力 file_handler = logging.FileHandler('logs/common.log') file_handler.setLevel(logging.INFO) file_handler.setFormatter(formatter) logger.addHandler(file_handler)
- main.py
from log import logger import sub try: logger.info('mainを実行します') sub.execute() except Exception as e: logger.critical('mainで致命的なエラーが発生しました') logger.exception(e) logger.info('mainを終了します')
- sub.py
from log import logger def execute(): logger.info('subを実行します') raise Exception('sub内で例外が発生しました。')
2021-11-15 21:41:13 [INFO] main.py, lines 5. mainを実行します
2021-11-15 21:41:13 [INFO] sub.py, lines 5. subを実行します
2021-11-15 21:41:13 [CRITICAL] main.py, lines 8. mainで致命的なエラーが発生しました
2021-11-15 21:41:13 [ERROR] main.py, lines 9. sub内で例外が発生しました。
Traceback (most recent call last):
File "main.py", line 6, in <module>
sub.execute()
File "sub.py", line 6, in execute
raise Exception('sub内で例外が発生しました。')
Exception: sub内で例外が発生しました。
2021-11-15 21:41:13 [INFO] main.py, lines 10. mainを終了します
まとめ
本日はPythonのloggingとLoggerについてまとめました。
プログラムを効率良く書いたり、実際の業務でシステムを滞りなく運用するためには、ログ出力を理解することが書かせません。
ログ出力を理解し、より品質の高いプログラムを書けるようにしましょう。
