为什么禁止覆盖日志记录属性？

Question

阅读Python的logging库文档（版本为2.7），我发现以下内容：

Logger.debug(msg, *args, **kwargs)

[...] 第二个关键字参数是extra，可以用于传递一个字典，该字典用于填充创建日志事件的LogRecord的__dict__属性中的用户定义属性。然后可以根据需要使用这些自定义属性。例如，它们可以并入已记录的消息中。[...] 在extra传递的字典中的键不应与日志系统使用的键冲突。 [强调我的]

那么为什么存在这种限制？在我看来，这会使库变得不够灵活，而且没有好的理由（开发人员应该检查哪些键是内置的，哪些不是）。

想象一下，您想编写一个装饰器，用于记录函数的进入和退出：

def log_entry_exit(func):
    def wrapper(*args, **kwargs):
        logger.debug('Entry')
        result = func(*args, **kwargs)
        logger.debug('Exit')
        return result
    return wrapper

@log_entry_exit
def foo():
    pass

假设您还想记录封闭函数的名称：

假设您还想记录封闭函数的名称：

format_string = '%(funcName)s: %(message)s'

抱歉，这个无法正常工作。输出结果为：

>>> foo()
wrapper: Entry
wrapper: Exit

当然，函数名称评估为wrapper，因为它是封闭函数。但这不是我想要的。我希望打印修饰函数的函数名称。因此，只需修改我的日志调用即可非常方便：

logger.debug('<msg>', extra={'funcName': func.__name__})

然而（正如文档已经指出的那样），这并不起作用：

KeyError: "Attempt to overwrite 'funcName' in LogRecord"

尽管如此，这将是一个非常简单和轻量级的解决方案来解决给定的问题。

所以，再次提问：为什么logging会阻止我设置内置属性的自定义值？

- a_guest

---

我不确定这个问题是否能够回答。该模块正如文档中所描述的那样工作。至于为什么设计成这样，你需要问开发人员。 - augurar

Answer 1

我不是作者，所以不能确定，但我有一种直觉。

看着 https://hg.python.org/cpython/file/3.5/Lib/logging/__init__.py，这似乎是引发你引用的错误的代码：

rv = _logRecordFactory(name, level, fn, lno, msg, args, exc_info, func, sinfo)
if extra is not None:
    for key in extra:
        if (key in ["message", "asctime"]) or (key in rv.__dict__):
            raise KeyError("Attempt to overwrite %r in LogRecord" % key)
        rv.__dict__[key] = extra[key]

查看该文件中的__init__()方法，我们可以看到它设置了一长串属性，其中至少一些用于跟踪对象状态（借用其他地方的术语来说，这些属性用作私有成员变量）:

self.args = args
self.levelname = getLevelName(level)
self.levelno = level
self.pathname = pathname
try:
    self.filename = os.path.basename(pathname)
    self.module = os.path.splitext(self.filename)[0]
except (TypeError, ValueError, AttributeError):
    self.filename = pathname
    self.module = "Unknown module"
self.exc_info = exc_info
self.exc_text = None      # used to cache the traceback text
self.stack_info = sinfo
self.lineno = lineno
self.funcName = func
[...]

该代码在各个地方都假定这些属性包含它们最初被初始化时的内容，而不是每次使用它们时都进行防御性检查，正如我们之前所看到的那样，它会阻止尝试更新任何这些属性。而且，它没有试图区分“安全覆盖”和“不安全覆盖”的属性，而是简单地阻止任何覆盖操作。

在funcName的特定情况下，我怀疑您不会受到任何不良影响（除了显示不同的funcName）。

可能的解决方法:

- 接受这个限制。 - 重写Logger.makeRecord()以允许更新funcName。 - 重写Logger以添加一个setFuncName()方法。

当然，无论您采取什么行动，都要仔细测试修改以避免出现意外情况。

- Chris Jaekl

Answer 2

我知道这篇文章已经几年了，但是没有被选中的答案。如果有人遇到这个问题，我有一个解决方法，可以在日志模块发生变化时继续使用。

不幸的是，作者没有公开那些可能会导致冲突的键，因此很难进行检查。然而，在文档中，他/她确实暗示了一种方法。这行代码：https://hg.python.org/cpython/file/3.5/Lib/logging/init.py#l368 返回了一个 LogRecord 对象的外壳：

rv = _logRecordFactory(None, None, "", 0, "", (), None, None)

在这个对象中，您可以看到所有属性，并且可以创建一个包含“冲突键”的Set。

我创建了一个日志辅助模块：

import logging

clashing_keywords = {key for key in dir(logging.LogRecord(None, None, "", 0, "", (), None, None)) if "__" not in key}
additional_clashing_keywords = {
    "message", 
    "asctime"
}
clashing_keywords = clashing_keywords.union(additional_clashing_keywords)

def make_safe_kwargs(kwargs):
    '''
    Makes sure you don't have kwargs that might conflict with
    the logging module
    '''
    assert isinstance(kwargs, dict)
    for k in kwargs:
        if k in clashing_keywords:
            kwargs['_'+k] = kwargs.pop(k)

    return kwargs

...这将使用_在冲突的键前添加前缀。可以像这样使用：

from mymodule.logging_helpers import make_safe_kwargs

logger.info("my message", extra=make_safe_kwargs(kwargs))

这对我来说一直效果很好。希望这对您有所帮助!

- Dougyfresh

Answer 3

对我来说，简短的答案是识别名称冲突，并重新命名kwarg:

#broken
log.info('some message', name=name)

# working
log.info('some message', special_name=name)

- jmunsch