ソースに絡まるエスカルゴ

貧弱プログラマの外部記憶装置です。

【python】ロガーについて

 今までにpythonで色々とやってきましたが、ロガーをまともに実装したことがなかったので今回はロガーについての記事になります。

 あくまで自分で必要だと思った部分のみを記述しているだけなので、詳しくは参考資料に挙げているページ様を参照してください。


 では、始めます。


1:pythonのロガー
 pythonには標準ライブラリの「logging」があるので、これを使うのが楽だと思います。

 python公式のloggingの内容ほぼそのままですが、最低限のロガーを書くと以下のようになります。

・logger_test.py

# -*- coding: utf-8 -*-
import logging

logger = logging.getLogger(__name__)

def main():
  logging.basicConfig(filename='myapp.log', level=logging.INFO)
  logger.info('Started')
  logger.debug('debug output') # ログレベルがinfoなのでdebugのメッセージは表示されない
  logger.info('Finished')

if __name__ == '__main__':
  main()

 logging.getLogger関数でロガーのインスタンスを作成しています。引数にはログの名前を設定しますが、面倒な場合は今回のように「__name__」としてモジュール名を渡すのが楽かと思います。
 そしてこのロガーのインスタンスに対してファイル名やログレベルを設定し、ログの内容を出力しています。

 このソースを実行すると同階層に「myapp.log」というファイルが作成され、中を開くと以下のようになっていると思います。

INFO:__main__:Started
INFO:__main__:Finished

 debugのログが出ていないことが確認できますが、これは設定したログレベルによるものです。


2:loggingのログレベル
 ログレベルは「出力するログ」をコントロールするために設定します。

 例えば「開発中にはログとして出しておきたいが、正式リリース時には出さないようにしたい」という時などにはこのログレベルを適切に切り替えることで対応できます。

 python公式のloggingページから抜き出し簡単にした表になりますが、ログレベルは以下のようになっています。

ログレベル 数値 目的 用途
logging.NOTSET 0 - DEBUGよりも更に詳しく出したい時に使う
logging.DEBUG 10 開発時に必要なログを出力 開発時に値がちゃんと入っているかなどを確認したい時に使う
logging.INFO 20 想定通りの動作に必要なログを出力 クラスや関数名を出すことでその処理がちゃんと実行されているかなどの時に使う
logging.WARNING 30 ソフトウェア上で想定される異常などのログを出力 バリデーションエラーなど、想定されうる異常などの時に使う
logging.ERROR 40 ソフトウェアの機能が実行できない場合のログを出力 try exceptなどで処理するような明らかなエラーが出る時などに使う
logging.CRITICAL 50 ソフトウェアが実行できない重大エラーの場合のログを出力 -

 自分の経験ではDEBUG~ERRORをよく使い、NOTSETとCRITICALはほとんど使わない印象です。CRITICALはこのレベルのログを出す場合はそもそもソフトウェアがまともに動かない場合だと思うので、ロガーに出す余裕もないんじゃないかと個人的には思っています。NOTSETは全てのログレベルのものを出力したい時にloggerのインスタンスに設定する時に使う印象です。

 この表を頭に入れた上で1の結果をもう一度見てみると、「level=logging.INFO」でログレベルをINFOに設定しているため、INFOよりも値が低いDEBUGのログが出力されていないことがわかるかと思います。


3:loggingのサンプル
 loggingの方法がわかったので、ある程度使えるような形のロガーサンプルを動かしてみます。
 以下の2つのファイルを同階層に作成してください。

・common_logger.py

# -*- coding: utf-8 -*-
import os
import logging


class CommonLogger():
  """共通ロガークラス"""
  # ログ出力ディレクトリ(本ファイルがある場所からの相対パス)
  LOG_DIR    = "log/"
  # 出力ログファイル名
  LOG_FILE   = "common.log"
  # ログフォーマット
  LOG_FORMAT = "%(asctime)s %(levelname)-8s %(message)s"
  # ログ文字コード
  LOG_ENCODE = "utf-8"
  # ログ出力のレベル
  LOG_LEVEL = logging.DEBUG

  _instance     = None
  _log_dir_path = ""
  _log_path     = ""
  _logger       = None


  def __new__(cls):
    """インスタンス生成前に実行される関数"""
    # 以下の判定はシングルトンにするために行っている
    if cls._instance is None:
        print("create logger")
        # 初めてインスタンスが作成される時の処理
        cls._instance = super().__new__(cls)
        # ログディレクトリを作成
        cls._log_dir_path = os.path.join(os.path.dirname(os.path.abspath(__file__)), cls.LOG_DIR)
        os.makedirs(cls._log_dir_path, exist_ok=True)
        # ログファイルパス作成
        cls._log_dir_path = os.path.join(cls._log_dir_path, cls.LOG_FILE)
        # 各種ログの設定
        cls._setup_logger(cls)

    return cls._instance


  def _setup_logger(cls):
    """ログの設定を行う関数"""
    # ログの設定
    cls._logger = logging.getLogger(__name__)
    cls._logger.setLevel(cls.LOG_LEVEL)
    # 標準出力のログの設定
    st_handler = logging.StreamHandler()
    st_handler.setLevel(cls.LOG_LEVEL)
    st_handler.setFormatter(logging.Formatter(cls.LOG_FORMAT))
    # ログファイル出力の設定
    fl_handler = logging.FileHandler(filename=cls._log_dir_path, encoding=cls.LOG_ENCODE)
    fl_handler.setLevel(cls.LOG_LEVEL)
    fl_handler.setFormatter(logging.Formatter(cls.LOG_FORMAT))
    # ハンドラーを設定
    cls._logger.addHandler(st_handler)
    cls._logger.addHandler(fl_handler)


  def __init__(self):
    """コンストラクタ"""
    pass


  def debug(self, output_class, message):
    """DEBUGレベルのログを出力する関数"""
    output = "[" + output_class.__name__ + "] " + message
    self._logger.debug(output)


  def info(self, output_class, message):
    """INFOレベルのログを出力する関数"""
    output = "[" + output_class.__name__ + "] " + message
    self._logger.info(output)


  def warning(self, output_class, message):
    """WARNINGレベルのログを出力する関数"""
    output = "[" + output_class.__name__ + "] " + message
    self._logger.warning(output)


  def error(self, output_class, message):
    """ERRORレベルのログを出力する関数"""
    output = "[" + output_class.__name__ + "] " + message
    self._logger.error(output)


  def critical(self, output_class, message):
    """CRITICALレベルのログを出力する関数"""
    output = "[" + output_class.__name__ + "] " + message
    self._logger.critical(output)


・common_logger_test.py

# -*- coding: utf-8 -*-
from common_logger import CommonLogger

class LogClass:
  """ログを出力するクラス1"""
  def __init__(self):
    """コンストラクタ"""
    self.logger = CommonLogger()

  def output_log(self):
    self.logger.debug(self.__class__, "debugです")
    self.logger.info(self.__class__, "infoです")
    self.logger.warning(self.__class__, "warningです")
    self.logger.error(self.__class__, "errorです")
    self.logger.critical(self.__class__, "criticalです")


class Log2Class:
  """ログを出力するクラス2"""
  def __init__(self):
    """コンストラクタ"""
    self.logger = CommonLogger()

  def output_log(self):
    self.logger.debug(self.__class__, "debug2です")
    self.logger.info(self.__class__, "info2です")
    self.logger.warning(self.__class__, "warning2です")
    self.logger.error(self.__class__, "error2です")
    self.logger.critical(self.__class__, "critical2です")


if __name__ == '__main__':
  log1 = LogClass()  # ロガーを作成
  log2 = Log2Class() # ロガーを作成(シングルトンなのでLogClassと同じインスタンスを取得)

  # それぞれログ出力
  log1.output_log()
  log2.output_log()


 上記の2つのファイルを同階層に作成し「common_logger_test.py」を実行すると、logディレクトリが作成されその中に「common.log」ファイルが出力されています。そしてそのcommon.logの中身を見ると以下のようになっているはずです。

2024-03-21 15:53:31,180 DEBUG    [LogClass] debugです
2024-03-21 15:53:31,181 INFO     [LogClass] infoです
2024-03-21 15:53:31,181 WARNING  [LogClass] warningです
2024-03-21 15:53:31,181 ERROR    [LogClass] errorです
2024-03-21 15:53:31,181 CRITICAL [LogClass] criticalです
2024-03-21 15:53:31,181 DEBUG    [Log2Class] debug2です
2024-03-21 15:53:31,181 INFO     [Log2Class] info2です
2024-03-21 15:53:31,181 WARNING  [Log2Class] warning2です
2024-03-21 15:53:31,184 ERROR    [Log2Class] error2です
2024-03-21 15:53:31,184 CRITICAL [Log2Class] critical2です

 少し解説するとcommon_logger.pyが今回自分が作成したある程度汎用的なロガーのクラスです。それをcommon_logger_test.pyから呼び出して使っています。
 common_logger.pyのCommonLoggerクラスは一応シングルトンとなるようにしています。シングルトンは「一度インスタンスが作成されていれば、コンストラクタが何度呼ばれても同じそのインスタンスを返す」ものです。ロガーなので、毎回同じインスタンスを返すようにするのが適切だと思いシングルトンとなるようにしています。
 またログ出力のフォーマットも日時、ログレベル、クラス名、メッセージ内容の4つを出力させるようにしています。これぐらいの情報をログとして出していれば、何か問題が起こったときでも問題個所を特定しやすくなるかと思います。


 以上がpythonでのロガー実装方法になります。

 詳しい人からすると全然足りていないような作りのサンプルコードだとは思いますが、必要最低限だとこのような形になると思います。
 またログのHandlerとして「TimedRotatingFileHandler」を使用するとログローテーションなどもpython側で設定できるようなので、それを使うのも良いかと思います。

 ちなみにマルチプロセスやマルチスレッドを使っている場合はシングルトンでもログ出力がぶつかってしまう可能性も考えられるので、その場合はQueueなどを使ってそこに順次突っ込んでいく形が良いような気がします。

 このようにロガーと一言で言っても、用途や使い方、どの程度までログに出すかの取り決めなど、ちゃんとやろうとすると考えることが多くなりそうなので、詳しい方がいれば色々と教えていただきたいと思いました。


・参考資料