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 loggingdef 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
[,  (INFO)>]
[,  (INFO)>, ,  (INFO)>]
[,  (INFO)>, ,  (INFO)>, ,  (INFO)>]
'''

解决方法

方法一

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

  # 示例
  import loggingdef 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
  [,  (INFO)>]
  [,  (INFO)>]
  [,  (INFO)>]
  '''
  

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

方法二

• 每个 Logger 都使用不同的命名

  自定义 logger

  #!/usr/bin/python
  # -*- coding:utf-8 -*-import logging
  import time
  import osclass Log(object):'''封装后的logging'''def __init__(self, logger=None, log_cate='search'):'''指定保存日志的文件路径，日志级别，以及调用文件将日志存入到指定的文件中'''# 创建一个loggerself.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_dirself.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添加handlerself.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 afrom common.log import Loglog = Log(__name__).getlog()
  log.info("I am c.py")# 执行 c.py 脚本输出结果
  [2019-01-14 16:24:12,008] b.py-> line:6 [INFO]I am b.py
  [2019-01-14 16:24:12,009] a.py-> line:6 [INFO]I am a.py
  [2019-01-14 16:24:12,009] c.py-> line:10 [INFO]I am c.py
  

方法三

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

  import loggingdef 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 osclass Log(object):'''
  封装后的logging'''def __init__(self, logger=None, log_cate='search'):'''指定保存日志的文件路径，日志级别，以及调用文件将日志存入到指定的文件中'''# 创建一个loggerself.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_dirself.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添加handlerself.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_loggerlog = concurrent_logger.getlog()
  log.info(f"01: I am a.py")# b.py
  from log_conf import concurrent_loggerlog = concurrent_logger.getlog()
  log.info(f"01: I am b.py")# c.py
  import a
  import b
  from log_conf import concurrent_loggerlog = concurrent_logger.getlog()
  log.info(f"01: I am c.py")# 执行 c.py 脚本输出结果
  [2022-11-16 17:10:35,034] a.py-> line:7 [INFO]01: I am a.py
  [2022-11-16 17:10:35,035] b.py-> line:7 [INFO]01: I am b.py
  [2022-11-16 17:10:35,035] c.py-> line:9 [INFO]01: I am c.py
  

方法五

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

  自定义 logger

  #!/usr/bin/python
  # -*- coding:utf-8 -*-import logging
  import time
  import osclass Log(object):'''封装后的logging'''def __init__(self, logger=None, log_cate='search'):'''指定保存日志的文件路径，日志级别，以及调用文件将日志存入到指定的文件中'''# 创建一个loggerself.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 = loggerself.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添加handlerself.logger.addHandler(fh)self.logger.addHandler(ch)# 关闭打开的文件fh.close()ch.close()def getlog(self):return self.logger
  

  测试示例

  # a.py
  from log_conf import Loglog = Log("aaa").getlog()
  log.info(f"01: I am a.py")# b.py
  from log_conf import Loglog = Log("bbb").getlog()
  log.info(f"01: I am b.py")# c.py
  import a
  import b
  from log_conf import Loglog = Log("ccc").getlog()
  log.info(f"01: I am c.py")
  

  执行 c.py 脚本输出结果