Python の Loggingを実装してみた

はじめに

Loggingを実装する機会があったので、やったことをまとめておきます。

print文で簡易的に、デバッグ的に処理の確認をしてましたが、今回の実装でこういったことを網羅した上でイケてる感じにできたかな…と思います。

わざわざ アドベントカレンダー に載せるほどの記事ではないと思いますが…

今回の実装手法

print文で実際に運用をしているプロジェクトもあると思うし、Loggingの方法も多岐にわたると思います。
今回は、こちらの Qiita記事 を参考にさせていただき、イケてる getLogger で実装させてもらいました。
大変参考になりました。（ amedamaさん 、ありがとうございました）

実装

Logging 用アクセサー

log_accessor.py

from logging import getLogger, StreamHandler, FileHandler, basicConfig, Formatter, handlers
import datetime

■ クラス定義

log_accessor.py

class App_log:
    """
    このクラスのインスタンスを作成すると、
    名前付きのlogging.Loggerインスタンスが作成され、
    指定したファイルにログを出力できる。
    """
    logger = None

    def __init__(self, module_name, script_name, output_dir, logLevel='DEBUG' isTest=False):
        """
        module_name:str型 （実行モジュール名を指定）
        script_name:str型 （実行スクリプト名を指定）
        output_dir:str型 （Log出力ディレクトリ）
        logLevel:str型 （Logレベルを指定）（Default:'DEBUG'）
        is_Test:bool型 （ターミナル等にLog出力する場合は'True'）（Default:false）
        """
        log_dir = f'{output_dir}/logs'

        self.logger = _get_module_logger(module_name, script_name, log_dir, logLevel, isTest)

    def debug_log(self, msg):
        """
        スクリプト内の変数の値などを出力する
        """
        self.logger.debug(msg)

    def info_log(self, msg):
        """
        実行スクリプトの開始や終了を出力する
        """
        self.logger.info(msg)

    def warning_log(self, msg):
        """
        エラーではないが期待した処理結果でない可能性があるときに出力する
        """
        self.logger.warning(msg)

    def error_log(self, msg):
        """
        エラーが発生したときに出力する
        """
        self.logger.error(msg)

■ 関数

• error_handler : 年月単位でログファイル出力
• info_handler : 「１MB」単位でログファイル出力（5サイクル）
• process_handler : 年月単位でログファイル出力
• 出力フォーマット : %(asctime)s - %(name)s - %(levelname)s - %(message)s

log_accessor.py

def _get_module_logger(module_name, script_name, log_dir, logLevel, isTest):
    """
    ret:logging.Logger
    handlerの種類は3つ
    error_handler:warning以上のレベルのログを全プログラム共通のファイルに出力する
    info_handler:parameterで指定されたレベルのログをモジュール単位のファイルに出力する
    process_handler:info以上のレベルのログを全プログラム共通のファイルに出力する
    StreamHandler:info_handlerの内容を標準出力する（isTest=True）
    """
    day = datetime.date.today().strftime('%Y%m')

    # Get Logger
    logger = getLogger(f'{module_name}.{script_name}')
    logger.setLevel('DEBUG')

    # Create Handler -(error_handler)
    error_handler = FileHandler(filename=f'{log_dir}/all_app_error_{day}.log', encoding='utf-8')
    # Set LogLevel -(error_handler)
    error_handler.setLevel('WARNING')
    # Create Formatter -(error_handler)
    fmt = Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    # Set Formatter -(error_handler)
    error_handler.setFormatter(fmt)

    # Create Handler -(info_handler)
    # info_handler = FileHandler(filename=f'{log_dir}/{module_name}_{day}.log')
    info_handler = handlers.RotatingFileHandler(
        filename=f'{log_dir}/{module_name}.log',
        maxBytes=1048576,  # 1MB
        backupCount=5,
        encoding='utf-8'
    )
    # Set LogLevel -(info_handler)
    info_handler.setLevel(logLevel)
    # Set Formatter -(info_handler)
    info_handler.setFormatter(fmt)

    # Create Handler -(process_handler)
    process_handler = FileHandler(filename=f'{log_dir}/all_app_process_{day}.log', encoding='utf-8')
    # Set LogLevel -(process_handler)
    process_handler.setLevel('INFO')
    # Create Formatter -(process_handler)
    fmt = Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    # Set Formatter -(process_handler)
    process_handler.setFormatter(fmt)

    # Logger - Set Handler
    logger.addHandler(error_handler)
    logger.addHandler(info_handler)
    logger.addHandler(process_handler)

    # Create Handler -(StreamHandler - basicConfig)
    # Logger - Set Handler -(StreamHandler - basicConfig)
    if isTest:
        stream_handler = StreamHandler()
        stream_handler.setFormatter(fmt)
        logger.addHandler(stream_handler)

    return logger

作成したアクセサーを使用する

■ インポート

xxxxx.py

# import logging
from util.log_accessor import App_log

■ インスタンス生成

xxxxx.py

    # Set Logging
    module_name = os.path.split(package_dir)[-1]
    script_name = os.path.splitext(os.path.basename(__file__))[0]
    app_log_ut = App_log(module_name=module_name,
                         script_name=script_name,
                         output_dir=project_dir, logLevel='DEBUG', isTest=True)

■ Logging 組込み

xxxxx.py

        self.logging.info_log(f'Start xxxxx')

        ~~~~~~~~

        self.logging.info_log(f'End xxxxx')

Log出力例

■ info_handler

TEST.log

2020-12-17 12:54:02,361 - TEST.xxxxx - INFO - Start xxxxx.edit
2020-12-17 12:54:02,400 - TEST.xxxxx - DEBUG -     Start method1
2020-12-17 12:54:02,405 - TEST.xxxxx - DEBUG -         df.shape (288, 19)
2020-12-17 12:54:02,405 - TEST.xxxxx - DEBUG -     END   method1
2020-12-17 12:54:02,406 - TEST.xxxxx - DEBUG -     Start method2
2020-12-17 12:54:02,409 - TEST.xxxxx - DEBUG -         min:1 max:120
2020-12-17 12:54:02,409 - TEST.xxxxx - DEBUG -         df2.shape (720, 8)
2020-12-17 12:54:02,409 - TEST.xxxxx - DEBUG -     End   method2
2020-12-17 12:54:02,409 - TEST.xxxxx - INFO - END   xxxxx.edit

■ process_handler

all_app_process_202012.log

2020-12-17 12:54:02,361 - TEST.xxxxx - INFO - Start xxxxx.edit
2020-12-17 12:54:02,409 - TEST.xxxxx - INFO - END   xxxxx.edit
2020-12-17 23:09:13,953 - TEST.yyyyy - INFO - Start yyyyy.edit
2020-12-17 23:27:38,536 - TEST.yyyyy - INFO - END   yyyyy.edit

さいごに

まだまだPython勉強中のため、いろいろとツッコミどころがあると思います。
ご指摘お願いします…