python logger 打印多次的问题与解决方案

学习 Python 不久碰到过这个问题, 记得当时没查出是什么问题. 刚刚无意中发现了这个问题的原因及解决方案, 记录一下.

参考:
https://juejin.im/post/5bc2bd3a5188255c94465d31

第一种情况

参考文章中介绍说产生这个问题的原因是因为创建了自定义的 Logger 对象后, 又使用了 logging 中的日志输出方法，这些方法使用的是默认配置的 Logger 对象，导致之后输出的日志信息会重复。

示例代码:

import logging

# 日志管理
logger = logging.getLogger('logger')
logger.setLevel(logging.DEBUG)
formatter = logging.Formatter('%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s')
# 输出到控制台的log
sh = logging.StreamHandler()
sh.setLevel(logging.DEBUG)
sh.setFormatter(formatter)
logger.addHandler(sh)

logger.debug('a debug message')
logger.info('a info message')
logger.warning('a warning message')
logging.error('a error message')
logger.critical('a critical message')

打印结果如下:

2019-07-17 09:42:29,336 spider.py[line:92] DEBUG a debug message
2019-07-17 09:42:29,336 spider.py[line:93] INFO a info message
2019-07-17 09:42:29,336 spider.py[line:94] WARNING a warning message
ERROR:root:a error message
2019-07-17 09:42:29,336 spider.py[line:96] CRITICAL a critical message
CRITICAL:logger:a critical message
[Finished in 0.6s]

可以看到从 error message 开始出现格式异常, 之后下一条 message 开始重复打印. 之后每一条 log 都会打印出两次. 去掉使用 logging 的日志输出方法后则打印正常.

第二种情况

封装了 logger 到文件后在其他文件 import 引用这个 logger . 却又在文件中创建了新的 logger . 如下:

封装了 logger 的 base_utils:

import configparser
import logging
import time
import os

# 配置文件管理
confLoad = configparser.ConfigParser()
confLoad.read('./spider.conf')

# 日志管理
logger = logging.getLogger('logger')
logger.setLevel(logging.DEBUG)
formatter = logging.Formatter('%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s')
# 输出到log目录下的当日log文件
log_dir = confLoad.get('logger','LOG_DIR')
if not os.path.exists(log_dir):
    os.makedirs(log_dir)
logFile = log_dir + time.strftime("%Y-%m-%d", time.localtime()) + ".log"
fh = logging.FileHandler(logFile, encoding='utf-8')
fh.setLevel(int(confLoad.get('logger','LOGFILE_LEVEL')))
fh.setFormatter(formatter)
# 输出到控制台的log
sh = logging.StreamHandler()
sh.setLevel(int(confLoad.get('logger','CONSOLE_LEVEL')))
sh.setFormatter(formatter)
logger.addHandler(fh)
logger.addHandler(sh)

配置文件 spider.conf :

# mongodb
[mongodb]
DB_MONGO_HOST=192.168.0.101
DB_MONGO_PORT=27017
DB_MONGO_DATABASE=spider
DB_MONGO_USERNAME=
DB_MONGO_PASSWORD=

[logger]
LOG_DIR = ./log/

# CRITICAL = 50
# FATAL = CRITICAL
# ERROR = 40
# WARNING = 30
# WARN = WARNING
# INFO = 20
# DEBUG = 10
# NOTSET = 0

CONSOLE_LEVEL = 10
LOGFILE_LEVEL = 10

在文件 spider.py 中引用:

from base_utils import logger

if __name__ == "__main__":
	# 如果在此文件中再次创建 logger, 会产生两个 logger 对象, 使 log 打印 2 次
    logger = logging.getLogger('logger')
    logger.setLevel(logging.DEBUG)
    formatter = logging.Formatter('%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s')
	sh = logging.StreamHandler()
    sh.setLevel(logging.DEBUG)
    sh.setFormatter(formatter)
    logger.addHandler(sh)

	logger.debug('a debug message')
    logger.info('a info message')
    logger.warning('a warning message')
    logger.error('a error message')
    logger.critical('a critical message')

打印结果如下:

2019-07-17 10:01:21,969 spider.py[line:93] DEBUG a debug message
2019-07-17 10:01:21,969 spider.py[line:93] DEBUG a debug message
2019-07-17 10:01:21,970 spider.py[line:94] INFO a info message
2019-07-17 10:01:21,970 spider.py[line:94] INFO a info message
2019-07-17 10:01:21,970 spider.py[line:95] WARNING a warning message
2019-07-17 10:01:21,970 spider.py[line:95] WARNING a warning message
2019-07-17 10:01:21,971 spider.py[line:96] ERROR a error message
2019-07-17 10:01:21,971 spider.py[line:96] ERROR a error message
2019-07-17 10:01:21,971 spider.py[line:97] CRITICAL a critical message
2019-07-17 10:01:21,971 spider.py[line:97] CRITICAL a critical message
[Finished in 0.6s]

可以看到 log 打印了 2 次, 同样的要避免这样子使用.