简单python日志配置中的重复输出

Question

我设置python日志如下：

def setup_logging():
    loggers = (logging.getLogger("amcat"), logging.getLogger("scrapers"),logging.getLogger(__name__))
    filename = "somefile.txt"
    sys.stderr = open(filename, 'a')
    handlers = (logging.StreamHandler(sys.stdout),logging.FileHandler(filename))
    formatter = AmcatFormatter(date = True)

    for handler in handlers:
        handler.setLevel(logging.INFO)
        handler.setFormatter(formatter)

    for logger in loggers:
        logger.propagate = False
        logger.setLevel(logging.INFO)
        for handler in handlers:        
            logger.addHandler(handler)
    logging.getLogger().handlers = []

启用了两个主要的模块记录器，它们都应该记录到控制台以及一个文件。错误被重定向到文件（理想情况下，错误也会显示在控制台中，但我还没有实现）

然后，我检查事情是否正确：

should_work = [
    "amcat.scraping.scraper",
    "amcat.scraping.htmltools",
    "amcat.scraping.controller",
    "__main__"]

loggerdict = logging.Logger.manager.loggerDict #all loggers
for name, logger in loggerdict.items():
    if name in should_work:
        print("\nlogger: "+name)
        #iterate through parents see if effective handlers are set correctly
        print(effectivehandlers(logger))
        #test logger
        logger.info("test for {name}".format(**locals()))

def effectivehandlers(logger):
    handlers = logger.handlers
    while True:
        logger = logger.parent
        handlers.extend(logger.handlers)
        if not (logger.parent and logger.propagate):
            break
    return handlers

控制台输出：

logger: __main__
[<logging.StreamHandler object at 0x3425d50>, <logging.FileHandler object at 0x3425dd0>]
[2013-10-24 10:27:30 daily.py:133 INFO] test for __main__

logger: amcat.scraping.controller
[<logging.StreamHandler object at 0x3425d50>, <logging.FileHandler object at 0x3425dd0>]
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.controller
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.controller

logger: amcat.scraping.htmltools
[<logging.StreamHandler object at 0x3425d50>, <logging.FileHandler object at 0x3425dd0>]
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.htmltools
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.htmltools

logger: amcat.scraping.scraper
[<logging.StreamHandler object at 0x3425d50>, <logging.FileHandler object at 0x3425dd0>]
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.scraper
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.scraper

这里是文件输出：

[2013-10-24 10:27:30 daily.py:133 INFO] test for __main__
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.controller
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.controller
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.htmltools
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.htmltools
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.scraper
[2013-10-24 10:27:30 daily.py:133 INFO] test for amcat.scraping.scraper

如您所见，尽管已禁用传播并确保不存在重复的处理程序，但输出是双精度的。哪里出了问题？

Answer 1

基本上，当您的一个子记录器显示一条消息时，它会在层次结构中向后移动，而父记录器也会记录相同的内容。

要取消该行为，可以添加以下内容：

logger.propagate = False

当它打到孩子的时候，它不会打到家长。

这里有一些关于这种行为的documentation。

Answer 2

对于Python2.7

logging.handlers.pop()

用户“radtek”引用： Python Logging - Messages appearing twice

Answer 3

我想出来了，谢谢帕科指引我正确的方向

原来，当调用getLogger时，会向其添加处理程序：

>>> print(effectivehandlers(logger))
[<logging.StreamHandler object at 0x305ad90>, <logging.FileHandler object at 0x305ae10>]
>>> logging.getLogger(name) #the same logger
<logging.Logger object at 0x7fa08fb9b2d0>
>>> print(effectivehandlers(logger))
[<logging.StreamHandler object at 0x305ad90>, <logging.FileHandler object at 0x305ae10>, <logging.StreamHandler object at 0x305ad90>, <logging.FileHandler object at 0x305ae10>]

现在，子对象和父对象都有相同的处理程序。因此重复输出。