ログの出力
なぜログを出力するのか
ログは、起動しているプログラムを監視し、どこまで処理が終わっているのか、どこでエラーが発生したのか、異常なデータが含まれていないか、不正な操作が行われていないかなどを確認し、いち早く不具合を修正できるようにするために出力される。
Pythonでは標準ライブラリのloggingを使うと簡単にログを出力できる。
loggingの基本的な使い方
loggingではメッセージの重要度よってログレベルというものが設定されていて、この重要度に応じてログとして出力するかどうかの出し分けが簡単にできるようになっている。
| ログレベル | 重要度 | 説明 |
| DEBUG | 10 | 開発中に確認する情報 |
| INFO | 20 | 通常処理で後から確認する可能性の高い情報 |
| WARNING | 30 | エラーではないが問題に発展する可能性のあることが起こったことを知らせる情報 |
| ERROR | 40 | 不具合が起こったことを知らせる情報 |
| CRITICAL | 50 | 致命的な状態でサービスの提供が維持できないことが起こったことを知らせる情報 |
loggingを用いてログ出力する基本的なコードは次のように記述できる。
from logging import getLogger, StreamHandler, INFO, Formatter
# ロガーを生成する（ファイル名を渡してファイルごとにロガーを生成）
logger = getLogger(__name__)
# 出力されるログレベル設定する（重要度がINFO以上のメッセージがログに出力されるように設定）
logger.setLevel(INFO)
# ハンドラーを生成する（コンソール上に出力するように設定）
handler = StreamHandler()
# ログの出力フォーマットを指定する
formatter = Formatter(
"%(asctime)s - %(levelname)s : %(name)s : %(message)s (%(filename)s:%(lineno)d) : "
)
# ハンドラーにフォーマットを渡す
handler.setFormatter(formatter)
# ロガーにハンドラーを追加する
logger.addHandler(handler)
# ログメッセージを出力する
logger.debug("DEBUGメッセージです。")
logger.info("INFOメッセージです。")
logger.warning("WARNINGメッセージです。")
logger.error("Errorメッセージです。")
logger.critical("CRITICALメッセージです。")
# 2024-10-23 17:17:32,425 - INFO : __main__ : INFOメッセージです。 (main.py:24) :
# 2024-10-23 17:17:32,426 - WARNING : __main__ : WARNINGメッセージです。 (main.py:25) :
# 2024-10-23 17:17:32,426 - ERROR : __main__ : Errorメッセージです。 (main.py:26) :
# 2024-10-23 17:17:32,427 - CRITICAL : __main__ : CRITICALメッセージです。 (main.py:27) :上記のコードを実行すると、コンソール上に重要度がINFO以上のメッセージが出力される。重要度がINFOより低いDEBAGのメッセージは出力されない。
なお、一つのロガーに複数のハンドラーを設定することもできる。複数のハンドラーを設定したコードは次のようになる。
from logging import getLogger, StreamHandler, FileHandler, INFO, ERROR, Formatter
# ロガーを生成する
logger = getLogger(__name__)
# 出力されるログレベル設定する
logger.setLevel(INFO)
# ログの出力フォーマットを指定する
formatter = Formatter(
"%(asctime)s - %(levelname)s : %(name)s : %(message)s (%(filename)s:%(lineno)d) : "
)
# 標準出力ハンドラを追加する
stream_handler = StreamHandler()
stream_handler.setLevel(ERROR)
stream_handler.setFormatter(formatter)
logger.addHandler(stream_handler)
# ファイルハンドラを追加する
file_handler = FileHandler("./app.log", encoding="utf-8")
file_handler.setLevel(INFO)
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)
# ログメッセージを出力する
logger.debug("DEBUGメッセージです。")
logger.info("INFOメッセージです。")
logger.warning("WARNINGメッセージです。")
logger.error("Errorメッセージです。")
logger.critical("CRITICALメッセージです。")
# 2024-10-23 17:55:02,792 - ERROR : __main__ : Errorメッセージです。 (main.py:31) :
# 2024-10-23 17:55:02,793 - CRITICAL : __main__ : CRITICALメッセージです。 (main.py:32) :上記のコードを実行すると、コンソール上とapp.logファイル内の２個所にログが出力される。handler.setLevel()を使ってハンドラーごとに出力されるログレベルを設定しているため、コンソール上にはError以上のメッセージが出力され、ファイル内にはINFO以上のメッセージを出力される。
# app.log
2024-10-23 17:59:03,048 - INFO : __main__ : INFOメッセージです。 (main.py:29) :
2024-10-23 17:59:03,048 - WARNING : __main__ : WARNINGメッセージです。 (main.py:30) :
2024-10-23 17:59:03,048 - ERROR : __main__ : Errorメッセージです。 (main.py:31) :
2024-10-23 17:59:03,048 - CRITICAL : __main__ : CRITICALメッセージです。 (main.py:32) : 上記の例では、欲しい情報が出力されるようにフォーマッターを次のように指定している。
formatter = Formatter(
"%(asctime)s - %(levelname)s : %(name)s : %(message)s (%(filename)s:%(lineno)d) : "
)フォーマット文字列の代表的なものを以下の表にまとめておく（詳細は公式Docを参照）。
| フォーマット | 説明 |
| %(asctime)s | ログが生成された時刻 |
| %(levelname)s | ログレベル |
| %(filename)s | ファイル名 |
| %(module)s | モジュール名（filenameの名前部分） |
| %(lineno)d | ログを出力した行番号 |
| %(funcName)s | ログを出力した関数の名前 |
| %(message)s | ログメッセージ |
| %(name)s | ロガー名 |
複数ファイルのログ
ロガーを作成する時にgetLoggerに__name__を渡すと、モジュール（ファイル）ごとにそのモジュールに対応したロガーが作成される。こうすることで、パッケージの階層構造とロガーの階層構造を一致させることができる。次に示すコードでは、main.pyとtest.pyの中でそれぞれgetLoggerに__name__を渡して、モジュールごとにロガーを生成し、それぞれを異なるログとして処理している。
# main.py
from logging import getLogger, FileHandler, INFO, Formatter
import test
# ロガーの設定
logger = getLogger(__name__)
logger.setLevel(INFO)
handler = FileHandler(f"./{__name__}.log", encoding="utf-8")
formatter = Formatter(
"%(asctime)s - %(name)s : %(levelname)s : %(message)s (%(filename)s:%(lineno)d) : "
)
handler.setFormatter(formatter)
logger.addHandler(handler)
def output_log():
"""ログを出力する関数"""
logger.debug("DEBUGメッセージです。")
logger.info("INFOメッセージです。")
logger.warning("WARNINGメッセージです。")
logger.error("Errorメッセージです。")
logger.critical("CRITICALメッセージです。")
output_log()
test.output_log()
# test.py
from logging import getLogger, FileHandler, ERROR, Formatter
# ロガーの設定
logger = getLogger(__name__)
logger.setLevel(ERROR)
handler = FileHandler(f"./{__name__}.log", encoding="utf-8")
formatter = Formatter(
"%(asctime)s - %(name)s : %(levelname)s : %(message)s (%(filename)s:%(lineno)d) : "
)
handler.setFormatter(formatter)
logger.addHandler(handler)
def output_log():
"""ログを出力する関数"""
logger.debug("DEBUGメッセージです。")
logger.info("INFOメッセージです。")
logger.warning("WARNINGメッセージです。")
logger.error("Errorメッセージです。")
logger.critical("CRITICALメッセージです。")
上記のコードを実行すると、__main__.logとtest.logという異なるファイルにログが出力される。
# __main__.log
2024-10-24 16:10:52,164 - __main__ : INFO : INFOメッセージです。 (main.py:19) :
2024-10-24 16:10:52,164 - __main__ : WARNING : WARNINGメッセージです。 (main.py:20) :
2024-10-24 16:10:52,164 - __main__ : ERROR : Errorメッセージです。 (main.py:21) :
2024-10-24 16:10:52,165 - __main__ : CRITICAL : CRITICALメッセージです。 (main.py:22) : # test.log
2024-10-24 16:10:52,165 - test : ERROR : Errorメッセージです。 (test.py:20) :
2024-10-24 16:10:52,165 - test : CRITICAL : CRITICALメッセージです。 (test.py:21) : なお、別ファイルでもgetLoggerに同名の変数を渡すと同一のロガーを使用することになる。
設定ファイルからログの設定を読み込む
fileconfigを利用して読み込む
まず、以下のような設定ファイルを用意する。
#logging.conf
[loggers]
keys=root, sample
[handlers]
keys=console,file,null
[formatters]
keys=formatter
[logger_root]
level=DEBUG
handlers=null
[logger_sample]
level=DEBUG
handlers=console,file
qualname=sample
[handler_console]
class=StreamHandler
level=INFO
formatter=formatter
[handler_file]
class=FileHandler
level=DEBUG
formatter=formatter
args=('app.log','a','utf-8')
[handler_null]
class=NullHandler
[formatter_formatter]
format=%(asctime)s - %(name)s - %(levelname)s:%(message)sサンプルプログラム内にログの設定を読み込むコードを記載して、動作を確認する。
# main.py
import logging.config
# ログ設定の読み込み
logging.config.fileConfig("logging.conf")
logger = logging.getLogger("sample")
# ログメッセージを出力する
logger.debug("DEBUGメッセージです。")
logger.info("INFOメッセージです。")
logger.warning("WARNINGメッセージです。")
logger.error("Errorメッセージです。")
logger.critical("CRITICALメッセージです。")
# 2024-10-24 13:53:23,125 - sample - INFO:INFOメッセージです。
# 2024-10-24 13:53:23,126 - sample - WARNING:WARNINGメッセージです。
# 2024-10-24 13:53:23,126 - sample - ERROR:Errorメッセージです。
# 2024-10-24 13:53:23,127 - sample - CRITICAL:CRITICALメッセージです。yamlファイルから読み込む
Pythonでyamlファイルを読み込むためにpyyamlをインストールしておく。
> pip install pyyamlその後、yaml形式で記述した設定ファイルを用意する。
# logging.yaml
version: 1
formatters:
simple:
format: '%(asctime)s - %(name)s - %(levelname)s:%(message)s'
handlers:
console:
class: logging.StreamHandler
level: INFO
formatter: simple
file:
class: logging.FileHandler
level: DEBUG
formatter: simple
filename: app.log
encoding: utf-8
loggers:
sample:
level: DEBUG
handlers: [console, file]サンプルプログラム内にログの設定を読み込むコードを記載して、動作を確認する。
# main.py
import logging.config
import yaml
# ログ設定の読み込み
logging.config.dictConfig(
yaml.load(
open("logging.yaml").read(),
Loader=yaml.SafeLoader,
)
)
logger = logging.getLogger("sample")
# ログメッセージを出力する
logger.debug("DEBUGメッセージです。")
logger.info("INFOメッセージです。")
logger.warning("WARNINGメッセージです。")
logger.error("Errorメッセージです。")
logger.critical("CRITICALメッセージです。")
# 2024-10-24 13:00:29,341 - sample - INFO:INFOメッセージです。
# 2024-10-24 13:00:29,341 - sample - WARNING:WARNINGメッセージです。
# 2024-10-24 13:00:29,343 - sample - ERROR:Errorメッセージです。
# 2024-10-24 13:00:29,343 - sample - CRITICAL:CRITICALメッセージです。