多个python文件调用logging模块报错误
pythonlogging模块主要是python提供的通用日志系统，使用的方法其实挺简单的，这块就不多介绍。下面主要会讲到在使用pythonlogging模块的时候，涉及到多个python文件的调用，而每个文件设置了对应的logging方式不同，可能会产生的令人困惑的现象。
下面以自己在开发的时候遇到的问题作为叙述的背景：
有三个python模块A、B、C。主模块A会importB和C模块，主模块有对应的logging方式，
A使用logging的模块的方式为：
importlogging importlogging.handlers defCreateLogger(logFile='batch'): handler=logging.handlers.RotatingFileHandler(str(logFile)+'.LOG',maxBytes=1024*1024*500,backupCount=5) fmt='%(asctime)s-%(filename)s:%(lineno)s-%(name)s-%(message)s' formatter=logging.Formatter(fmt) handler.setFormatter(formatter) logger=logging.getLogger(str(logFile)) logger.addHandler(handler) logger.setLevel(logging.INFO) returnlogger sLogger=CreateLogger()
其实A模块使用logging的方式很简单，创建一个RotatingFileHandler，通过RotatingFileHandler回滚logging的方式来控制LOG文件的个数和每个LOG文件的上限大小。并创建一个Formatter对象来设置LOG文件的格式。在程序中使用这种方式产生的logging对象来打LOG，很显然使用这种方式的话，LOG都会打印到对应的LOG文件中去。
B使用logging模块的方式为
defGetLogger(testName):
logger=logging.getLogger(testName)
logger.setLevel(logging.INFO)
hdlr=logging.FileHandler(testName+'.LOG')
hdlr.setLevel(logging.INFO)
formatter=logging.Formatter("[%(asctime)s]\t[%(levelname)s]\t[%(thread)d]\t[%(pathname)s:%(lineno)d]\t%(message)s")
hdlr.setFormatter(formatter)
logger.addHandler(hdlr)
returnlogger
logger=GetLogger('OK')
defSetLogger(log):
globallogger
logger=log
B模块默认logging的方式跟A差不多，只是B选择logging的方式是往一个LOG文件中打LOG。A其实在实际使用B模块对应的函数和类的时候并没有直接用B的logging方式，而是对Blogging进行了一个重定向，这个可以从SetLogger函数的作用可以函数。A直接会把已经logging对象传给B，这样B也可以和A共享同一个logging对象，并把LOG打到A设定的文件中。这对于一个主模块调用多个子模块的逻辑、而且每个子模块都有对应的logging使用方式、打到不同文件中进行统一还是挺有好处的，这样可以有效的控制总的LOG文件大小和数量。
但是没有注意C模块，然后发现的情况是，A程序在运行过程中会把A、B模块的LOG信息直接打到屏幕上，而且LOG文件中也有对应的LOG。这些挺让人困惑的，把对B模块的调用注释掉，依然会发现有A的LOG直接打到屏幕上。但是把A程序中设置logging对象的那段代码单独拿出来，一切都正常。
根据当时的情景，只能怀疑是C模块中有什么设置，会导致A、B模块打LOG的方式有些转变。后来意识到，C模块中并没有设置logging的对象，而是直接使用logging.info去打LOG。把这部分的逻辑注释掉，发现A、B打LOG的方式又恢复正常，再也不会往屏幕上打LOG。
通过参阅pythonlogging模块的代码，发现一些有趣的现象：
1.logging对象其实是一个树形结构，每个创建的logging对象都是rootlogging对象的孩子结点。当使用logging模块的getLogger(name=None)函数构造logging对象的时候，如果name为None，这样会产生一个rootlogging对象。如果name中含有.，比如name='a.b.c'，通过这种方式会产生3个logging对象，分别为c、b、a，c->b->a->root，root树的根结点，a为root的孩子结点，b为a的孩子结点，c为a的孩子结点，依次类推。
2.root结点是全局的，虽然这过程中涉及到多个模块，但是它们会共享一个root结点。
3.每个logging对象打LOG的时候，也会把LOG信息传递到传递到上层logging对象中，对于c->b->a->root这种情况，这个LOG其实会打4次，以c、b、a、root循序依次打一个LOG。
可能有人会问，像我之前一般用A模块或者B模块那样的方式去初始化一个logging对象，这样初始化的对象也会是rootlogging对象的一个孩子，而rootlogging对象通常会把LOG打到屏幕上，那按理说，正常情况下打LOG都会打两份，一份会打到文件中，一份会打到屏幕中。那为什么实际情况是，只有LOG文件中有对应的LOG，但是屏幕中并没有对象的显示呢？
其实，如果对这个过程有些好奇，对直接很习以为常的方式有些怀疑，而且抱着这样的好奇心去探索，相信肯定会有更多的收获。
所以，比较困惑的是，为什么我调用A模块产生的sLogger.info打出的LOG，只有LOG文件中有，而rootlogging为什么不打LOG打到屏幕上。为什么rootlogging不起作用。这个时候，可以看下logging__init__.py的代码，会发现，rootlogginginfo的代码如下：
definfo(msg,*args,**kwargs): """ Logamessagewithseverity'INFO'ontherootlogger. """ iflen(root.handlers)==0: basicConfig() root.info(msg,*args,**kwargs)
上面的代码中涉及到root.handlers，怀疑root.handlers跟打LOG的方式有关。因此，printlen(root.handlers)，发现结果为0。也就是说，默认的rootlogging对应的handlers为[]，这样导致的结果是sLogger打LOG的时候，rootlogging并不会打任何LOG。在__main__中添加如下代码：
if__name__=='__main__':
sLogger.info('OK')
printlen(logging.root.handlers),logging.root.handlers
logging.info('Bad')
printlen(logging.root.handlers),logging.root.handlers
运行程序，得到如下运行结果：
0[]
1[
]。
第一行结果为0[]很好的解释了，为什么正常情况下，rootlogging对象为什么没有打出LOG。
而调用logging.info('Bad')之后，root.handlers对象为StreamHandler对象。通过这个程序可以看到调用logging.info对象前后rootlogging对象发生的变化。
还有一点需要验证，就是logging调用前后正常模块logging的方式。
在__main__中写下如下代码：
if__name__=='__main__':
foriinxrange(0,2):
sLogger.info('OK')
logging.info('Bad')
根据之前分析的，第一次调用sLogger.info('OK')是不会打LOG的，而logging.info本身是由于不到WARNING级别，所以也没有打LOG，而第二次会打LOG在屏幕中。所以，看到的结果是，LOG文件中有三条LOG，而屏幕上有一条INFO:batch:OK。跟之前猜想到的挺吻合的。
为什么调用了logging.info之后，会发生如此转变？
继续看完上面rootlogginginfo，并对照着下面的basicConfig代码。会注意到len(root.handlers)==0会去调用basicConfig，这个时候就可以注意下，basicConfig这个模块的实现。
defbasicConfig(**kwargs):
iflen(root.handlers)==0:
filename=kwargs.get("filename")
iffilename:
mode=kwargs.get("filemode",'a')
hdlr=FileHandler(filename,mode)
else:
stream=kwargs.get("stream")
hdlr=StreamHandler(stream)
fs=kwargs.get("format",BASIC_FORMAT)
dfs=kwargs.get("datefmt",None)
fmt=Formatter(fs,dfs)
hdlr.setFormatter(fmt)
root.addHandler(hdlr)
level=kwargs.get("level")
iflevelisnotNone:
root.setLevel(level)
可以看出，当root.handlers的长度为0的时候，会创建一个默认的StreamHandler对象，而这个对象设置的模式导致的情况是LOG会打到屏幕上。这个跟之前打出的logging.root.handlers的结果挺吻合。通过这些想必明白了，为什么我之前遇到的C文件中调用logging.info的方式会影响到上层模块以及其调用的子模块。
通过我遇到的问题，以及对logging的这相关部分的分析，想必会对logging模块有更深刻的认识。最关键的一点，如果想尽可能精确的控制logging方式，一定要注意，主模块以及对应的子模块中具体不要直接使用logging打LOG。
更多关于多个python文件调用logging模块产生错误的问题请查看下面的相关链接
声明：本文内容来源于网络，版权归原作者所有，内容由互联网用户自发贡献自行上传，本网站不拥有所有权，未作人工编辑处理，也不承担相关法律责任。如果您发现有涉嫌版权的内容，欢迎发送邮件至：czq8825#qq.com（发邮件时，请将#更换为@）进行举报，并提供相关证据，一经查实，本站将立刻删除涉嫌侵权内容。