Python 中使用日志记录模块的奇怪问题

Question

在我正在处理的应用程序中调用另一个模块后记录数据时，我似乎运行遇到了问题。我想了解这里可能发生的情况。

为了重现这个问题，我开发了以下脚本...

#!/usr/bin/python

import sys
import logging
from oletools.olevba import VBA_Parser, VBA_Scanner
from cloghandler import ConcurrentRotatingFileHandler

# set up logger for application
dbg_h = logging.getLogger('dbg_log')
dbglog = '%s' % 'dbg.log'
dbg_rotateHandler = ConcurrentRotatingFileHandler(dbglog, "a")
dbg_h.addHandler(dbg_rotateHandler)
dbg_h.setLevel(logging.ERROR)

# read some document as a buffer
buff = sys.stdin.read()

# generate issue
dbg_h.error('Before call to module....')
vba = VBA_Parser('None', data=buff)
dbg_h.error('After call to module....')

当我运行这个时，我得到以下...

cat somedocument.doc | ./replicate.py
ERROR:dbg_log:After call to module....

出于某种原因，我最后一次 dbg_h 记录器写入尝试是将输出输出到控制台并写入我的 dbg.log 文件？这似乎只发生在调用 VBA_Parser.

之后

cat dbg.log
Before call to module....
After call to module....

有人知道为什么会发生这种情况吗？我查看了 source code of olevba 并没有看到任何特别突出的内容。

我应该向模块作者提出这个问题吗？或者我在使用 cloghandler 时做错了什么？

Answer 1

oletools 代码库充斥着通过调用 logging.debug(...)、logging.error(...) 等对根记录器的调用。由于作者没有费心去配置根记录器，默认行为是转储到 sys.stderr。由于从命令行运行时 sys.stderr 默认为控制台，因此您会看到所见即所得。

您应该联系 oletools 的作者，因为他们没有有效地使用日志系统。理想情况下，他们会使用命名记录器并将消息推送到该记录器。作为抑制消息的解决方法，您可以将根记录器配置为使用您的处理程序。

# Set a handler
logger.root.addHandler(dbg_rotateHandler)

请注意，这可能会导致重复的日志消息。

Python 中使用日志记录模块的奇怪问题

Strange Issue Using Logging Module in Python

python

debugging

error-logging