Python 上下文日志记录
我在一个Python应用程序中设置了日志记录，它可以把日志记录到文件和MongoDB。这个设置大致是这样的：
[logger_root]
handlers=myHandler,mongoHandler
level=DEBUG
qualname=myapp
[handler_myHandler]
class=handlers.RotatingFileHandler
level=DEBUG
formatter=myFormatter
args=('myapp.log', 'a',20000000,10)
[handler_mongoHandler]
class=myapp.MongoLogger.MongoLogger
level=INFO
args=('log',)
[formatter_myFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
而MongoLogger有一个叫emit()的函数，内容是这样的：
def emit(self, record):
logdata = record.__dict__
try:
if(self.data == None):
self.initDb()
self.logtable.insert(logdata)
except:
self.handleError(record)
日志记录的方式是这样的：
logger.info("Processing account %s..." % account)
这个方法运行得还不错，但现在我有一个额外的需求。我希望能添加一些上下文信息，比如说，定义一个自定义值，比如账户名称，这样在处理账户时，每条日志记录中都能包含这个账户名称，作为传递给上面emit的record的一部分，同时也能在myFormatter字符串中使用。
用日志模块可以做到这一点吗？有没有其他更好的方法来实现同样的功能？
5 个回答
8
请原谅我自我宣传一下，我写了一个叫做 log-with-context 的 Python 包，专门用来解决这个问题。你可以在 PyPI 和 GitHub 上找到它。下面是如何使用 log-with-context 来记录消息，并且可以使用任意数量的线程本地上下文值。
1. 安装 log-with-context 和一个日志格式化工具。
你需要把 log-with-context 和一个可以显示 extra 字段的日志记录器搭配使用。我最喜欢的日志格式化工具是 JSON-log-formatter。
你可以用 pip 一次性安装这两个包：
pip3 install log-with-context JSON-log-formatter
2. 配置日志格式化工具。
下面是如何配置 JSON-log-formatter，让它打印出 INFO 级别及以上的 JSON 日志到标准错误输出。
import logging.config
logging.config.dictConfig({
"version": 1,
"disable_existing_loggers": True,
"formatters": {
"json": {"()": "json_log_formatter.JSONFormatter"},
},
"handlers": {
"console": {
"formatter": "json",
"class": "logging.StreamHandler",
}
},
"loggers": {
"": {"handlers": ["console"], "level": "INFO"},
},
})
3. 使用 log-with-context 创建一个新的日志记录器。
接下来，下面是如何创建你的日志记录器：
from log_with_context import add_logging_context, Logger
LOGGER = Logger(__name__)
4. 使用 add_logging_context 上下文管理器记录消息。
你可以使用 add_logging_context 上下文管理器来推入和弹出上下文的键和值。下面是一些示例代码，展示如何使用这个上下文管理器：
with add_logging_context(current_request="hi"):
LOGGER.info("Level 1")
with add_logging_context(more_info="this"):
LOGGER.warning("Level 2")
LOGGER.info("Back to level 1")
LOGGER.error("No context at all...")
这是上面记录的日志消息以 JSON 格式打印出来的样子：
{"current_request": "hi", "message": "Level 1", "time": "2021-08-03T21:29:45.987392"}
{"current_request": "hi", "more_info": "this", "message": "Level 2", "time": "2021-08-03T21:29:45.988786"}
{"current_request": "hi", "message": "Back to level 1", "time": "2021-08-03T21:29:45.989178"}
{"message": "No context at all...", "time": "2021-08-03T21:29:45.989600"}
11
解释
Python的官方文档（日志记录食谱）提供了两种方法来给日志添加上下文信息：
- 使用 LoggerAdapters - 如果想了解更多，可以参考 pete lin的回答。
- 使用 Filters（和全局上下文变量） - 过滤器在日志记录被输出之前处理记录。它的主要目的是允许更复杂和自定义的规则来拒绝日志记录（
filter方法返回布尔值，指示是否输出该记录）。不过，它也允许你处理记录，并根据需要添加属性。例如，你可以根据全局上下文设置属性，这里有两个选项：- ContextVar 适用于 Python 3.7 及以上版本（感谢 jeromerg 的评论）
- threading.local 变量适用于 Python 3.7 之前的版本
什么时候用哪个？
- 如果你需要为特定的日志记录器 实例 编辑记录，我建议使用 LoggerAdapters - 在这种情况下，实例化一个适配器是有意义的。
- 如果你想编辑由特定处理器处理的 所有记录，包括其他模块和第三方包，我建议使用 Filter。在我看来，这通常是更干净的方法，因为我们只需在入口代码中配置我们的日志记录器，其余代码保持不变（不需要用适配器实例替换日志记录器实例）。
代码示例
下面是一个 Filter 示例，它从全局的 threading.local 变量中添加属性：
log_utils.py
log_context_data = threading.local()
class ContextFilter(logging.Filter):
"""
This is a filter which injects contextual information from `threading.local` (log_context_data) into the log.
"""
def __init__(self, attributes: List[str]):
super().__init__()
self.attributes = attributes
def filter(self, record):
for a in self.attributes:
setattr(record, a, getattr(log_context_data, a, 'default_value'))
return True
还有一个 ContextVar 版本：
log_context_data = contextvars.ContextVar('log_context_data', default=dict())
class ContextFilter(logging.Filter):
"""
This is a filter which injects contextual information from `contextvars.ContextVar` (log_context_data) into the log.
"""
def __init__(self, attributes: List[str]):
super().__init__()
self.attributes = attributes
def filter(self, record):
context_dict = log_context_data.get()
for a in self.attributes:
setattr(record, a, context_dict.get(a, 'default_value'))
return True
log_context_data 可以在你开始处理一个账户时设置，并在完成后重置。不过，我建议使用上下文管理器来设置它：
同样在 log_utils.py 中，适用于 threading.local：
class SessionContext(object):
def __init__(self, logger, context: dict = None):
self.logger = logger
self.context: dict = context
def __enter__(self):
for key, val in self.context.items():
setattr(log_context_data, key, val)
return self
def __exit__(self, et, ev, tb):
for key in self.context.keys():
delattr(log_context_data, key)
或者 ContextVar
class SessionContext(object):
def __init__(self, logger, context: dict = None):
self.logger = logger
self.context: dict = context
self.token = None
def __enter__(self):
context_dict = log_context_data.get()
for key, val in self.context.items():
context_dict[key] = val
self.token = log_context_data.set(context_dict)
return self
def __exit__(self, et, ev, tb):
log_context_data.reset(self.token)
self.token = None
还有一个使用示例，my_script.py：
root_logger = logging.getLogger()
handler = ...
handler.setFormatter(
logging.Formatter('{name}: {levelname} {account} - {message}', style='{'))
handler.addFilter(ContextFilter(['account']))
root_logger.addHandler(handler)
...
...
using SessionContext(logger=root_logger, context={'account': account}):
...
...
注意：
Filter只应用于它所附加的logger。所以如果我们将它附加到logging.getLogger('foo')，它不会影响logging.getLogger('foo.bar')。解决方法是将Filter附加到Handler，而不是logger。ContextFilter可能会拒绝记录，如果log_context_data不包含所需的属性。这取决于你的需求。
21
你可以在处理账户的代码中定义一个函数，方法是在获取到账户名称之后，像这样：
# account_name should already be defined
log = lambda msg: logger.info(msg, extra={'account': account_name})
###
log('Processing account...')
注意这里的 extra 这个关键字参数。它的作用是为日志记录添加额外的信息——在这个例子中，就是账户名称。
你可以在格式化器中使用通过 extra 传递的上下文信息：
format = '%(asctime)s - %(name)s - %(levelname)s - %(message)s - %(account)s'
要注意，如果你这样设置格式化器却忘了传递 account，你会遇到字符串格式化的错误。