深度剖析 Python 日志重复打印问题

python 日志处理流程
使用 python 做日志输出时，首先我们需要一个创建一个 Logger 对象：import logging; logger = logging.getLogger()

然后就可以用 logger.info/debug/error(msg) 来输出日志

如果只是单纯地打印日志，这样做和 print 没有任何区别。我们期望 log 能有一定的格式，这时就会用到 logging.Formatter

我们还希望日志不仅在 console 中输出，还要向文件输出

这样需要给 logger 添加 handler，一个 handler 指向标准输出流，一个 handler 指向文件 handler

logging.handlers 提供了一些这些常用的 handler

针对不同的输出流进行精准的控制

比如：在 console 中只输出某些高级别的日志，而在文件日志中输出所有日志

在 console 中，使用一种输出 formatter，在文件输出中使用另一种 formatter

不满足于 python 提供的 DEBUG/INFO/WARNING/ERROR/CRITICAL 的控制粒度，想要更精细地控制日志就需要理解日志是如何流转、继承

如下是python官方提供的 log 工作流：

 

详细资料请查阅： https://docs.python.org/3/howto/logging.html

python logger 重复打印问题
情景介绍
log 重复打印存在两种情况：

未定义 logger （ logger = logging.getLogger() ），默认使用了 RootLogger，一个 python 程序内全局唯一的，所有 Logger 对象的祖先

每次实例化返回的都是 RootLogger 对象

自定义的 log 函数，每次调用都实例化，传入相同的 logger name，经验证 logging.getLogger(“name”) 使用了单例模型

也就是说每次实例化返回的是同一个 logger 对象，然后每次都调用 logger.addHandler(handler) 方法添加日志处理器

导致 handlers 列表添加了相同的 handler（注意：日志的打印由 handler 控制）

以此类推，调用几次就会有几个 handler，然后前面打印的 log 就会影响后面定义的 log

总结：

日志重复打印的问题源于 handlers 列表添加了相同的 handler

附上源码截图

 

注意：

验证 logging.getLogger(“name”) 使用了单例模型，最简单的就是打印 logger id

 

示例验证
打印日志重复次数会与实例化 log 函数的次数相同，每次实例化都打印出 self.handlers 会发现 handlers 列表累加一个 handler 元素

 

示例代码

import logging


def log(msg):
    logger = logging.getLogger()
    handler = logging.FileHandler('test.log')

    logger.setLevel(logging.INFO)  # 设置日志等级
    # 日志输出格式
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    handler.setFormatter(formatter)
    # 输入到控制台
    console = logging.StreamHandler()
    console.setLevel(logging.INFO)
    logger.addHandler(handler)
    logger.addHandler(console)

    print(logger.handlers)

    logger.info(msg)

if __name__ == '__main__':
    log("a")
    log("bb")
    log("ccc")

输出结果

'''
a
bb
bb
ccc
ccc
ccc
[<FileHandler C:\Users\EDY\PycharmProjects\pythonProject1\test.log (NOTSET)>, <StreamHandler <stderr> (INFO)>]
[<FileHandler C:\Users\EDY\PycharmProjects\pythonProject1\test.log (NOTSET)>, <StreamHandler <stderr> (INFO)>, <FileHandler C:\Users\EDY\PycharmProjects\pythonProject1\test.log (NOTSET)>, <StreamHandler <stderr> (INFO)>]
[<FileHandler C:\Users\EDY\PycharmProjects\pythonProject1\test.log (NOTSET)>, <StreamHandler <stderr> (INFO)>, <FileHandler C:\Users\EDY\PycharmProjects\pythonProject1\test.log (NOTSET)>, <StreamHandler <stderr> (INFO)>, <FileHandler C:\Users\EDY\PycharmProjects\pythonProject1\test.log (NOTSET)>, <StreamHandler <stderr> (INFO)>]
'''

解决方法

方法一

• 打印日志后，通过 removeHandler() 将处理器移除掉

# 示例
import logging


def log(msg):
    logger = logging.getLogger()
    .....
    logger.info(msg)
    
    #移除处理器
    logger.removeHandler(handler)
    logger.removeHandler(console)

if __name__ == '__main__':
    log("a")
    log("bb")
    log("ccc")
    
# 输出
'''
a
bb
ccc
[<FileHandler C:\Users\EDY\PycharmProjects\pythonProject1\test.log (NOTSET)>, <StreamHandler <stderr> (INFO)>]
[<FileHandler C:\Users\EDY\PycharmProjects\pythonProject1\test.log (NOTSET)>, <StreamHandler <stderr> (INFO)>]
[<FileHandler C:\Users\EDY\PycharmProjects\pythonProject1\test.log (NOTSET)>, <StreamHandler <stderr> (INFO)>]
'''

相同的 handler 没有被添加到 handlers，日志也就不会重复打印了

方法二

• 每个 Logger 都使用不同的命名自定义 logger

#!/usr/bin/python
# -*- coding:utf-8 -*-
 
import logging
import time
import os
 
 
class Log(object):
    '''
    封装后的logging
    '''
 
    def __init__(self, logger=None, log_cate='search'):
        '''
            指定保存日志的文件路径，日志级别，以及调用文件
            将日志存入到指定的文件中
        '''
 
        # 创建一个logger
        self.logger = logging.getLogger(logger)
        self.logger.setLevel(logging.DEBUG)
        # 创建一个handler，用于写入日志文件
        self.log_time = time.strftime("%Y_%m_%d")
        file_dir = os.getcwd() + '/../log'
        if not os.path.exists(file_dir):
            os.mkdir(file_dir)
        self.log_path = file_dir
        self.log_name = self.log_path + "/" + log_cate + "." + self.log_time + '.log'
        # print(self.log_name)
 
        fh = logging.FileHandler(self.log_name, 'a')  # 追加模式  这个是python2的
        # fh = logging.FileHandler(self.log_name, 'a', encoding='utf-8')  # 这个是python3的
        fh.setLevel(logging.INFO)
 
        # 再创建一个handler，用于输出到控制台
        ch = logging.StreamHandler()
        ch.setLevel(logging.INFO)
 
        # 定义handler的输出格式
        formatter = logging.Formatter(
            '[%(asctime)s] %(filename)s->%(funcName)s line:%(lineno)d [%(levelname)s]%(message)s')
        fh.setFormatter(formatter)
        ch.setFormatter(formatter)
 
        # 给logger添加handler
        self.logger.addHandler(fh)
        self.logger.addHandler(ch)
 
        # 关闭打开的文件
        fh.close()
        ch.close()
 
    def getlog(self):
        return self.logger

测试示例

# a.py
from common.log import Log
log = Log(__name__).getlog()
log.info("I am a.py")

# b.py
from common.log import Log
log = Log(__name__).getlog()
log.info("I am b.py")

# c.py
import b
import a
 
from common.log import Log
 
log = Log(__name__).getlog()
log.info("I am c.py")

# 执行 c.py 脚本输出结果
[2019-01-14 16:24:12,008] b.py-><module> line:6 [INFO]I am b.py
[2019-01-14 16:24:12,009] a.py-><module> line:6 [INFO]I am a.py
[2019-01-14 16:24:12,009] c.py-><module> line:10 [INFO]I am c.py

方法三

• 在 log 方法里做判断，如果这个 logger 已有 handler，则不再添加 handler

3333333333333333

import logging


def log(message):
    logger = logging.getLogger('testlog')

    #  这里进行判断，如果logger.handlers列表为空，则添加，否则，直接去写日志
    if not logger.handlers:
        streamhandler = logging.StreamHandler()
        streamhandler.setLevel(logging.ERROR)
        formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(name)s - %(message)s')
        streamhandler.setFormatter(formatter)
        logger.addHandler(streamhandler)

    logger.error(message)


if __name__ == '__main__':
    log('hi')
    log('hi too')
    log('hi three')

方法四

• 还有一个推荐方法，适用所有不同模块调用自定义的 logger，封装好以后，直接在 log conf 文件底部实例化 logger ，其他模块调用时都引用实例化好的 logger 对象，节省资源空间

#!/usr/bin/python
# -*- coding:utf-8 -*-
 
import logging
import time
import os
 
 
class Log(object):
    '''
封装后的logging
    '''
 
    def __init__(self, logger=None, log_cate='search'):
        '''
            指定保存日志的文件路径，日志级别，以及调用文件
            将日志存入到指定的文件中
        '''
 
        # 创建一个logger
        self.logger = logging.getLogger(logger)
        self.logger.setLevel(logging.DEBUG)
        # 创建一个handler，用于写入日志文件
        self.log_time = time.strftime("%Y_%m_%d")
        file_dir = os.getcwd() + '/../log'
        if not os.path.exists(file_dir):
            os.mkdir(file_dir)
        self.log_path = file_dir
        self.log_name = self.log_path + "/" + log_cate + "." + self.log_time + '.log'
        # print(self.log_name)
 
        fh = logging.FileHandler(self.log_name, 'a')  # 追加模式  这个是python2的
        # fh = logging.FileHandler(self.log_name, 'a', encoding='utf-8')  # 这个是python3的
        fh.setLevel(logging.INFO)
 
        # 再创建一个handler，用于输出到控制台
        ch = logging.StreamHandler()
        ch.setLevel(logging.INFO)
 
        # 定义handler的输出格式
        formatter = logging.Formatter(
            '[%(asctime)s] %(filename)s->%(funcName)s line:%(lineno)d [%(levelname)s]%(message)s')
        fh.setFormatter(formatter)
        ch.setFormatter(formatter)
 
        # 给logger添加handler
        self.logger.addHandler(fh)
        self.logger.addHandler(ch)

        # 关闭打开的文件
        fh.close()
        ch.close()
 
    def getlog(self):
        return self.logger

# 实例化 log
concurrent_logger = Log()

测试示例

# a.py
from log_conf import concurrent_logger


log = concurrent_logger.getlog()
log.info(f"01: I am a.py")

# b.py
from log_conf import concurrent_logger


log = concurrent_logger.getlog()
log.info(f"01: I am b.py")

# c.py
import a
import b
from log_conf import concurrent_logger


log = concurrent_logger.getlog()
log.info(f"01: I am c.py")

# 执行 c.py 脚本输出结果
[2022-11-16 17:10:35,034] a.py-><module> line:7 [INFO]01: I am a.py
[2022-11-16 17:10:35,035] b.py-><module> line:7 [INFO]01: I am b.py
[2022-11-16 17:10:35,035] c.py-><module> line:9 [INFO]01: I am c.py

方法五

• 不同模块调用日志，需要将日志存储到对应的模块文件下，方便定位问题自定义 logger

#!/usr/bin/python
# -*- coding:utf-8 -*-

import logging
import time
import os


class Log(object):
    '''
    封装后的logging
    '''

    def __init__(self, logger=None, log_cate='search'):
        '''
            指定保存日志的文件路径，日志级别，以及调用文件
            将日志存入到指定的文件中
        '''

        # 创建一个logger
        self.logger = logging.getLogger(logger)
        self.logger.setLevel(logging.DEBUG)
        # 创建一个handler，用于写入日志文件
        self.log_time = time.strftime("%Y_%m_%d")
        if not os.path.exists(logger):
            os.mkdir(logger)
        self.log_path = logger
        self.log_name = self.log_path + "/" + logger + "." + self.log_time + '.log'

        fh = logging.FileHandler(self.log_name, 'a')  # 追加模式  这个是python2的
        # fh = logging.FileHandler(self.log_name, 'a', encoding='utf-8')  # 这个是python3的
        fh.setLevel(logging.INFO)

        # 再创建一个handler，用于输出到控制台
        ch = logging.StreamHandler()
        ch.setLevel(logging.INFO)

        # 定义handler的输出格式
        formatter = logging.Formatter(
                '[%(asctime)s] %(filename)s->%(funcName)s line:%(lineno)d [%(levelname)s]%(message)s')
        fh.setFormatter(formatter)
        ch.setFormatter(formatter)

        # 给logger添加handler
        self.logger.addHandler(fh)
        self.logger.addHandler(ch)

        # 关闭打开的文件
        fh.close()
        ch.close()

    def getlog(self):
        return self.logger

测试示例

# a.py
from log_conf import Log


log = Log("aaa").getlog()
log.info(f"01: I am a.py")

# b.py
from log_conf import Log


log = Log("bbb").getlog()
log.info(f"01: I am b.py")

# c.py
import a
import b
from log_conf import Log


log = Log("ccc").getlog()
log.info(f"01: I am c.py")

执行 c.py 脚本输出结果