今天一位小伙伴过来问我,他写的程序中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")
|