Pythonコマンドラインアプリケーションのログ出力

導入

ログは、重大なアプリケーションの必要な部分です.それはあなたとあなたのユーザーが効果的に問題をデバッグすることができます.この記事では、コマンドラインPythonアプリケーションのログを設定する良い方法を紹介します.完成品はgithub gistとして見ることができますhere .

ゴール

我々のロガーの目標は複数の部品を持つでしょう.

コンソール出力をきれいにして、人間によって読みやすい

コンピュータによって解析できるログファイルに追加出力を保存する

後でデバッグするためのすべてのトレースバック情報を保存する

ユーザーがコンソールとログファイル出力の詳細を変更できるようにする

コンソール出力を次のようにします.

ログファイルは次のようになります.

DEBUG:2022-04-03 15:41:17,920:root:A debug message
INFO:2022-04-03 15:41:17,920:root:An info message
WARNING:2022-04-03 15:41:17,920:root:A warning message
ERROR:2022-04-03 15:41:17,920:root:An error message
CRITICAL:2022-04-03 15:41:17,920:root:A critical message from an exception
    Traceback (most recent call last):
        /home/eb/projects/py-scratch/color-log.py  <module>  327: raise ValueError("A critical message from an exception")
    ValueError: A critical message from an exception

ここでいくつかのトリッキーなことがあります.

我々は、ログレベルに基づいて別の色や形式を使用している

私たちは、コンソールとファイル出力のために異なるフォーマットを使用しています

トレースバック形式を変更しました

フォーマッタ

Pythonロギングフォーマッタはログレベルに基づいて異なる書式指定文字列を許可しませんので、独自のフォーマッタを実装する必要があります.

import typing as t

class MultiFormatter(PrettyExceptionFormatter):
    """Format log messages differently for each log level"""

    def __init__(self, formats: t.Dict[int, str] = None, **kwargs):
        base_format = kwargs.pop("fmt", None)
        super().__init__(base_format, **kwargs)

        formats = formats or default_formats

        self.formatters = {
            level: PrettyExceptionFormatter(fmt, **kwargs)
            for level, fmt in formats.items()
        }

    def format(self, record: logging.LogRecord):
        formatter = self.formatters.get(record.levelno)

        if formatter is None:
            return super().format(record)

        return formatter.format(record)

我々の中でMultiFormatter クラスは、ログレベルの書式設定文字列をマッピングし、各レベルの異なるフォーマッタを作成します.イン.format() , 我々は、ログレベルのフォーマッタにディスパッチします.
さて、何PrettyExceptionFormatter ? また、それを実装する必要があります.これはログレコードに含まれているときにトレースバックと例外情報をフォーマットします.

from textwrap import indent
from pretty_traceback.formatting import exc_to_traceback_str

class PrettyExceptionFormatter(logging.Formatter):
    """Uses pretty-traceback to format exceptions"""

    def __init__(self, *args, color=True, **kwargs) -> None:
        super().__init__(*args, **kwargs)
        self.color = color

    def formatException(self, ei):
        _, exc_value, traceback = ei
        return exc_to_traceback_str(exc_value, traceback, color=self.color)

    def format(self, record: logging.LogRecord):
        record.message = record.getMessage()

        if self.usesTime():
            record.asctime = self.formatTime(record, self.datefmt)

        s = self.formatMessage(record)

        if record.exc_info:
            # Don't assign to exc_text here, since we don't want to inject color all the time
            if s[-1:] != "\n":
                s += "\n"
            # Add indent to indicate the traceback is part of the previous message
            text = indent(self.formatException(record.exc_info), " " * 4)
            s += text

        return s

我々は素晴らしいを使用しているpretty-traceback パッケージはこちら.のデフォルト動作logging.Formatter を変更するrecord.exc_text の出力で.formatException() , その振る舞いをオーバーライドする必要があります.これはANSIカラーを追加し、ログファイルでそれを見たくないからです.
標準でlogging.Formatter 実装は、例外をフォーマットする際に( Python 3.10.2のように)レコードが変更されます:

def format(self, record):
    ...
    # exc_text is MODIFIED, which propagates to other formatters for other handlers
    record.exc_text = self.formatException(record.exc_info)
    ...
    return s

The MultiFormatter クラスはレベルごとの書式指定文字列を変更するための引数をとります.

default_formats = {
    logging.DEBUG: style("DEBUG", fg="cyan") + " | " + style("%(message)s", fg="cyan"),
    logging.INFO: "%(message)s",
    logging.WARNING: style("WARN ", fg="yellow") + " | " + style("%(message)s", fg="yellow"),
    logging.ERROR: style("ERROR", fg="red") + " | " + style("%(message)s", fg="red"),
    logging.CRITICAL: style("FATAL", fg="white", bg="red", bold=True) + " | " + style("%(message)s", fg="red", bold=True),
}

これは、プレーンメッセージとして渡される情報メッセージを除いて、レベル名とメッセージの間に垂直線を加えます.The style ここでの機能は click.style ユーティリティ.

コンテキストマネージャ

ここで最後の目標は、単にコールすることですwith cli_log_config(): , そして、美しい出力を得てください.コンテキストマネージャを必要とします.ログコンテキストから始まるpython docs :

class LoggingContext:
    def __init__(
        self,
        logger: logging.Logger = None,
        level: int = None,
        handler: logging.Handler = None,
        close: bool = True,
    ):
        self.logger = logger or logging.root
        self.level = level
        self.handler = handler
        self.close = close

    def __enter__(self):
        if self.level is not None:
            self.old_level = self.logger.level
            self.logger.setLevel(self.level)

        if self.handler:
            self.logger.addHandler(self.handler)

    def __exit__(self, *exc_info):
        if self.level is not None:
            self.logger.setLevel(self.old_level)

        if self.handler:
            self.logger.removeHandler(self.handler)

        if self.handler and self.close:
            self.handler.close()

次に、複数のコンテキストマネージャを動的に結合するための特別なコンテキストマネージャを作成します.

class MultiContext:
    """Can be used to dynamically combine context managers"""

    def __init__(self, *contexts) -> None:
        self.contexts = contexts

    def __enter__(self):
        return tuple(ctx.__enter__() for ctx in self.contexts)

    def __exit__(self, *exc_info):
        for ctx in self.contexts:
            ctx.__exit__(*exc_info)

最後に、私たちはこれまでの単一のコンテキストマネージャにまとめました.

def cli_log_config(
    logger: logging.Logger = None,
    verbose: int = 2,
    filename: str = None,
    file_verbose: int = None,
):
    """
    Use a logging configuration for a CLI application.
    This will prettify log messages for the console, and show more info in a log file.

    Parameters
    ----------
    logger : logging.Logger, default None
        The logger to configure. If None, configures the root logger
    verbose : int from 0 to 3, default 2
        Sets the output verbosity.
        Verbosity 0 shows critical errors
        Verbosity 1 shows warnings and above
        Verbosity 2 shows info and above
        Verbosity 3 and above shows debug and above
    filename : str, default None
        The file name of the log file to log to. If None, no log file is generated.
    file_verbose : int from 0 to 3, default None
        Set a different verbosity for the log file. If None, is set to `verbose`.
        This has no effect if `filename` is None.

    Returns
    -------
    A context manager that will configure the logger, and reset to the previous configuration afterwards.
    """

    if file_verbose is None:
        file_verbose = verbose

    verbosities = {
        0: logging.CRITICAL,
        1: logging.WARNING,
        2: logging.INFO,
        3: logging.DEBUG,
    }

    console_level = verbosities.get(verbose, logging.DEBUG)
    file_level = verbosities.get(file_verbose, logging.DEBUG)

    # This configuration will print pretty tracebacks with color to the console,
    # and log pretty tracebacks without color to the log file.

    console_handler = logging.StreamHandler()
    console_handler.setFormatter(MultiFormatter())
    console_handler.setLevel(console_level)

    contexts = [
        LoggingContext(logger=logger, level=min(console_level, file_level)),
        LoggingContext(logger=logger, handler=console_handler, close=False),
    ]

    if filename:
        file_handler = logging.FileHandler(filename)
        file_handler.setFormatter(
            PrettyExceptionFormatter(
                "%(levelname)s:%(asctime)s:%(name)s:%(message)s", color=False
            )
        )
        file_handler.setLevel(file_level)
        contexts.append(LoggingContext(logger=logger, handler=file_handler))

    return MultiContext(*contexts)

我々は現在、冗長性レベル、ログファイル、およびファイルの異なる冗長性を指定するオプションがあります.例を試してみてください.

with cli_log_config(verbose=3, filename="test.log"):
    try:
        logging.debug("A debug message")
        logging.info("An info message")
        logging.warning("A warning message")
        logging.error("An error message")
        raise ValueError("A critical message from an exception")
    except Exception as exc:
        logging.critical(str(exc), exc_info=True)

陰謀

本稿では、

ログレベルに基づいて動的にメッセージをフォーマットするカスタムロギングフォーマッタを実装しました

コンソールログ出力に色を追加

ログメッセージ中のprettified例外

すべてを再利用可能なコンテキストマネージャにラップします

私はあなたが楽しんで、あなたのCLIアプリより多くのユーザーフレンドリーかつ堅牢な作りのためのいくつかのインスピレーションを描いてほしい!