问题背景&现象

最近在项目中，需要用python的logging库来将日志打印到文件中,然后将python脚本放到crontab中执行。所以写了一个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)

        #  添加下面一句，在记录日志之后移除句柄
        # self.logger.removeHandler(ch)
        # self.logger.removeHandler(fh)
        # 关闭打开的文件
        fh.close()
        ch.close()

    def getlog(self):
        return self.logger

目的是让所有用到logger的地方，只import这个封装库就行，然后直接调用。比如调用logger的a.py

#!/usr/bin/python
# -*- coding:utf-8 -*-
from common.log import Log
log = Log().getlog()
log.info("I am a.py")

b.py

#!/usr/bin/python
# -*- coding:utf-8 -*-
from common.log import Log
log = Log().getlog()
log.info("I am b.py")

c.by

#!/usr/bin/python
# -*- coding:utf-8 -*-
import a
import b
from common.log import Log
log = Log().getlog()
log.info("I am c.py")

此时执行c.py的结果如下：

➜  search git:(master) ✗ python c.py
[2019-01-14 15:58:35,807] a.py-><module> line:6 [INFO]I am a.py
[2019-01-14 15:58:35,808] b.py-><module> line:6 [INFO]I am b.py
[2019-01-14 15:58:35,808] b.py-><module> line:6 [INFO]I am b.py
[2019-01-14 15:58:35,809] c.py-><module> line:8 [INFO]I am c.py
[2019-01-14 15:58:35,809] c.py-><module> line:8 [INFO]I am c.py
[2019-01-14 15:58:35,809] c.py-><module> line:8 [INFO]I am c.py

可见，a.py, b.py,c.py的logger共用了，出现了重复打印。

问题原因分析

从现象可以得出，不同文件间的log系统是相互影响的，在a.py，b.py, c.py中，我们的调用方式是log = Log().getlog(), 即self.logger = logging.getLogger(logger),logger参数并未传递 , 所以得到的self.logger是RootLogger。
RootLogger是一个python程序内全局唯一的，所有Logger对象的祖先。所以我们对RootLogger的设定，自然会影响到所有的日志输出。简言之，就是先打开的文件中对log的设置，后打开的文件都会受到影响,都会走一遍logger的继承关系。在这个示例中，b.py在a.py之后被import, 所以b.py会执行一次自己的logger，再执行一次a.py中打开的RootLogger, 以此类推.........

问题解决方式

不用默认的RootLogger, 给每个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的最新执行结果：

➜  search git:(master) ✗ python 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

没有重复了，符合预期。问题得以解决。

参考资料

• [python]多个文件共用日志系统的重复打印问题
• python的logging 模块浅析