Python logging模块继承逻辑

0X00 起因

在使用一个第三方库时，在我定义的日志文件中一直有额外的日志输出，于是开始了DEBUG之路。

涉及到的相关知识：logger的继承关系、handler继承、basicConfig、导入另一个模块且该模块包含logger会引发什么现象

0X01 DEMO

可能起因中的话并不能很清晰的描述我到底碰到了什么情况，所以直接上代码，给几个DEMO，大伙可以分析分析代码的日志会怎么输出，输出到哪个文件，如果全部分析正确了，那么说明相关知识已经掌握了。如果分析不出来，那么就还没有弄清楚相关细节。以两个py文件为例，a.py和b.py，我们直接运行b.py，因为在b中会import a。

1.

a.py:

from logging.handlers import RotatingFileHandler
import logging


a_logger = logging.getLogger(__name__)
a_logger.setLevel(logging.WARNING)
formatter = logging.Formatter('%(asctime)s %(levelname)s [%(lineno)d]: %(message)s')
update_debug = RotatingFileHandler('./a.log', maxBytes=20*1024*1024, backupCount=5)
update_debug.setFormatter(formatter)
a_logger.addHandler(update_debug)

a_logger.warning('log from a')

b.py:

import logging
import a


logging.basicConfig(
    filemode='a',
    filename='./b.log'
)

logging.warning('log from b')

结果：a.log中记录log from a，b.log中记录log from b

2.

a.py:

from logging.handlers import RotatingFileHandler
import logging


a_logger = logging.getLogger(__name__)
a_logger.setLevel(logging.WARNING)
formatter = logging.Formatter('%(asctime)s %(levelname)s [%(lineno)d]: %(message)s')
update_debug = RotatingFileHandler('./a.log', maxBytes=20*1024*1024, backupCount=5)
update_debug.setFormatter(formatter)
a_logger.addHandler(update_debug)

a_logger.warning('log from a')

b.py:

import logging


logging.basicConfig(
    filemode='a',
    filename='./b.log'
)

logging.warning('log from b')

import a

结果：a.log中记录了log from a，b.log中先记录了log from b，再记录了log from a。

3.

a.py:

from logging.handlers import RotatingFileHandler
import logging


a_logger = logging.getLogger(__name__)
a_logger.setLevel(logging.WARNING)
formatter = logging.Formatter('%(asctime)s %(levelname)s [%(lineno)d]: %(message)s')
update_debug = RotatingFileHandler('./a.log', maxBytes=20*1024*1024, backupCount=5)
update_debug.setFormatter(formatter)
a_logger.addHandler(update_debug)


def func():
    a_logger.warning('log from a')

b.py:

import logging
import a


logging.basicConfig(
    filemode='a',
    filename='./b.log'
)

logging.warning('log from b')

a.func()

结果：a.log记录了log from a，b.log先记录了log from b，再记录了log from a

4.究极折磨

a.py:

import logging


logging.basicConfig(
    filemode='a',
    filename='./a.log'
)

a_logger = logging.getLogger(__name__)
a_logger.warning('log from a')

b.py:

import logging
import a


logger = logging.getLogger()
logger.warning('log from b')

结果：a.log先记录了log from a，再记录了log from b

0X02 分析

关于logging模块有几个重要的知识点，掌握之后，便可以很好的分析日志究竟是怎么记录的了

        1.默认情况下logger分为root logger和其他logger，basicConfig配置的就是root logger，创建的其他logger会自动继承于root logger，并且在调用其他logger记录日志时，会先调用logger自身配置的handler，然后调用父亲的handler。有点绕，给个例子：

import logging

#  设置root logger的handler为FileHandler，以a的模式将日志追加到a.log中
logging.basicConfig(
    filemode='a',
    filename='./a.log'
)

#  获取一个__name__的logger，该logger自动继承于root logger，并且该logger在日志记录时
#  先会调用自身的handler，然后调用root logger的handler。在此处logger并未设置handler，所以
#  只会调用root logger的handler，也就会将日志记录到a.log中了
a_logger = logging.getLogger(__name__)
a_logger.warning('log from a')

        2.当导入的模块中定义了logger时，并且在最外层就进行了日志记录，那么在导入之后就会直接记录日志，因为python导入模块会将模块外层代码执行。参考00X1 DEMO中的1和2两个例子，先import a和后import a的日志记录情况是不同的。那么如何规避这种情况了，那就是在函数中进行日志记录，那么只有在调用该函数时才会记录日志，import模块时不会记录。

        3.如何让每个logger只调用自己的handler，不要去调用父类的handler？添加一个配置即可：

logger.propagate = False

        4.创建的logger默认只会继承root logger，两个同级logger并不会自动产生继承关系，除非手动指定，例如：

import logging


a_logger = logging.getLogger('a')
b_logger = logging.getLogger('b')
print a_logger.parent
print b_logger.parent

a_logger和b_logger的parent都为logging.RootLogger object

    5.当你的模块需要被别人导入使用时，最好不要在你的模块中设置root logger的配置，否则会使日志记录混乱，或者加上propagate参数。