Python で仕事 実務で使う ログ準備編

プログラミング

実務で使うプログラムを作成する際は、常にログのことも考えておく必要があります。
ただし、ログ設計というのは簡単なようで実に奥が深い……。

準備

どの様に設計するかは実際の実際にプログラムを作成する際に考えることにして、今回はログ出力の準備だけしておきましょう。

想定している構成は以下のようになります。

.
└── Python_de_work                              <== 実務で使う様にフォルダを作成
    ├── decologging.py                          <== ログ出力用の自作モジュール
    ├── logging.conf                            <== ログ用の設定
    ├── logs                                    <== ログ出力先フォルダ
    │   ├── sampleworks_2021-08-01.log              ログは日付ごとに分けて出力する
    │   ├── sampleworks_2021-08-02.log
    │   ├──            :
    │   └── sampleworks_2021-08-05.log
    └── work_20210805.py                        <== 実務用の Python プログラム ※対象外

今回も VS Code を使用します。VS Code 上のアイコンを使用して以下のフォルダ・ファイルを作成します。

実務用の Python プログラムでログ出力するための準備をしている様子

次にネットの情報を参考にしてログ出力用の設定や、モジュールを作成します。

logging.conf

設定ファイルです。こちらは Python の本家サイトの情報をもとに加筆・修正しています。
上級ロギングチュートリアル | Logging HOWTO – Python 3.9.4 ドキュメント

[loggers]
keys=root,sampleWork

[handlers]
keys=consoleHandler,fileHandler

[formatters]
keys=sampleWorkFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_sampleWork]
level=DEBUG
handlers=consoleHandler,fileHandler
qualname=sampleWork
propagate=0

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=sampleWorkFormatter
args=(sys.stdout,)

[handler_fileHandler]
class=FileHandler
level=DEBUG
formatter=sampleWorkFormatter
args=(__import__("datetime").datetime.now().strftime('Python_de_work/logs/sampleworks_%%Y-%%m-%%d.log'), 'a+')

[formatter_sampleWorkFormatter]
; For the other attributes, you can see the following page.
; (ref) https://docs.python.org/ja/3/library/logging.html#logrecord-attributes
;
; If you use "decologging" module, you can also use the following attributes, too.
; - real_filename: e.g., /workspace/Python_de_work/work_20210805.py
; - real_funcname: e.g., main
; - real_lineno:   e.g., 30
format=[%(asctime)s] - %(name)s - %(levelname)-8s - %(message)s
datefmt=

decologging.py

デコレータ(※)を使用してログ出力するためのモジュールを作成します。以下の記事を参考にさせていただきました。
【Python】Decorator(デコレーター)を使ってロギング機能を共通化してみた

"""ロギング用のデコレータを提供するモジュール
参照:https://qiita.com/homines22/items/dccae65fa3434641b995
参照:https://docs.python.org/ja/3/howto/logging.html#advanced-logging-tutorial
"""

import inspect
import logging
import logging.config
from functools import wraps


class CustomFilter(logging.Filter):
    """logger用のユーザー定義フィルター"""

    def filter(self, record):
        """呼び出し元のファイル名、関数名、行番号が表示されるようにする関数
        これでフィルタリングしないとデコレーターを使用した関数(呼び出し元)に関する情報ではなく、
        test1.pyの後述のlog関数を元にした情報が出力される

        Returns:
            True: 常にフィルターをパスする
        """

        record.real_filename = getattr(record,
                                       'real_filename',
                                       record.filename)
        record.real_funcname = getattr(record,
                                       'real_funcname',
                                       record.funcName)
        record.real_lineno = getattr(record,
                                     'real_lineno',
                                     record.lineno)
        return True


def get_logger(name='sampleWork'):
    """logging.Loggerの作成

    Returns:
        logger (logging.Logger): logging.Loggerのインスタンス
    """

    # configure logger via the config file.
    logging.config.fileConfig('Python_de_work/logging.conf')

    # create logger
    logger = logging.getLogger(name)
    logger.addFilter(CustomFilter())

    return logger



def log(logger):
    """デコレーターでloggerを引数にとるためのラッパー関数

    Args:
        logger (logging.Logger)

    Returns:
        _decoratorの返り値
    """

    def _decorator(func):
        """デコレーターを使用する関数を引数とする

        Args:
            func (function)

        Returns:
            wrapperの返り値
        """

        # funcのメタデータを引き継ぐ
        @wraps(func)
        def wrapper(*args, **kwargs):
            """実際の処理を書くための関数

            Args:
                *args, **kwargs: funcの引数

            Returns:
                funcの返り値
            """

            func_name = func.__name__
            # loggerで使用するためにfuncに関する情報をdict化
            extra = {
                'real_filename': inspect.getfile(func),
                'real_funcname': func_name,
                'real_lineno': inspect.currentframe().f_back.f_lineno
            }

            logger.info(f'[START] {extra["real_filename"]}::{func_name}', extra=extra)

            try:
                # funcの実行
                result = func(*args, **kwargs)
            except Exception as err:
                # funcのエラーハンドリング
                logger.error(err, exc_info=True, extra=extra)
                logger.error(f'[KILLED] {extra["real_filename"]}::{func_name}', extra=extra)
            else:
                logger.info(f'[END] {extra["real_filename"]}::{func_name}', extra=extra)

            return result

        return wrapper
    return _decorator

以上で、準備完了です。

試しに使ってみる

「logtest.py」を作成して以下のプログラムを実行してみましょう。

import decologging      # デコレータを使用したロギング用のローカルライブラリ

logger = decologging.get_logger()       # ログ出力のための準備

@decologging.log(logger)                # この様に記載することで、関数の前後でログが自動で出力される
def main():
    """ログ出力の確認
    """
    logger.debug('ログ出力のテストです')    # 開発用に出力する際に使用するレベル
    logger.info('ログ出力のテストです')     # 運用用に出力する際に使用するレベル
    logger.warning('ログ出力のテストです')  # 警告用 主に復帰可能なもの
    logger.error('ログ出力のテストです')    # エラー用 復帰不可能なもの
    logger.critical('ログ出力のテストです') # 致命的なエラー ものすごくヤバイ場合

if __name__ == '__main__':
    main()
ログが出力され、ログファイルも作成された様子

確認完了です!

コメント

タイトルとURLをコピーしました