[python]エラーレベルに合わせてlogging する方法

初めに

ログ出力の基本は、内容に応じてdebug,info,warning,errorといったログレベルを変えたり、環境に応じて出力対象レベルを調整することです。
今回は、各レベルごとにメソッドを定義して、ログレベルに応じたログ出力を行いたいと思います。

エラーハンドリングについてはこちらで説明しています。

コード全体像

今回のログでは、
共通モジュールとしてLoggerクラスを定義

class Logger():
    def __init__(self, resource_name) -> None:
            self.__resource_name = resource_name
            self.__member_id = ""

    def __get_logger(
            self,
            file_name: str,
            line_no: int,
            message: str = "",
            trace_shown: bool = True,
    ) -> logging.LoggerAdapter:
        logger = getLogger(shortuuid.uuid())  
        logger.propagate = False  
        logger.setLevel(
            DEBUG if os.environ["ENV"] == "dev" else INFO
        )

        handler = logging.StreamHandler()
        handler.setLevel(
            DEBUG if os.environ["ENV"] == "dev" else INFO
        )

        log_format = "%(asctime)s { loglevel: %(levelname)s, " \
            "app: %(app_name)s, datetime: %(asctime)s, " \
            "resource: %(resource_name)s, file: %(file_name)s, " \
            "line: %(line_no)s, member_id: %(member_id)s, trace: %(trace)s, " \
            "message_content: %(message)s, }"

        formatter = Formatter(log_format, "%Y-%m-%d %H:%M:%S")
        formatter.converter = lambda *args: datetime.now(
            timezone('Asia/Tokyo')
        ).timetuple()
        handler.setFormatter(formatter)
        logger.addHandler(handler)

        trace = (
            traceback.format_exc().strip().split("\n")
            if trace_shown else ""
        )

        return logging.LoggerAdapter(logger, {
            "app_name": self.APP_NAME,
            "resource_name": self.__resource_name,
            "file_name": file_name,
            "line_no": line_no,
            "trace": trace,
            "message": message,
        })

def debug(self, message: str) -> None:
        file_name = inspect.currentframe().f_back.f_code.co_filename
        line_no = inspect.currentframe().f_back.f_lineno

        logger = self.__get_logger(
            file_name=file_name,
            line_no=line_no,
            trace_shown=False,
            message=message
        )
        logger.debug()

    def info(self, message: str, *args: str) -> None:
        file_name = inspect.currentframe().f_back.f_code.co_filename
        line_no = inspect.currentframe().f_back.f_lineno

        logger = self.__get_logger(
            file_name=file_name,
            line_no=line_no,
            message=message,
            trace_shown=False
        )
        logger.info()

    def warning(self, message: str, *args: str) -> None:
        exc_info = sys.exc_info()
        file_name = exc_info[2].tb_frame.f_code.co_filename
        line_no = exc_info[2].tb_lineno

        logger = self.__get_logger(
            file_name=file_name,
            line_no=line_no,
            message=message,
        )
        logger.warning()

    def error(self, message: str, *args: str) -> None:
        exc_info = sys.exc_info()
        file_name = exc_info[2].tb_frame.f_code.co_filename
        line_no = exc_info[2].tb_lineno

        logger = self.__get_logger(
            file_name=file_name,
            line_no=line_no,
            message=message,
        )
        logger.error()

コード説明

__get_loggerメソッド

この関数では、主に以下の内容を設定しています。

• ハンドラーが処理するログメッセージの最低レベル
• 記録するログメッセージの最低レベル
• 出力するログの内容

まず、__get_loggerメソッドの引数は、エラーメッセージに必要な内容を受け取っています。
それからloggerの名前が一意になるようuuidを使用し、親LoggerのHandlerがpropagateしないように設定してます。

logger = getLogger(shortuuid.uuid())  
logger.propagate = False

次にハンドラーが処理するログメッセージの最低レベルと、記録するログメッセージの最低レベルを設定します。
以下の例では、環境に応じてレベルをDEBUGかINFOに設定しているため、DEBUGに設定すると、INFO以下のメッセージが無視されることになります。

開発段階であれば、infoレベルを表示させて開発効率を上げたり、本番ではwarningとerrorを出力して余計なログを表示させないようにしましょう。

logger.setLevel(
            DEBUG if os.environ["ENV"] == "dev" else INFO
        )
handler = logging.StreamHandler()
handler.setLevel(
            DEBUG if os.environ["ENV"] == "dev" else INFO
        )

次は実際に出力するメッセージを設定していきます。
log_formatで本文を指定し、log_formatのタイムスタンプとタイムゾーンを指定しています。
handler.setFormatter(formatter)で、このハンドラを使用してログメッセージを出力する際に、指定されたフォーマットでメッセージが表示されるようになります。
logger.addHandler(handler)で、loggerにhandlerが追加され、ログメッセージを出力する際に、設定したハンドラ（およびそのフォーマッタ）が使用されるようになります。

log_format = "%(asctime)s { loglevel: %(levelname)s, " \
            "app: %(app_name)s, datetime: %(asctime)s, " \
            "resource: %(resource_name)s, file: %(file_name)s, " \
            "line: %(line_no)s, member_id: %(member_id)s, trace: %(trace)s, " \
            "message_content: %(message)s, }"

        formatter = Formatter(log_format, "%Y-%m-%d %H:%M:%S")
        formatter.converter = lambda *args: datetime.now(
            timezone('Asia/Tokyo')
        ).timetuple()
        handler.setFormatter(formatter)
        logger.addHandler(handler)

最後に、設定したメッセージをLoggerAdapterに追加して、呼び出し元に返却します。

return logging.LoggerAdapter(logger, {
            "app_name": self.APP_NAME,
            "resource_name": self.__resource_name,
            "file_name": file_name,
            "line_no": line_no,
            "trace": trace,
            "message": message,
        })

errorメソッド

ここでは、ログメッセージに使用する例外が発生したファイル名と行を取得しています。
そして追加したいメッセージとともに__get_loggerでログメッセージ等を設定して出力しています。

sys.exc_info()は、現在のスレッドで発生している例外に関する３つのタプル返します。(例外の型、例外のインスタンス、トレースバックオブジェクト)

file_nameは例外が発生した場所のファイル名を取得しています。(tb_frameはトレースバックのフレームオブジェクト、f_codeはフレーム内で現在実行されているコードオブジェクト、co_filenameはコードオブジェクトが定義されているファイルの名前)

line_noはエラー行の取得をしています。

loggerは先の__get_logger関数で設定したオブジェクトなので、このloggerに対してerrorメソッドを実行することでエラーレベルのログを出力することができます

def error(self, message: str, *args: str) -> None:
        # 例外発生箇所のファイル名・行番号を取得
        exc_info = sys.exc_info()
        file_name = exc_info[2].tb_frame.f_code.co_filename
        line_no = exc_info[2].tb_lineno

        logger = self.__get_logger(
            file_name=file_name,
            line_no=line_no,
            message=message,
        )
        logger.error()

使い方

import Logger

logger = Logger()
try:
    1 == 2 
exception:
    logger.error("error_function")
    # logger.warning("warning_function")
    # logger.info("info_function")

子でエラーハンドリングする場合は、以下のように親で検知できるようにする

import Logger

logger = Logger()
try:
    error_function()
    1 == 2 
exception as e:
    logger.error(str(e))
    # logger.warning(str(e))
    # logger.info(str(e))

def error_function():
    try:
        1 == 2
    except Exception as e:
        raise e