当前位置： 文江博客话题详情

使用 Python Logging 记录出现两次的消息

发布于 2024-11-24 03:55:03 字数 1140 浏览 1 评论 0原文

我正在使用 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)

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

原文

I'm using Python logging, and for some reason, all of my messages are appearing twice.

I have a module to configure logging:

# 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)

Later on, I call this method to configure logging:

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

And then within say, the buy_ham module, I'd call:

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

And for some reason, all the messages are appearing twice. I commented out one of the stream handlers, still the same thing. Bit of a weird one, not sure why this is happening. I'm assuming I've missed something obvious.

如果你对这篇内容有疑问，欢迎到本站社区发帖提问 参与讨论，获取更多帮助，或者扫码二维码加入 Web 技术交流群。

扫码二维码加入Web技术交流群

发布评论

需要 登录 才能够评论， 你可以免费 注册 一个本站的账号。

评论（19）

￡冰雨忧蓝° 2024-12-01 03:55:05

我遇到了一种奇怪的情况，控制台日志加倍，但我的文件日志却没有。经过大量挖掘后，我明白了。

请注意，第三方软件包可以注册记录器。这是需要注意的事情（在某些情况下是无法避免的）。在许多情况下，第三方代码会检查是否存在任何现有的root记录器处理程序；如果没有，他们会注册一个新的控制台处理程序。

我的解决方案是在根级别注册我的控制台记录器：

rootLogger = logging.getLogger()  # note no text passed in--that's how we grab the root logger
if not rootLogger.handlers:
        ch = logging.StreamHandler()
        ch.setLevel(logging.INFO)
        ch.setFormatter(logging.Formatter('%(process)s|%(levelname)s] %(message)s'))
        rootLogger.addHandler(ch)

I was getting a strange situation where console logs were doubled but my file logs were not. After a ton of digging I figured it out.

Please be aware that third party packages can register loggers. This is something to watch out for (and in some cases can't be prevented). In many cases third party code checks to see if there are any existing root logger handlers; and if there isn't--they register a new console handler.

My solution to this was to register my console logger at the root level:

rootLogger = logging.getLogger()  # note no text passed in--that's how we grab the root logger
if not rootLogger.handlers:
        ch = logging.StreamHandler()
        ch.setLevel(logging.INFO)
        ch.setFormatter(logging.Formatter('%(process)s|%(levelname)s] %(message)s'))
        rootLogger.addHandler(ch)
回复 原文
浪漫人生路 2024-12-01 03:55:05

如果您使用任何配置进行日志记录，例如 log.conf

在 .conf 文件中，您可以通过在 [logger_myLogger] 部分中添加以下行来实现： 传播=0

[logger_myLogger]
level=DEBUG
handlers=validate,consoleHandler
qualname=VALIDATOR
propagate=0

If you are using any config for logging, For instance log.conf

In .conf file you can do it by adding this line in the [logger_myLogger] section: propagate=0

[logger_myLogger]
level=DEBUG
handlers=validate,consoleHandler
qualname=VALIDATOR
propagate=0
回复 原文
时光倒影 2024-12-01 03:55:05

如果您使用标准构造logger =logging.getLogger('mymodule')，然后不小心将logger输入为logging，即

logger = logging.getLogger('mymodule')

# configure your handlers

logger.info("my info message")  # won't make duplicate 
logging.info("my info message")  # will make duplicate logs

这将导致重复由于调用 logging 创建了一个新的记录器，因此会出现消息。

If you use the standard construction logger = logging.getLogger('mymodule') and then accidentally mistype loggger as logging i.e.

logger = logging.getLogger('mymodule')

# configure your handlers

logger.info("my info message")  # won't make duplicate 
logging.info("my info message")  # will make duplicate logs

then this will cause duplicate messages to come up because the call to logging creates a new logger.

回复 原文
鱼窥荷 2024-12-01 03:55:05

我有同样的问题。就我而言，这不是由于处理程序或重复的初始配置，而是由于一个愚蠢的拼写错误。在 main.py 中，我使用了 logger 对象，但在 my_tool.py 中，我直接调用了 logging模块错误，因此在从 my_tool 模块调用函数后，一切都变得混乱并且消息看起来重复。

这是代码：

main.py

import logging
import my_tool

logger_name = "cli"
logger = logging.getLogger(logger_name)

logger.info("potato")
logger.debug("potato)
my_tool.function()
logger.info("tomato")

my_tool.py

import logging
logger_name = "cli"
logger = logging.getLogger(logger_name)
# some code
logging.info("carrot")

和结果

terminal

>> potato
>> potato
>> carrot
>> tomato
>> tomato

I had the same issue. In my case, it was not due to handlers or duplicate initial configuration but a stupid typo. In main.py I was using a logger object but in my_tool.py I was directly calling to the logging module by mistake, hence after invoking functions from my_tool module everything was messed up and the messages appeared duplicated.

This was the code:

main.py

import logging
import my_tool

logger_name = "cli"
logger = logging.getLogger(logger_name)

logger.info("potato")
logger.debug("potato)
my_tool.function()
logger.info("tomato")

my_tool.py

import logging
logger_name = "cli"
logger = logging.getLogger(logger_name)
# some code
logging.info("carrot")

and the result

terminal

>> potato
>> potato
>> carrot
>> tomato
>> tomato
回复 原文
碍人泪离人颜 2024-12-01 03:55:05

就我而言，我看到 INFO 日志消息两次，因为我在 Bottle 实例的 run() 调用中使用了 reloader=True 。

语境：

def run(app=None, server='wsgiref', host='127.0.0.1', port=8080,
        interval=1, reloader=False, quiet=False, plugins=None,
        debug=None, **kargs):

In my case I saw the INFO log message twice because I used reloader=True in the run() call of the bottle instance.

Context:

def run(app=None, server='wsgiref', host='127.0.0.1', port=8080,
        interval=1, reloader=False, quiet=False, plugins=None,
        debug=None, **kargs):
回复 原文
晚风撩人 2024-12-01 03:55:05

值得注意的是，如果您使用 Django 及其 runserver 命令，并且还运行自动重新加载功能（如果 DEBUG 设置为 true，则会自动发生），您将看到两次输出，因为自动重新加载进程还会初始化第二次应用程序。要解决此问题，您可以执行runserver --noreload，或者：为什么在 Django 开发服务器中 run 被调用两次？

Worth noting, if you're using Django and its runserver command, if you are also running the auto reload feature (which will happen automatically if DEBUG is set to true), you will see the output twice, because the autoreloader process also initializes the app a second time. To fix this you can do runserver --noreload, or: Why is run called twice in the Django dev server?

回复 原文
亣腦蒛氧 2024-12-01 03:55:05

我遇到了同样的问题，有一个简单的方法可以解决这个问题。在自定义日志文件中，添加此行

print('adding log handler from '+__name__)

现在，当应用程序初始化时，您将看到两行显示重复的导入。问题是我以两种不同的方式导入模块

from base_pkg.module_pkg.app_logger import log

并将

from module_pkg.app_logger import log

所有内容更改为从 base_pkg 导入，问题就解决了。

I had the same issue, and there is an easy way to fix this. In the custom log file, add this line

print('adding log handler from '+__name__)

Now, when the application initializes, you will see two lines showing the imports where it is getting duplicated. The issue was that I was importing the module in two different ways

from base_pkg.module_pkg.app_logger import log

and

from module_pkg.app_logger import log

Change everything to import from base_pkg and the issue was solved.

回复 原文
戏蝶舞 2024-12-01 03:55:04

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

尝试跟踪对该方法的调用并消除其中之一。或者在Boy的__init__方法中设置一个标志logging_initialized初始化为False，并更改configure_logging< /code> 如果 logging_initialized 为 True 则不执行任何操作，并在初始化记录器后将其设置为 True。

如果您的程序创建了多个 Boy 实例，则必须使用添加处理程序的全局 configure_logging 函数以及 Boy.configure_logging 方法仅初始化 self.logger 属性。

解决此问题的另一种方法是检查记录器的 handlers 属性：

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

You are calling configure_logging twice (maybe in the __init__ method of Boy) : getLogger will return the same object, but addHandler does not check if a similar handler has already been added to the logger.

Try tracing calls to that method and eliminating one of these. Or set up a flag logging_initialized initialized to False in the __init__ method of Boy and change configure_logging to do nothing if logging_initialized is True, and to set it to True after you've initialized the logger.

If your program creates several Boy instances, you'll have to change the way you do things with a global configure_logging function adding the handlers, and the Boy.configure_logging method only initializing the self.logger attribute.

Another way of solving this is by checking the handlers attribute of your logger:

logger = logging.getLogger('my_logger')
if not logger.handlers:
    # create the handlers and call logger.addHandler(logging_handler)
回复 原文
[浮城] 2024-12-01 03:55:04

如果您遇到此问题并且没有两次添加处理程序，请参阅 abarnert 的答案 此处

来自 文档：

注意：如果将处理程序附加到记录器及其一个或多个
祖先，它可能会多次发出相同的记录。一般来说，你
不需要将处理程序附加到多个记录器 - 如果您
只需将其连接到最高的相应记录器即可
记录器层次结构，然后它将看到所有后代记录的所有事件
记录器，前提是它们的传播设置保留为 True。一个
常见的情况是仅将处理程序附加到根记录器，并且
让传播处理剩下的事情。

因此，如果您想要在“test”上使用自定义处理程序，并且不希望其消息也发送到根处理程序，答案很简单：关闭其 propagate 标志：

logger.propagate = False

If you are seeing this problem and you're not adding the handler twice then see abarnert's answer here

From the docs:

Note: If you attach a handler to a logger and one or more of its
ancestors, it may emit the same record multiple times. In general, you
should not need to attach a handler to more than one logger - if you
just attach it to the appropriate logger which is highest in the
logger hierarchy, then it will see all events logged by all descendant
loggers, provided that their propagate setting is left set to True. A
common scenario is to attach handlers only to the root logger, and to
let propagation take care of the rest.

So, if you want a custom handler on "test", and you don't want its messages also going to the root handler, the answer is simple: turn off its propagate flag:

logger.propagate = False
回复 原文
淡淡の花香 2024-12-01 03:55:04

我是 python 新手，但这似乎对我有用（Python 2.7）

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

I'm a python newbie, but this seemed to work for me (Python 2.7)

while logger.handlers:
     logger.handlers.pop()
回复 原文
最笨的告白 2024-12-01 03:55:04

就我而言，我会设置 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')

In my case I'd to set logger.propagate = False to prevent double printing.

In below code if you remove logger.propagate = False then you will see double printing.

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')
回复 原文
时间你老了 2024-12-01 03:55:04

每次从外部调用时都会添加处理程序。完成工作后尝试删除处理程序：

self.logger.removeHandler(ch)

The handler is added each time you call from outside. Try Removeing the Handler after you finish your job:

self.logger.removeHandler(ch)
回复 原文
染墨丶若流云 2024-12-01 03:55:04

如果您尝试从父文件创建日志记录对象，也可能会发生这种情况。例如
这是主应用程序文件 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

This can also happen if you are trying to create a logging object from the parent file. For e.g.
This is the main application file 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')

And below is the parent file main.py

import test

test.my_code()

The output of this will print only once

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

But if we had a parent logging object, then it will be printed twice. For e.g. if this is the parent file

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


test.my_code()

The the output will be

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
回复 原文
笔芯 2024-12-01 03:55:04

添加到其他人的有用响应...

万一您没有意外地在记录器上配置多个处理程序：

当您的记录器有祖先（根记录器始终是一个）并且它们有自己的处理程序时，当您的记录器输出（默认情况下）时，它们也会输出，这将创建重复项。您有两个选项：

  • 不要通过设置将日志事件传播到祖先：
my_logger.propagate = False
  • 如果您只有一个祖先（根记录器），则可以直接配置其处理程序。例如：
# directly change the formatting of root's handler
root_logger = logging.getLogger()
roots_handler = root_logger.handlers[0]
roots_handler.setFormatter(logging.Formatter(': %(message)s')) # change format

my_logger = logging.getLogger('my_logger') # my_logger will use new formatting

Adding to others' useful responses...

In case you are NOT accidentally configuring more than one handler on your logger:

When your logger has ancestors(root logger is always one) and they have their own handlers, they will also output when your logger outputs (by default), which will create duplicates. You have two options:

  • Don't propagate your log event to your ancestors by setting:
my_logger.propagate = False
  • If you only have one ancestor(root logger), you could directly configure their handler instead. For example:
# directly change the formatting of root's handler
root_logger = logging.getLogger()
roots_handler = root_logger.handlers[0]
roots_handler.setFormatter(logging.Formatter(': %(message)s')) # change format

my_logger = logging.getLogger('my_logger') # my_logger will use new formatting
回复 原文
看透却不说透 2024-12-01 03:55:04

如果没有安装根处理程序，则对 logging.debug() 的调用将调用 logging.basicConfig()。这发生在我的测试框架中，我无法控制测试用例的触发顺序。我的初始化代码正在安装第二个。默认使用我不想要的logging.BASIC_FORMAT。

A call to logging.debug() calls logging.basicConfig() if there are no root handlers installed. That was happening for me in a test framework where I couldn't control the order that test cases fired. My initialization code was installing the second one. The default uses logging.BASIC_FORMAT that I didn't want.

回复 原文
坐在坟头思考人生 2024-12-01 03:55:04

看来，如果你（不小心）向记录器输出一些内容然后配置它，那就太晚了。例如，在我的代码中，

logging.warning("look out)"

...
ch = logging.StreamHandler(sys.stdout)
root = logging.getLogger()
root.addHandler(ch)

root.info("hello")

我会得到类似的东西（忽略格式选项），

look out
hello
hello

并且所有内容都被写入标准输出两次。我相信这是因为第一次调用 logging.warning 自动创建一个新的处理程序，然后我显式添加了另一个处理程序。当我删除意外的第一个 logging.warning 调用时，问题就消失了。

It seems that if you output something to the logger (accidentally) then configure it, it is too late. For example, in my code I had

logging.warning("look out)"

...
ch = logging.StreamHandler(sys.stdout)
root = logging.getLogger()
root.addHandler(ch)

root.info("hello")

I would get something like (ignoring the format options)

look out
hello
hello

and everything was written to stdout twice. I believe this is because the first call to logging.warning creates a new handler automatically, and then I explicitly added another handler. The problem went away when I removed the accidental first logging.warning call.

回复 原文
追风人 2024-12-01 03:55:04

我在多个进程的背景下遇到了同样的问题。 （有关代码，请参阅 docs 我几乎逐字关注。）也就是说，源自任何子进程的所有日志消息都被复制。

我的错误是在子进程和主进程中都调用了worker_configurer()

def worker_configurer(logging_queue):
    queue_handler = logging.handlers.QueueHandler(logging_queue)
    root = logging.getLogger()
    root.addHandler(queue_handler)
    root.setLevel(level)

（因为我也希望主进程记录内容）。这导致麻烦（在我的 Linux 机器上）的原因是，在 Linux 上，子进程是通过分叉启动的，因此从主进程继承了现有的日志处理程序。也就是说，在 Linux 上，QueueHandler 注册了两次。

现在，防止 QueueHandler 在 worker_configurer() 函数中注册两次并不像看起来那么简单：

  • 像根记录器这样的 Logger 对象 root 有一个 handlers 属性，但没有记录。

  • 根据我的经验，测试是否 any([handler is queue_handler for handler in root.handlers]) (identity) 或 any([handler == queue_handler for handler in root.handlers] ])（相等）在分叉后失败，即使 root.handlers 看似包含相同的 QueueHandler。 （显然，前两个表达式可以缩写为root.handlers中的queue_handler，因为in运算符检查列表情况下的同一性和相等性。）

  • 根记录器被修改为像 pytest 这样的包，所以 root.handlers 和 root.hasHandlers() 一开始就不是很可靠。 （毕竟，它们是全局状态。）

因此，干净的解决方案是用生成代替分叉，以从一开始就防止此类多处理错误（当然，前提是您可以忍受额外的内存占用）。或者使用 logging 包的替代方案，它不依赖于全局状态，而是要求您进行适当的依赖项注入，但我离题了……:)

话虽这么说，我最终还是去了对于一个相当简单的检查：

def worker_configurer(logging_queue):
    queue_handler = logging.handlers.QueueHandler(logging_queue)
    root = logging.getLogger()

    for handler in root.handlers:
        if isinstance(handler, logging.handlers.QueueHandler):
            return

    root.addHandler(queue_handler)
    root.setLevel(level)

显然，当我决定在其他地方注册第二个队列处理程序时，这会产生令人讨厌的副作用。

I was struggling with the same issue in the context of multiple processes. (For the code see the docs which I was following almost verbatim.) Namely, all log messages originating from any of the child processes got duplicated.

My mistake was to call worker_configurer(),

def worker_configurer(logging_queue):
    queue_handler = logging.handlers.QueueHandler(logging_queue)
    root = logging.getLogger()
    root.addHandler(queue_handler)
    root.setLevel(level)

both in the child processes and also in the main process (since I wanted the main process to log stuff, too). The reason this led to trouble (on my Linux machine) is that on Linux the child processes got started through forking and therefore inherited the existing log handlers from the main process. That is, on Linux the QueueHandler got registered twice.

Now, preventing the QueueHandler from getting registered twice in the worker_configurer() function is not as trivial as it seems:

  • Logger objects like the root logger root have a handlers property but it is undocumented.

  • In my experience, testing whether any([handler is queue_handler for handler in root.handlers]) (identity) or any([handler == queue_handler for handler in root.handlers]) (equality) fails after forking, even if root.handlers seemingly contains the same QueueHandler. (Obviously, the previous two expressions can be abbreviated by queue_handler in root.handlers, since the in operator checks for both identity and equality in the case of lists.)

  • The root logger gets modified by packages like pytest, so root.handlers and root.hasHandlers() are not very reliable to begin with. (They are global state, after all.)

The clean solution, therefore, is to replace forking with spawning to prevent these kinds of multiprocessing bugs right from the start (provided you can live with the additional memory footprint, of course). Or to use an alternative to the logging package that doesn't rely on global state and instead requires you to do proper dependency injection but I'm digressing… :)

With that being said, I ended up going for a rather trivial check:

def worker_configurer(logging_queue):
    queue_handler = logging.handlers.QueueHandler(logging_queue)
    root = logging.getLogger()

    for handler in root.handlers:
        if isinstance(handler, logging.handlers.QueueHandler):
            return

    root.addHandler(queue_handler)
    root.setLevel(level)

Obviously, this will have nasty side effects the second I decide to register a second queue handler somewhere else.

回复 原文
夏雨凉 2024-12-01 03:55:04

来自文档：

“记录器具有以下属性和方法。请注意，记录器不应直接实例化，而应始终通过模块级函数logging.getLogger(name)进行实例化。
多次调用同名的 getLogger() 将始终返回对同一 Logger 对象的引用。

确保不要使用相同的名称初始化记录器
我建议您使用 __name__ 作为名称参数初始化记录器，即：

import logging
logger = logging.getLogger(__name__)

注意：
即使您从具有相同名称的其他模块初始化记录器，您仍然会获得相同的记录器，因此调用 ie logger.info('somthing') 将记录与启动记录器类一样多的次数。

From the docs:

"Loggers have the following attributes and methods. Note that Loggers should NEVER be instantiated directly, but always through the module-level function logging.getLogger(name).
Multiple calls to getLogger() with the same name will always return a reference to the same Logger object".

Make sure you don't initialise your loggers with the same name
I advise you to initialise the logger with __name__ as name param i.e:

import logging
logger = logging.getLogger(__name__)

NOTE:
even if you init a loggers from other modules with same name, you will still get the same logger, therefore calling i.e logger.info('somthing') will log as many times as you initiated the logger class.

回复 原文
复古式 2024-12-01 03:55:04

我尝试了很多东西，最后想出了我的自定义记录器。您只需将其复制并粘贴到您的代码中，它就会完成您所需的工作。

为什么要使用？

  1. 没有重复的日志。
  2. 单独定制信息日志 - [不包含路径和不必要的详细信息]
  3. 不同的颜色代表不同的日志级别。
  4. 您将获得所有不同级别的日志 - [信息、警告、错误、严重、调试...]。
import logging


class CustomFormatter(logging.Formatter):
    def __init__(self) -> None:
        super().__init__()

    def format(self, record):
        if record.levelno == logging.INFO:
            self._style._fmt = "%(levelname)-5s  %(asctime)-3s %(message)s"
        else:
            color = {
                logging.WARNING: 33,
                logging.ERROR: 31,
                logging.FATAL: 31,
                # logging.DEBUG: 36
            }.get(record.levelno, 0)
            self._style._fmt = f'\033[{color}m%(levelname)-5s %(asctime)s file/"%(pathname)10s", line %(lineno)d in "%(funcName)s" -> "%(message)s" \033[0m'
        return super().format(record)


logger = logging.getLogger("my-logger")
if not logger.handlers:
    handler = logging.StreamHandler()
    handler.setFormatter(CustomFormatter())
    logger.addHandler(handler)
    logger.setLevel(logging.DEBUG)
    logger.propagate = False
    # to disable any level of logs; eg - disabled debug level logs.
    logging.disable(logging.DEBUG)

您将得到什么 [ *在您的 colsole/日志文件中它将具有不同的颜色 ]

logger.info("这是信息日志")

INFO 2023-03-24 20:11:51,230 这是信息日志

logger.warning("这是警告日志")

警告 2023-03-24 20:11:51,230 file/"/home/xyz/abc", "my_function" 中的第 25 行 -> “这是警告日志”

logger.error("这是错误日志")

错误 2023-03-24 20:11:51,230 file/"/home/xyz/abc", "my_function" 中的第 26 行 -> “这是错误日志”

logger.ritic(“这是关键日志”)

关键 2023-03-24 20:11:51,231 file/"/home/xyz/abc", "my_function" 中的第 27 行 -> “这是关键日志”

logger.debug(“这是调试日志”)

DEBUG 2023-03-24 20:11:51,231 file/"/home/xyz/abc", "my_function" 中的第 28 行 -> “这是调试日志”

注意-我在上面的代码中禁用了调试级别日志，以使用注释/删除行。

I tried many things and finally came up with my custom logger. You just need to copy and paste it in your code and it will do the work you required.

Why to use?

  1. No repeated logs.
  2. Separate customisation for info logs - [ Not contains path and unnecessary details ]
  3. Different colours to different log levels.
  4. You will get all the different levels of logs - [ info, warning, error, critical, debug ,... ].
import logging


class CustomFormatter(logging.Formatter):
    def __init__(self) -> None:
        super().__init__()

    def format(self, record):
        if record.levelno == logging.INFO:
            self._style._fmt = "%(levelname)-5s  %(asctime)-3s %(message)s"
        else:
            color = {
                logging.WARNING: 33,
                logging.ERROR: 31,
                logging.FATAL: 31,
                # logging.DEBUG: 36
            }.get(record.levelno, 0)
            self._style._fmt = f'\033[{color}m%(levelname)-5s %(asctime)s file/"%(pathname)10s", line %(lineno)d in "%(funcName)s" -> "%(message)s" \033[0m'
        return super().format(record)


logger = logging.getLogger("my-logger")
if not logger.handlers:
    handler = logging.StreamHandler()
    handler.setFormatter(CustomFormatter())
    logger.addHandler(handler)
    logger.setLevel(logging.DEBUG)
    logger.propagate = False
    # to disable any level of logs; eg - disabled debug level logs.
    logging.disable(logging.DEBUG)

What you will get [ *it will be with different colours in you colsole/log file ]

logger.info("This is info log")

INFO 2023-03-24 20:11:51,230 This is info log

logger.warning("This is warning log")

WARNING 2023-03-24 20:11:51,230 file/"/home/xyz/abc", line 25 in "my_function" -> "This is warning log"

logger.error("This is error log")

ERROR 2023-03-24 20:11:51,230 file/"/home/xyz/abc", line 26 in "my_function" -> "This is error log"

logger.critical("This is critical log")

CRITICAL 2023-03-24 20:11:51,231 file/"/home/xyz/abc", line 27 in "my_function" -> "This is critical log"

logger.debug("This is debug log")

DEBUG 2023-03-24 20:11:51,231 file/"/home/xyz/abc", line 28 in "my_function" -> "This is debug log"

Note - I have disabled the debug level log in the above code, to use comment/remove the lines.

回复 原文
~没有更多了~

关于作者

蝶…霜飞

暂无简介

0 文章
0 评论
24 人气
发私信

相关话题

更多

热门标签

操作系统 程序设计 IT运维 Linux系统管理 JavaScript 服务器应用 solaris C/C++ PHP Shell BSD Vue.js aix Oracle Python HTML 系统管理 HTML5 CSS 前端
更多

推荐作者

胡图图

文章 0 评论 0

zt006

文章 0 评论 0

z祗昰~

文章 0 评论 0

冰葑

文章 0 评论 0

野の

文章 0 评论 0

天空

文章 0 评论 0

更多

友情链接

文江博客
    我们使用 Cookies 和其他技术来定制您的体验包括您的登录状态等。通过阅读我们的 隐私政策 了解更多相关信息。 单击 接受 或继续使用网站，即表示您同意使用 Cookies 和您的相关数据。
    原文