python - 子记录器的日志显示两次

Question

我无法使用 python 的标准 logging 正确记录我的模块。然而，这是一个非常简单的案例。我有以下模块层次结构:

module\
  foo.py
  bar.py

我需要使用以下约束从这些模块中的每一个进行登录:

1. 所有日志 >= INFO 从 module.foo 到控制台(因为这个模块所做的很重要，必须实时通知用户)
2. module.* 中的所有日志到一个文件中
3. 所有日志 >= WARNING 从 module.* 到控制台

这里是主要代码

import logging
import logging.config
import os
import yaml

def setup_logging():
    loadfrom = os.path.join(os.path.dirname(__file__), 'config.yml')
    # Load
    with open(loadfrom, 'rt') as f:
        config = yaml.safe_load(f.read())
    logging.config.dictConfig(config)

setup_logging()

foo = logging.getLogger('module.foo')
bar = logging.getLogger('module.bar')

foo.info('module.foo doing something')
foo.debug('module.foo debug data')

bar.info('module.bar doing something')
bar.error('module.bar something bad happened')

这是我正在使用的配置

version: 1
disable_existing_loggers: False
formatters:
    simple:
        format: "%(asctime)s - %(name)s - %(levelname)s - %(message)s"

handlers:
    console:
        class: logging.StreamHandler
        level: INFO
        formatter: simple
        stream: ext://sys.stdout
    file:
        class: logging.handlers.RotatingFileHandler
        level: DEBUG
        filename: 'log.log'
        formatter: simple
        encoding: utf8

loggers:
  module:
    level: WARNING
    handlers: [console]
    propagate: yes
  module.foo:
    level: INFO
    handlers: [console]
    propagate: yes # If yes, gets displayed twice. If false, entry is missing in log file
root:
    level: DEBUG
    handlers: [file]

这是输出:

2017-09-21 10:48:39,679 - module.foo - INFO - module.foo doing something
2017-09-21 10:48:39,679 - module.foo - INFO - module.foo doing something
2017-09-21 10:48:39,681 - module.bar - ERROR - module.bar something bad happened

子模块中的 log.info 显示两次，因为 propagate 字段在配置中设置为 yes。将其设置为 false 可解决控制台中的问题，但会破坏日志文件，因为其中缺少该条目。

我该如何解决这个问题？我个人认为违反直觉的标准库的任何替代品？

编辑 1

@wmorell 回答后的新配置:

handlers:
    console:
        class: logging.StreamHandler
        level: INFO
        formatter: simple
        stream: ext://sys.stdout
    file:
        class: logging.handlers.RotatingFileHandler
        level: DEBUG
        filename: 'log.log'
        formatter: simple
        encoding: utf8

loggers:
  module:
    level: WARNING
    handlers: [console]
    propagate: yes
  module.foo:
    level: DEBUG    <- set this to debug
    handlers: [file, console] <- Add file here
    propagate: false
root:
    level: DEBUG
    handlers: [file]

控制台输出正常:

2017-09-21 11:14:51,174 - module.foo - INFO - module.foo doing something
2017-09-21 11:14:51,174 - module.bar - ERROR - module.bar something bad happened

日志输出不正常，错过了对 log.info('module.bar') 的调用:

2017-09-21 11:18:34,335 - module.foo - INFO - module.foo doing something
2017-09-21 11:18:34,335 - module.foo - DEBUG - module.foo debug data
2017-09-21 11:18:34,335 - module.bar - ERROR - module.bar something bad happened

Answer 1

将 file 处理程序显式添加到记录器定义中，然后复制 console 处理程序以过滤不同的日志级别:

handlers:
  console_info:
    class: logging.StreamHandler
    level: INFO
    formatter: simple
    stream: ext://sys.stdout
  console_warning:
    class: logging.StreamHandler
    level: WARNING
    formatter: simple
    stream: ext://sys.stdout
  file:
    class: logging.handlers.RotatingFileHandler
    level: DEBUG
    filename: 'log.log'
    formatter: simple
    encoding: utf8
loggers:
  module:
    level: DEBUG
    handlers: [file, console_warning]
    propagate: false
  module.foo:
    level: DEBUG
    handlers: [file, console_info]
    propagate: false

日志首先在记录器定义处被过滤，因此 module 和 module.foo 记录器必须允许 DEBUG 如果要实现的话到日志文件。然后记录器将消息转发给所有处理程序，处理程序可以将消息丢弃到其配置的阈值以下；所以你需要一个处理程序来删除基本 module 记录器的 INFO 日志，以及一个允许 INFO 日志的处理程序用于更具体的 module.foo 记录器。