日志输出解惑

日志配置见：

[loggers]
keys=root,idaparser

[handlers]
keys=consoleHandler,fileHandler

[formatters]
keys=simpleFormatter

[formatter_simpleFormatter]
format=[%(asctime)s] - (%(levelname)s) : %(message)s

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_idaparser]
level=DEBUG
handlers=consoleHandler,fileHandler
qualname=idaparser

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=simpleFormatter
args=(sys.stdout,)

[handler_fileHandler]
class=FileHandler
level=INFO
formatter=simpleFormatter
args=('idaparser.log', )

测试代码如下：

# test.py

import logging
import logging.config

logging.config.fileConfig("logging_parser.conf")

#create logger
logger = logging.getLogger("idaparser")

#"application" code
logger.debug("debug message")
logger.info("info message")

logHello = logging.getLogger("hello")
logHello.info("Hello world!")


logchild = logging.getLogger("idaparser.child")
logchild.info("Hello Child!")

其输出为：

[2011-09-08 11:26:16,842] - (DEBUG) : debug message   
[2011-09-08 11:26:16,842] - (DEBUG) : debug message
[2011-09-08 11:26:16,842] - (INFO) : info message
[2011-09-08 11:26:16,842] - (INFO) : info message
[2011-09-08 11:26:16,842] - (INFO) : Hello world!
[2011-09-08 11:26:16,842] - (INFO) : Hello Child!
[2011-09-08 11:26:16,842] - (INFO) : Hello Child!

其中发现每条log输出不等。研究了一下log源码，得到解释如下：

[2011-09-08 11:26:16,842] - (DEBUG) : debug message      ---- logger输出
[2011-09-08 11:26:16,842] - (DEBUG) : debug message      ---- root输出
[2011-09-08 11:26:16,842] - (INFO) : info message           ---- logger输出
[2011-09-08 11:26:16,842] - (INFO) : info message           ---- root输出
[2011-09-08 11:26:16,842] - (INFO) : Hello world!             ---- root输出
[2011-09-08 11:26:16,842] - (INFO) : Hello Child!              ---- logger输出
[2011-09-08 11:26:16,842] - (INFO) : Hello Child!              ---- root输出

其中，每个logger实例输出先通过自身的handlers处理，然后还会交到其父层handlers处理。故出现重复输出情况。 logworld实例默认安全级别为warn，故只有其父层root输出信息。