flask 解决日志重复打印问题 or Python日志重复打印
背景:业务代码上线后,莫名会重复输出很多相同的日志,已知以为是多线程问题,后仔细了解期logging原理后发现并非如此。
以下为解决方案
from flask import Flask as _Flask from flask.helpers import locked_cached_property from flask.logging import has_level_handler, default_handler def create_MyLogger(app: "Flask") -> logging.Logger: """Get the Flask app's logger and configure it if needed. The logger name will be the same as :attr:`app.import_name <flask.Flask.name>`. When :attr:`~flask.Flask.debug` is enabled, set the logger level to :data:`logging.DEBUG` if it is not set. If there is no handler for the logger's effective level, add a :class:`~logging.StreamHandler` for :func:`~flask.logging.wsgi_errors_stream` with a basic format. """ # logger = logging.getLogger(app.name) # 防止重复打印 logger = logging.getLogger(uuid.uuid1().hex) if app.debug and not logger.level: logger.setLevel(logging.DEBUG) if not has_level_handler(logger) : logger.addHandler(default_handler) return logger class Flask(_Flask): """ 将重新的方法进行注册 """ @locked_cached_property def logger(self) -> logging.Logger: """A standard Python :class:`~logging.Logger` for the app, with the same name as :attr:`name`. In debug mode, the logger's :attr:`~logging.Logger.level` will be set to :data:`~logging.DEBUG`. If there are no handlers configured, a default handler will be added. See :doc:`/logging` for more information. .. versionchanged:: 1.1.0 The logger takes the same name as :attr:`name` rather than hard-coding ``"flask.app"``. .. versionchanged:: 1.0.0 Behavior was simplified. The logger is always named ``"flask.app"``. The level is only set during configuration, it doesn't check ``app.debug`` each time. Only one format is used, not different ones depending on ``app.debug``. No handlers are removed, and a handler is only added if no handlers are already configured. .. versionadded:: 0.3 """ return create_MyLogger(self)
重复打印的原因 参考 http://static.kancloud.cn/noahs/python/932418
问题起源:
在学习了python的函数式编程后,又接触到了logging这样一个强大的日志模块。为了减少重复代码,应该不少同学和我一样便迫不及待的写了一个自己的日志函数,比如下面这样:
# 这里为了便于理解,简单的展示了一个输出到屏幕的日志函数
def my_log():
logger = logging.getLogger('mysql.log')
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(fmt)
logger.addHandler(ch)
return logger
my_log().error('run one')
my_log().error('run two')
my_log().error('run three')
函数写好了,看起来似乎也没有问题,我们来运行一下!
结果如下:
> 2018-06-21 13:06:37,569 - mysql.log - ERROR - run one
> 2018-06-21 13:06:37,569 - mysql.log - ERROR - run two
> 2018-06-21 13:06:37,569 - mysql.log - ERROR - run two
> 2018-06-21 13:06:37,569 - mysql.log - ERROR - run three
> 2018-06-21 13:06:37,569 - mysql.log - ERROR - run three
> 2018-06-21 13:06:37,569 - mysql.log - ERROR - run three
日志居然重复输出了,且数量递增。
问题解析
-
实际上
logger = logging.getLogger('mysql.log')
在执行时,没有每次生成一个新的logger,而是先检查内存中是否存在一个叫做‘mysql.log’的logger对象,存在则取出,不存在则新建。 -
实例化的logger对象具有‘handlers’这样一个属性来存储 Handler,代码演示如下:
def my_log(): logger = logging.getLogger('mysql.log') # 每次被调用后打印出logger的handlers列表 print(logger.handlers) ch = logging.StreamHandler() ch.setLevel(logging.ERROR) fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') ch.setFormatter(fmt) logger.addHandler(ch) return logger my_log().error('run one') my_log().error('run two') my_log().error('run three')
运行结果:
> \[\] > 2018-06-21 13:26:14,059 - mysql.log - ERROR - run one > \[ (ERROR)>\] > 2018-06-21 13:26:14,060 - mysql.log - ERROR - run two > 2018-06-21 13:26:14,060 - mysql.log - ERROR - run two > \[ (ERROR)>, (ERROR)>\] > 2018-06-21 13:26:14,060 - mysql.log - ERROR - run three > 2018-06-21 13:26:14,060 - mysql.log - ERROR - run three > 2018-06-21 13:26:14,060 - mysql.log - ERROR - run three
logger.handlers
最初是一个空列表,执行‘logger.addHandler(ch)’添加一个‘StreamHandler’,输出一条日志- 在第二次被调用时,
logger.handlers
已经存在一个‘StreamHandler’,再次执行‘logger.addHandler(ch)’就会再次添加一个‘StreamHandler’,此时的logger有两个个‘StreamHandler’,输出两条重复的日志 - 在第三次被调用时,
logger.handlers
已经存在两个‘StreamHandler’,再次执行‘logger.addHandler(ch)’就会再次添加一个,此时的logger有三个‘StreamHandler’,输出三条重复的日志
解决办法
1.改名换姓
# 为日志函数添加一个name,每次调用时传入不同的日志名
def my_log(name):
logger = logging.getLogger(name)
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(fmt)
logger.addHandler(ch)
return logger
my_log('log1').error('run one')
my_log('log2').error('run two')
my_log('log3').error('run three')
运行结果:
> 2018-06-21 13:40:51,685 - log1 - ERROR - run one
> 2018-06-21 13:40:51,685 - log2 - ERROR - run two
> 2018-06-21 13:40:51,685 - log3 - ERROR - run three
2.及时清理(logger.handlers.clear)
def my_log():
logger = logging.getLogger()
# 每次被调用后,清空已经存在handler
logger.handlers.clear()
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(fmt)
logger.addHandler(ch)
return logger
my_log().error('run one')
my_log().error('run two')
my_log().error('run three')
3.用前判断
import logging
def my_log():
logger = logging.getLogger('mysql.log')
# 判断logger是否已经添加过handler,是则直接返回,否则才执行
if not logger.handlers:
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(fmt)
logger.addHandler(ch)
return logger
my_log().error('run one')
my_log().error('run two')
my_log().error('run three')
综上,解决方法可以参照上诉三种在 create_MyLogger 函数中实现即可。