使用Python Logging记录消息两次

Question

我正在使用Python日志记录,出于某种原因,我的所有消息都出现了两次.

我有一个配置日志记录的模块:

# BUG: It's outputting logging messages twice - not sure why - it's not the propagate setting.
def configure_logging(self, logging_file):
    self.logger = logging.getLogger("my_logger")
    self.logger.setLevel(logging.DEBUG)
    self.logger.propagate = 0
    # Format for our loglines
    formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
    # Setup console logging
    ch = logging.StreamHandler()
    ch.setLevel(logging.DEBUG)
    ch.setFormatter(formatter)
    self.logger.addHandler(ch)
    # Setup file logging as well
    fh = logging.FileHandler(LOG_FILENAME)
    fh.setLevel(logging.DEBUG)
    fh.setFormatter(formatter)
    self.logger.addHandler(fh)

稍后,我调用此方法来配置日志记录:

if __name__ == '__main__':
    tom = Boy()
    tom.configure_logging(LOG_FILENAME)
    tom.buy_ham()

然后说,buy_ham模块,我打电话给:

self.logger.info('Successfully able to write to %s' % path)

由于某种原因,所有消息都出现了两次.我注释掉了一个流处理程序,仍然是一样的.有点怪异,不知道为什么会发生这种情况......哈哈.假设我错过了一些明显的东西.

干杯,维克多

Answer 1

您正在调用configure_logging两次(可能在__init__方法中Boy):getLogger将返回相同的对象,但addHandler不检查是否已将类似的处理程序添加到记录器中.

尝试跟踪对该方法的调用并消除其中一个.或者设置一个在方法中logging_initialized初始化的标志,如果是,则更改为什么都不做,并在初始化记录器后将其设置为.False__init__Boyconfigure_logginglogging_initializedTrueTrue

如果您的程序创建了多个Boy实例,则必须使用configure_logging添加处理程序的全局函数来更改执行操作的方式,并且该Boy.configure_logging方法仅初始化self.logger属性.

另一种解决方法是检查记录器的处理程序属性:

logger = logging.getLogger('my_logger')
if not logger.handlers:
    # create the handlers and call logger.addHandler(logging_handler)

Answer 2

如果你看到这个问题并且你没有两次添加处理程序,那么请在这里查看abarnert的答案

来自文档:

注意:如果将处理程序附加到记录器及其一个或多个祖先,则它可能会多次发出相同的记录.通常,您不需要将处理程序附加到多个记录器 - 如果您只是将其附加到记录器层次结构中最高的相应记录器,那么它将看到所有后代记录器记录的所有事件,前提是它们的传播设置左侧设置为True.常见的情况是仅将处理程序附加到根记录程序,并让传播处理其余部分.

因此,如果您想在"test"上使用自定义处理程序,并且您不希望其消息也转到根处理程序,那么答案很简单:关闭其传播标志:

logger.propagate = False

Answer 3

每次从外部打电话时都会添加处理程序.完成工作后尝试删除处理程序:

self.logger.removeHandler(ch)

Answer 4

我是一个python新手,但这似乎适合我(Python 2.7)

while logger.handlers:
     logger.handlers.pop()

Answer 5

就我而言，我会设置logger.propagate = False为防止重复打印。

在下面的代码中，如果您删除，logger.propagate = False那么您将看到重复打印。

import logging
from typing import Optional

_logger: Optional[logging.Logger] = None

def get_logger() -> logging.Logger:
    global _logger
    if _logger is None:
        raise RuntimeError('get_logger call made before logger was setup!')
    return _logger

def set_logger(name:str, level=logging.DEBUG) -> None:
    global _logger
    if _logger is not None:
        raise RuntimeError('_logger is already setup!')
    _logger = logging.getLogger(name)
    _logger.handlers.clear()
    _logger.setLevel(level)
    ch = logging.StreamHandler()
    ch.setLevel(level)
    # warnings.filterwarnings("ignore", "(Possibly )?corrupt EXIF data", UserWarning)
    ch.setFormatter(_get_formatter())
    _logger.addHandler(ch)
    _logger.propagate = False # otherwise root logger prints things again


def _get_formatter() -> logging.Formatter:
    return logging.Formatter(
        '[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s')

Answer 6

如果您尝试从父文件创建日志记录对象，也可能会发生这种情况。例如，这是主应用程序文件test.py

import logging

# create logger
logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)

# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)

# create formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# add formatter to ch
ch.setFormatter(formatter)

# add ch to logger
logger.addHandler(ch)

def my_code():
# 'application' code
    logger.debug('debug message')
    logger.info('info message')
    logger.warning('warn message')
    logger.error('error message')
    logger.critical('critical message')

下面是父文件main.py

import test

test.my_code()

其输出只会打印一次

2021-09-26 11:10:20,514 - simple_example - DEBUG - debug message
2021-09-26 11:10:20,514 - simple_example - INFO - info message
2021-09-26 11:10:20,514 - simple_example - WARNING - warn message
2021-09-26 11:10:20,514 - simple_example - ERROR - error message
2021-09-26 11:10:20,514 - simple_example - CRITICAL - critical message

但是如果我们有一个父日志记录对象，那么它将被打印两次。例如，如果这是父文件

import test
import logging
logging.basicConfig(level=logging.DEBUG,format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')


test.my_code()

输出将是

2021-09-26 11:16:28,679 - simple_example - DEBUG - debug message
2021-09-26 11:16:28,679 - simple_example - DEBUG - debug message
2021-09-26 11:16:28,679 - simple_example - INFO - info message
2021-09-26 11:16:28,679 - simple_example - INFO - info message
2021-09-26 11:16:28,679 - simple_example - WARNING - warn message
2021-09-26 11:16:28,679 - simple_example - WARNING - warn message
2021-09-26 11:16:28,679 - simple_example - ERROR - error message
2021-09-26 11:16:28,679 - simple_example - ERROR - error message
2021-09-26 11:16:28,679 - simple_example - CRITICAL - critical message
2021-09-26 11:16:28,679 - simple_example - CRITICAL - critical message