Python 日志记录:属于一个请求的组日志

Python Logging: Group logs which belong to one request

有没有办法将属于一个网络请求的 python 网络应用程序的日志分组?

示例:

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 方式解决这个问题?

日志条目在本质上被设计为彼此独立。
将它们连接在一起的正确方法是在条目中包含一些上下文信息,以便稍后查看日志时进行过滤。

这是包含此类信息的 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 推荐两种方法之一:使用 LoggerAdapterFilter

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配合),但实际上两者都可以做到。

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

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

例如,在龙卷风中:

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 日志来查找属于单独请求的所有消息。