运行子进程后，logging.StreamHandler() 的级别和格式发生变化

Question

我有一段Python代码，它会一直循环运行。在这个循环里，我会记录一些日志，根据某个条件，我会用subprocess模块来执行一个命令，然后再记录一些日志。大概是这样的：

#!/usr/bin/env python

import logging
import subprocess
import time

TIME_FORMAT = '%a %b %-d %Y %-I:%M:%S %p'
logger = logging.getLogger(__name__)                                                                                                                                                                                                                                                                                
logger.setLevel(logging.DEBUG)                                                  
logformat = '%(asctime)s [%(levelname)s] %(name)s: %(message)s'                 
formatter = logging.Formatter(fmt=logformat, datefmt=TIME_FORMAT)               

file_handler = logging.FileHandler('/path/to/logfile.log')          
file_handler.setLevel(logging.DEBUG)                                            
file_handler.setFormatter(formatter)                                            
logger.addHandler(file_handler)                                                 

console = logging.StreamHandler()                                               
console.setLevel(logging.INFO)                                                  
console.setFormatter(formatter)                                                 
logger.addHandler(console) 

def main():
    if some_condition:
        return_code = subprocess.call(['./some_other_process'])
        if return_code == 0:
            logger.info('Just ran some_other_process')
    else:
        logger.debug('Sleeping for 60 seconds.')
        time.sleep(60)

if __name__ == '__main__':
    main()

当我第一次开始执行这个过程时，我发现输出是正确的；也就是说，日志的内容应该是这样的：

Fri Aug 22 2014 3:35:11 PM [DEBUG] __main__: Sleeping for 60 seconds.

但是一旦调用了subprocess.call，我注意到所有在控制台上的日志（日志文件里的输出是正常的）都变回了默认的样子：

DEBUG:__main__:Sleeping for 60 seconds.

更不用说，我本来不应该在控制台看到调试级别的日志，只应该看到信息级别及以上的日志。

这到底是怎么回事呢？

Answer 1

我不太明白为什么会出现这个问题，但我用类似的方法解决过类似的情况。看起来，getLogger和StreamHandler这两个功能会创建两个不同的StreamHandler。

你可以试试下面的代码：

#!/usr/bin/env python

import logging
import subprocess
import time

TIME_FORMAT = '%a %b %-d %Y %-I:%M:%S %p'
logformat = '%(asctime)s [%(levelname)s] %(name)s: %(message)s'                 
formatter = logging.Formatter(fmt=logformat, datefmt=TIME_FORMAT)               

file_handler = logging.FileHandler('/path/to/logfile.log')          
file_handler.setLevel(logging.DEBUG)                                            
file_handler.setFormatter(formatter)                                            
logging.getLogger('').addHandler(file_handler)                                                 

console = logging.StreamHandler()                                               
console.setLevel(logging.INFO)                                                  
console.setFormatter(formatter)                                                 
logging.getLogger('').addHandler(console) 

def main():
    if some_condition:
        return_code = subprocess.call(['./some_other_process'])
        if return_code == 0:
            logger.info('Just ran some_other_process')
    else:
        logger.debug('Sleeping for 60 seconds.')
        time.sleep(60)

if __name__ == '__main__':
    main()