如何在Python logging模块中将类实例变量添加到发送给父日志记录器的消息中

Question

我有一些日志记录器，用于多个程序，每个程序都有多个处理器，这些处理器配置在一个叫做 "__main__" 的日志记录器里，还有一个包创建了一个 "__main__.package" 的日志记录器，所以它会使用那个配置来记录信息。我无法控制这些程序的日志记录器，只有我自己的包可以控制。我的包应该使用这些日志记录器的设置。我可以假设每个使用我包的程序都有一个配置好的日志记录器。

我想从主日志记录器那里继承格式化器，但在信息发送到格式化器之前，先修改一下信息/格式。这个需求跟这个问题很相似，只不过我是在处理一个子日志记录器，而不是直接处理父日志记录器。

举个例子：

main.py

import logging
import mypackage
logger = logging.getLogger("__main__")
logger.setLevel(logging.DEBUG)
stream_handler = logging.StreamHandler()
stream_handler.setLevel(logging.INFO)
stream_formatter = logging.Formatter('%(levelname)s:%(filename)s:%(lineno)d:%(message)s')
stream_handler.setFormatter(stream_formatter)
logger.addHandler(stream_handler)    

def main():
    a=1
    logger.info("message from main")
    b = mypackage.MyClass("EXTRA INSTANCE INFO")
    b.mymodule(a)

    c = mypackage.MyClass("EXTRA INSTANCE INFO2")
    c.mymodule(a+1)
    
main()

我尝试添加这些信息的方法是通过添加一个过滤器来修改消息，这样在输出之前就能修改消息：

mypackage.py

import logging
logger = logging.getLogger(f"__main__.{__name__}")

class _PackageContextFilter(logging.Filter):

    def __init__(self, needed_info_from_my_package):
        self.needed_info_from_my_package=needed_info_from_my_package

    def filter(self, record):
        record.msg = f"({self.needed_info_from_my_package}) " + record.msg
        return True
    
class MyClass():
    def __init__(self,init_cond) -> None:
        self.data=[]
        self.needed_info_from_my_package = [init_cond]
        # I think the issue arises here because a single logger object gets multiple filters
        logger.addFilter(_PackageContextFilter(self.needed_info_from_my_package))
        
        
    def mymodule(self,data):
        self.data.append(data)
        logger.info(f"message from mymodule about {self.data}")
       

输出：

INFO:main.py:13:message from main
INFO:mypackage.py:24:(['EXTRA INSTANCE INFO']) message from mymodule about [1]
INFO:mypackage.py:24:(['EXTRA INSTANCE INFO2']) (['EXTRA INSTANCE INFO']) message from mymodule about [2]

我想要的输出是

INFO:main.py:13:message from main
INFO:mypackage.py:24:(['EXTRA INSTANCE INFO']) message from mymodule about [1]
INFO:mypackage.py:24:(['EXTRA INSTANCE INFO2']) message from mymodule about [2]

我觉得这个输出重复是因为我一直在同一个日志对象上添加过滤器。在日志记录手册中，有一个示例是创建上下文变量来处理某个类的两个实例，但当我查找上下文变量的文档时，发现它似乎更多是与线程相关的。我不确定创建它们来解决这个问题是否是个“好主意”。

我想我还可以做的另一种选择是将每个日志消息的输入都包裹起来，比如 logging.info(self.format_message_instance(msg))，但我觉得应该有一些公认的最佳实践。

Answer 1

通常情况下，过滤器是无法知道哪个MyClass实例调用了它的，所以它不知道该在消息中添加什么信息。我们可以考虑使用一个适配器，这个适配器对每个实例都是独一无二的，类似于烹饪书中的例子：

class CustomAdapter(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        return f"({self.extra['info']}) {msg}", kwargs

    
class MyClass():
    def __init__(self,init_cond) -> None:
        self.data=[]
        self.needed_info_from_my_package = [init_cond]
        # here we initialize based on the main logger
        self.logger = CustomAdapter(logger, {'info': self.needed_info_from_my_package})
        
        
    def mymodule(self,data):
        self.data.append(data)
        self.logger.info(f"message from mymodule about {self.data}")