解决logging模块日志信息重复问题

解决logging模块日志信息重复问题

问题描述

相信大家都知道python的logging模块记录日志信息的步骤:
# coding:utf-8

import logging

### 创建logger对象
logger = logging.getLogger()
###设置下最低级别
logger.setLevel(logging.DEBUG)
### 创建文件操作符
fh = logging.FileHandler('test',encoding='utf-8')
### 创建屏幕操作符
sh = logging.StreamHandler()
### 创建一个格式对象
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
### logger绑定文件操作符
logger.addHandler(fh)
### logger绑定屏幕操作符
logger.addHandler(sh)
### 文件操作符绑定格式
fh.setFormatter(formatter)
### 屏幕操作符绑定格式
sh.setFormatter(formatter)
### 用logger对象输出信息
logger.warning('logger1')
logger.info('logger2')
logger.error('logger3')
然后,如果我们用上面的思路来写一个函数实现日志功能(我们写日志的py文件为logger.py,在同目录下创建一个文件log.log来记录日志信息,而且这里只将日志信息输出到文件来显示):
# logger.py
# coding:utf-8

import logging

def logger(msg):
    #生成logger对象
    whw_logger = logging.getLogger('log.log')
    whw_logger.setLevel(logging.INFO)
    #生成handler对象
    whw_fh = logging.FileHandler('log.log')
    whw_fh.setLevel(logging.INFO)
    #生成Formatter对象
    file_formatter = logging.Formatter(' %(asctime)s - %(name)s - %(levelname)s - %(message)s ')
    #把formatter对象绑定到handler对象中
    whw_fh.setFormatter(file_formatter)
    # 把handler对象绑定到logger对象中
    whw_logger.addHandler(whw_fh)
    whw_logger.info(msg)

if __name__ == '__main__':
   logger('hello world1')
   logger('hello world2')
   logger('hello world3')
但是,当程序运行后,你会发现,你的log.log文件中的记录竟然是酱紫的(程序运行2次):
 2019-04-07 14:47:12,318 - log.log - INFO - hello world1
 2019-04-07 14:47:12,319 - log.log - INFO - hello world2
 2019-04-07 14:47:12,319 - log.log - INFO - hello world2
 2019-04-07 14:47:12,319 - log.log - INFO - hello world3
 2019-04-07 14:47:12,319 - log.log - INFO - hello world3
 2019-04-07 14:47:12,319 - log.log - INFO - hello world3
 2019-04-07 14:47:15,388 - log.log - INFO - hello world1
 2019-04-07 14:47:15,388 - log.log - INFO - hello world2
 2019-04-07 14:47:15,388 - log.log - INFO - hello world2
 2019-04-07 14:47:15,388 - log.log - INFO - hello world3
 2019-04-07 14:47:15,388 - log.log - INFO - hello world3
 2019-04-07 14:47:15,388 - log.log - INFO - hello world3 
也就是说,我们每一次进行日志信息打印的次数是成倍增长的!!!

问题分析

其实,我们每次在创建一个logger对象的时候,里面会有一个handlers属性,初始值为一个空列表:
class Logger(Filterer):
    """
    logger 对象的介绍 详情大家可以看源码
    """
    def __init__(self, name, level=NOTSET):
        """
        Initialize the logger with a name and an optional level.
        """
        Filterer.__init__(self)
        self.name = name
        self.level = _checkLevel(level)
        self.parent = None
        self.propagate = True
        # 初始化为空列表的handlers属性
        self.handlers = []
        self.disabled = False
那么问题来了:这个handlers属性是做什么用的呢?让我们再来看一下源码:
def addHandler(self, hdlr):
    """
    Add the specified handler to this logger.
    """
    _acquireLock()
    try:
        if not (hdlr in self.handlers):
            self.handlers.append(hdlr)
    finally:
        _releaseLock()
当我们为一个logger对象绑定一个文件或者屏幕操作符的时候,其实就是讲它们加在了这个handlers列表里面。然后我们再接着往下看(这里只截取代码片段,帮助大家分析问题,具体的还是建议大家自己看源码):
for h in handlers:
    if h.formatter is None:
        h.setFormatter(fmt)
    root.addHandler(h)
这段代码下面其实就是从我们这个handlers列表中获取操作符,然后进行文件或屏幕的格式化操作。
问题就出现在了这里:由于我们上面的代码每次都打印三个信息————在第一次执行打印 hello world1 的时候会创建一个logger对象,而此时handlers列表是空的,因此程序会为这个空列表加上一个文件操作符;在第二次打印 hello world2 时,程序会根据getLogger函数的name属性获取之前的同一个logger对象,并没有创建新的logger对象,而接着程序又会‘像之前一样’误将文件操作符又一次append到了handlers列表里,此时这个列表中有两个相同的文件操作符,因此第二次会打印两次相同的信息;第三次原理一样...文件中输出三次相同的信息
我们可以在logger函数的结尾加上下面这段代码,每次都打印一下handlers列表,验证一下我们的猜想::
print(whw_logger.handlers)
print(len(whw_logger.handlers))
输出结果如下:
[<FileHandler E:\practice\old_boy_all_day\all_days\day26+1\log.log (INFO)>]
1
[<FileHandler E:\practice\old_boy_all_day\all_days\day26+1\log.log (INFO)>, <FileHandler E:\practice\old_boy_all_day\all_days\day26+1\log.log (INFO)>]
2
[<FileHandler E:\practice\old_boy_all_day\all_days\day26+1\log.log (INFO)>, <FileHandler E:\practice\old_boy_all_day\all_days\day26+1\log.log (INFO)>, <FileHandler E:\practice\old_boy_all_day\all_days\day26+1\log.log (INFO)>]
3
结果果真如我们所想的那样:列表中每一次都添加了新的文件操作符。

问题解决

关于一次性重复打印的问题的原因我们找到了,那么如何解决呢?下面给出两种推荐的解决方案:

每一次输出完后及时移除操作符

就是说,在每一次输出结束后,我们将handlers这个列表中的logger对象及时移除。
移除的方法有两种,一种是利用logger对象中自带的removeHandler方法,另外也可以直接利用列表的pop方法直接将handlers对象中的文件操作符删除(不过这种方法得考虑每一次添加了多少个文件操作符),针对本例给出的解决方案的代码如下:
# coding:utf-8

import logging

def logger(msg):
    #生成logger对象
    whw_logger = logging.getLogger('log.log')
    whw_logger.setLevel(logging.INFO)
    #生成handler对象
    whw_fh = logging.FileHandler('log.log')
    whw_fh.setLevel(logging.INFO)
    #生成Formatter对象
    file_formatter = logging.Formatter(' %(asctime)s - %(name)s - %(levelname)s - %(message)s ')
    #把formatter对象绑定到handler对象中
    whw_fh.setFormatter(file_formatter)
    # 把handler对象绑定到logger对象中
    whw_logger.addHandler(whw_fh)
    whw_logger.info(msg)
    whw_logger.removeHandler(whw_fh)

if __name__ == '__main__':
   logger('hello world1')
   logger('hello world2')
   logger('hello world3')

在logger函数中判断handlers属性是否为空

使用前判断logger对象的handlers列表是否为空,空则添加一个handler,不空则直接调用:
# coding:utf-8

import logging

def logger(msg):
    #生成logger对象
    whw_logger = logging.getLogger('log.log')
    whw_logger.setLevel(logging.INFO)
    # 如果handlers属性为空则添加文件操作符,不为空直接写日志
    if not whw_logger.handlers:
        #生成handler对象
        whw_fh = logging.FileHandler('log.log')
        whw_fh.setLevel(logging.INFO)
        #生成Formatter对象
        file_formatter = logging.Formatter(' %(asctime)s - %(name)s - %(levelname)s - %(message)s ')
        #把formatter对象绑定到handler对象中
        whw_fh.setFormatter(file_formatter)
        # 把handler对象绑定到logger对象中
        whw_logger.addHandler(whw_fh)
    whw_logger.info(msg)

if __name__ == '__main__':
   logger('hello world1')
   logger('hello world2')
   logger('hello world3')

利用单例模式解决

如果利用面向对象的方法写一个Log类去实现的话,基本思路是:首先利用重写__new__的方法创建每个logger对象的单例,然后在每次实例化的时候判断是否已经存在这个logger对象,如果不存在的话就创建,若之前已经创建了一个相同的logger对象,就直接用之前的,酱紫大大提高了程序的效率
话不多说,直接上代码:
# -*- coding:utf-8 -*-
import logging

class Log(object):
    __instance = None
    # 重写new方法实现单例模式
    def __new__(cls, *args, **kwargs):
        if not cls.__instance:
            obj = object.__new__(cls)
            cls.__instance = obj
        return cls.__instance

    def __init__(self,level=logging.DEBUG):
        # 如果之前没创建过 就新建一个logger对象,后面相同的实例共用一个logger对象
        if 'logger' not in self.__dict__:
            logger = logging.getLogger()
            logger.setLevel(level)
            fh = logging.FileHandler('log.log', encoding='utf-8')
            ch = logging.StreamHandler()
            formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
            fh.setFormatter(formatter)
            ch.setFormatter(formatter)
            logger.addHandler(fh)
            logger.addHandler(ch)
            self.logger = logger

if __name__ == '__main__':
    log1 = Log()
    log2 = Log()
    log3 = Log()
    log1.logger.info('123')
    log2.logger.info('456')
    log3.logger.info('789')
输出结果:
2019-04-09 20:39:08,081 - root - INFO - 123
2019-04-09 20:39:08,081 - root - INFO - 456
2019-04-09 20:39:08,081 - root - INFO - 789
当然,如果考虑到效率的问题,在logger函数中判断handlers属性是否为空利用单例模式解决的方法要比每次从handlers属性列表中删除掉之前的操作符的方法高效,因为这样可以避免Python解释器做重复繁琐的工作。
上一篇:ThreadLocal详解(实现多线程同步访问变量)


下一篇:Java selenium web页面的滚动条操作