Python Logging：对属于一个请求的日志进行分组答案

【问题标题】：Python Logging: Group logs which belong to one requestPython Logging：对属于一个请求的日志进行分组
【发布时间】：2015-02-11 12:37:40
【问题描述】：

有没有办法对属于一个 web 请求的 python web 应用程序的日志进行分组？

例子：

2015-02-11 13:06:32 myapp.middleware.MYAPPMiddleware: INFO     Login of user foo was successful
2015-02-11 13:06:32 myapp.middleware.MYAPPMiddleware: INFO     Login of user bar failed
2015-02-11 13:06:32 myapp.send_mails: INFO     failed to send mail to someone@example.com

以上日志行彼此无关。

你怎么能用pythonic的方式解决这个问题？

【问题讨论】：

标签： python logging httprequest

【解决方案1】：

日志条目本质上是相互独立的。
将它们连接在一起的正确方法是在条目中包含一些上下文信息，以便以后查看日志时进行过滤。

以下是包含此类信息的 Sharepoint 日志记录示例：

Timestamp               Process             TID     Area                    Category                    EventID Level       Message     Correlation
02/26/2015 17:49:19.65  w3wp.exe (0x1F40)   0x2358  SharePoint Foundation   Logging Correlation Data    xmnv    Medium      Name=Request (POST:http://reserver2:80/pest/_vti_bin/sitedata.asmx) d1e2b688-e0b2-481e-98ce-497a11acab44

在 Python logging 文档中，Adding contextual information to your logging output 建议使用以下两种方法之一：使用 LoggerAdapter 或 Filter。

LoggerAdapter 是这样使用的（示例基于文档中的示例）：

class AddConnIdAdapter(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        return <augment_message(msg,arbitrary_info)>, kwargs
la = AddConnIdAdapter(<logger>,extra=<parameters, saved in self.extra>)
<...>
la.info(<message>)

Filter 是这样使用的：

#Either all messages should have custom fields
# or the Formatter used should support messages
# both with and without custom fields
logging.basicConfig(<...>,format='%(asctime)-15s %(name)-5s %(levelname)-8s IP: %(ip)-15s User: %(user)-8s %(message)s')
class AddClientInfo(logging.Filter):
    #override __init__ or set attributes to specify parameters
    def filter(self, record):
        record.ip = <get_client_ip()>
        record.user = <get_client_name()>
        return True    #do not filter out anything
l=<logger()>
l.addFilter(AddClientInfo()) #can attach to either loggers or handlers
<...>
l.info('message')

如您所见，区别在于LoggerAdapter 是不透明的，而Filter 是透明的。在示例中，前者修改消息文本，而后者设置自定义属性（实际上编写它们需要使用的Formatter 配合），但实际上两者都可以。

因此，如果您只需要为某些消息添加上下文，则前者更有用，而后者更适合扩充所有或大部分正在记录的消息。

【讨论】：

【解决方案2】：

您可以在 init 方法中为每个请求分配随机 UUID，并将其添加到所有日志消息中。

例如，在 Tornado 中：

class MainRequestHandler(RequestHandler):
    def __init__(self, application, request):
        super(MainRequestHandler, self).__init__(application, request)
        self.uuid = uuid.uuid4()
        logging.info("%s | %s %s %s",
                     self.uuid,
                     request.method,
                     request.full_url(),
                     request.remote_ip)

因此，您将能够通过此 UUID grep 日志来查找属于单独请求的所有消息。

【讨论】：

这种方法通常很有用，当您记录到多个独立日志时是必要的，例如Python 日志框架加上一个 Web 服务器日志。没有这个，很难在日志之间建立关联。