在python日志输出的每一行前面添加变量缩进

我正在将日志记录构建到一个Python应用程序中，我希望它是人类可读的。目前，调试日志记录了调用的每个函数以及参数和返回值。这意味着，实际上，嵌套函数调用的调试日志可能如下所示：

2024-07-29 16:52:26,641: DEBUG: MainController.initialize_components called with args <controllers.main_controller.MainController(0x1699fdcdda0) at 0x000001699F793300>
2024-07-29 16:52:26,643: DEBUG: MainController.setup_connections called with args <controllers.main_controller.MainController(0x1699fdcdda0) at 0x000001699F793300>
2024-07-29 16:52:26,645: DEBUG: MainController.setup_connections returned None
2024-07-29 16:52:26,646: DEBUG: MainController.initialize_components returned None

我想通过使用 python 风格的缩进，在嵌套时读取日志来使其变得明显。所以理想的输出是这样的：

2024-07-29 16:52:26,641: DEBUG: MainController.initialize_components called with args <controllers.main_controller.MainController(0x1699fdcdda0) at 0x000001699F793300>
    2024-07-29 16:52:26,643: DEBUG: MainController.setup_connections called with args <controllers.main_controller.MainController(0x1699fdcdda0) at 0x000001699F793300>
    2024-07-29 16:52:26,645: DEBUG: MainController.setup_connections returned None
2024-07-29 16:52:26,646: DEBUG: MainController.initialize_components returned None

我目前通过使用这个装饰器包装类方法来实现我的文档：

import functools
import logging

def log(_func=None, *, logger):
    def decorator_log(func):
        @functools.wraps(func)
        def wrapper(*args, **kwargs):
            if logger.handlers:
                current_formatter = logger.handlers[0].formatter
                current_formatter.set_tabs(current_formatter.get_tabs() + 1)
            
            self = args[0]
            name = f'{self.__class__.__name__}.{func.__name__}'
            if logger.root.level < logging.DEBUG:
                logger.info(f"Entering {name}")
            else:
                args_repr = [repr(a) for a in args]
                kwargs_repr = [f"{k}={v!r}" for k, v in kwargs.items()]
                signature = ", ".join(args_repr + kwargs_repr)
                logger.debug(f"{name} called with args {signature}")
                try:
                    result = func(*args, **kwargs)
                except Exception as e:
                    logger.exception(f"Exception raised in {name}: {str(e)}")
                    raise e
                if logger.root.level < logging.DEBUG:
                    logger.info(f"Leaving {name}")
                else:
                    logger.debug(f"{name} returned {result}")

                if logger.handlers:
                    current_formatter = logger.handlers[0].formatter
                    current_formatter.set_tabs(current_formatter.get_tabs() - 1)
                
                return result
        return wrapper
    if _func is None:
        return decorator_log
    else:
        return decorator_log(_func)

我可以使用 tabs 向记录器添加一个属性 setattr 并在开始/递减时递增在装饰器的末尾，但这仅将选项卡应用于输出的 message 部分，如下所示：

2024-07-29 16:52:26,641: DEBUG: MainController.initialize_components called with args <controllers.main_controller.MainController(0x1699fdcdda0) at 0x000001699F793300>
2024-07-29 16:52:26,643: DEBUG:     MainController.setup_connections called with args <controllers.main_controller.MainController(0x1699fdcdda0) at 0x000001699F793300>
2024-07-29 16:52:26,645: DEBUG:     MainController.setup_connections returned None
2024-07-29 16:52:26,646: DEBUG: MainController.initialize_components returned None

这比没有好，但不完全是我想要的。如何更新它（最好不使用全局变量）以在记录器输出的每行开头处具有变量缩进？

要实现Python日志输出中每行开头的可变缩进，你可以使用一个全局变量来跟踪缩进级别，并在自定义格式化程序中使用它。

这是一个示例：

import logging
import functools

# 全局缩进级别
INDENT_LEVEL = 0

class IndentedFormatter(logging.Formatter):
    def __init__(self, fmt=None, datefmt=None, style='%'):
        super().__init__(fmt, datefmt, style)

    def format(self, record):
        # 在每行消息前面添加缩进
        message = super().format(record)
        indented_message = '\t' * INDENT_LEVEL + message
        return indented_message

def log(_func=None, *, logger=None):
    if logger is None:
        logger = logging.getLogger()  # 获取默认的根记录器

    def decorator_log(func):
        @functools.wraps(func)
        def wrapper(*args, **kwargs):
            global INDENT_LEVEL
            INDENT_LEVEL += 1

            self = args[0]
            name = f'{self.__class__.__name__}.{func.__name__}'
            logger.debug(f"Entering {name}")
            try:
                result = func(*args, **kwargs)
            except Exception as e:
                logger.exception(f"Exception raised in {name}: {str(e)}")
                raise e
            logger.debug(f"{name} returned {result}")

            INDENT_LEVEL -= 1
            return result
        return wrapper
    if _func is None:
        return decorator_log
    else:
        return decorator_log(_func)

# 创建一个记录器并设置格式化程序
logger = logging.getLogger(__name__)
handler = logging.StreamHandler()
formatter = IndentedFormatter('%(asctime)s: %(levelname)s: %(message)s', '%Y-%m-%d %H:%M:%S')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.setLevel(logging.DEBUG)

# 示例用法
class MyClass:
    @log(logger=logger)
    def my_method(self, arg1, arg2):
        logger.debug(f"my_method called with args: {arg1}, {arg2}")
        self.my_inner_method()

    @log(logger=logger)
    def my_inner_method(self):
        logger.debug("my_inner_method called")

# 创建类的实例并调用方法
my_class = MyClass()
my_class.my_method(1, 2)

这将产生以下输出：

2024-07-29 17:22:05: DEBUG: Entering MyClass.my_method
    2024-07-29 17:22:05: DEBUG: my_method called with args: 1, 2
    2024-07-29 17:22:05: DEBUG: Entering MyClass.my_inner_method
        2024-07-29 17:22:05: DEBUG: my_inner_method called
    2024-07-29 17:22:05: DEBUG: MyClass.my_inner_method returned None
2024-07-29 17:22:05: DEBUG: MyClass.my_method returned None

说明：

• 我们定义了一个全局变量 INDENT_LEVEL 来跟踪当前的缩进级别。
• 我们创建了一个自定义格式化程序 IndentedFormatter ，它使用 INDENT_LEVEL 变量在每行消息前面添加缩进。
• log 装饰器增加了 INDENT_LEVEL ，记录消息，然后减少 INDENT_LEVEL 。
• 我们将自定义格式化程序设置为记录器的处理程序。

现在，每次调用装饰的函数时，日志消息都会缩进以指示嵌套级别。

注意： 虽然全局变量在简单情况下有效，但在处理多线程应用程序时可能会导致问题。对于更健壮的解决方案，请考虑使用上下文管理器或基于线程的存储来管理缩进级别。