通过源码排查 python log 在console中重复打印日志问题

今天一位小伙伴过来问我，他写的程序中log明明只调用了一次，但在console中打印了多次，表示不解。具体现象表现为：

123456

123456
123456

123456
123456
123456

分析了一下他的代码，大致的逻辑是他在for循环中调用了一个静态类的方法，该方法中会初始化logger并打印log，为了方便理解，我把代码进行了简化，代码如下：

"""
test.py
"""
def test(self):
    for i, test_resource in enumerate(test_resources):
        test_result = TestAPI().get_result()

"""
testApi.py
"""
from log import logger_config
class TestAPI():

    def get_result(self):
      logger = logger_config(log_path='log.txt', logging_name='log')
      logger.info("123456")

"""
log.py
"""
import logging
def logger_config(log_path,logging_name):
    logger = logging.getLogger(logging_name)
    ……
    logger.addHandler(console)
    return logger

从代码中我们可以看到，逻辑是在一个for循环中调用TestAPI类的get_result方法。在该方法中通过logger_config来初始化一个log实例，用于后面的日志打印 。接下来，调用logger.info方法打印需要输出的日志。

在这个logger_config方法的代码中，首先通过logging库的getLogger方法创建了一个实例并返回。然后给logger实例加入console handler让日志可以打印在console中，最后将logger实例返回。上面调用的logger实例就是此处返回的。

从整体逻辑来看，好像并没有什么问题。即使是在for循环中调用，但每次logger实例都是新创建的，不会同时存在，也就不会出现这种随着for循环次数的增加，打印数也增加的情况。

这时问题就聚焦在了logger实例的addHandler方法上。从现象反推，猜测是由于addHandler方法内部是用数组来存放传入的handler的，并在执行时遍历数组来使用handler。为了验证这个猜想，我找到logging模块的源码来看看它的实现是否正如我猜想的那样。

通过在命令行中import logging，读取__file__属性找到模块源码的路径：

打开源码，搜索addHandler方法，其代码如下：

方法中调用了self.handlers.append将传入handler传入，而self.handlers在文件开头被定义为数组：

由此可见，addHandlers方法内部确实是使用的数组来管理handler。

因此，在每一次的for循环中，每当调用到logger.addHandler(console)方法都会增加一个console handler。所以在logger实例进行输出时，会调用数组中的所有console handler，从而导致重复打印。而且循环次数每增加一次，重复打印的次数也会随之增加一次。

为了避免出现这样的问题，建议把初始化logger的代码移动全局，确保其只执行一次，例如：

"""
log.py
"""
from log import logger_config
logger = logger_config(log_path='log.txt', logging_name='log')

class TestAPI():

    def get_result(self):
      logger.info("123456")