Django中根据请求生成唯一标识

我在服务器应用中常常会打印很多日志, 方便定位和排查问题. 但是在生产环境下, 针对并发请求处理, 往往需要标识出当前的日志属于哪次请求. 这里简单讨论下如何在django中实现这个功能.

基础

这个问题我在stackoverflow也找到了: django-logging-unique-id, 回答中提到的这篇文章相当有帮助. 主要提到了两点:

  1. threading.local
  2. logging模块的filter

threading.local

有关threading.local, 简单说就是一个线程级别的变量, 类似gcc里面的__thread. 一个简单的例子来看看:

threading.local
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
import threading

local_data = threading.local()
local_data.foo = 'main'

print("[main] local_data.foo: {0}".format(local_data.foo))

def test_local_data(*args, **kwargs):
    print("[sub] local.data.foo: {0}".format(local_data.foo))
    local_data.foo = args[0]
    print("[sub] local.data.foo: {0}".format(local_data.foo))

t1 = threading.Thread(target=test_local_data, args=('t1'))
t1.start()
t1.join()

print("[main] local_data.foo: {0}".format(local_data.foo))

子线程在执行local_data.foo = args[0]会抛异常, 提示无foo这个属性. 利用它的局部特征, 我们可以用它来保存一些特别的变量, 例如request\_id.

logging的filter

之前我在一篇文章中学习了一下logging的使用, 这里用到了它的filter特性, 简单看下它的说明:

Filter instances are allowed to modify the LogRecords passed to them, including adding additional attributes which can then be output using a suitable format string, or if needed a custom Formatter.

简而言之, 我们可以使用filter去修改record中的内容, 贴下官网的例子:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
import logging
from random import choice

class ContextFilter(logging.Filter):
    """
    This is a filter which injects contextual information into the log.

    Rather than use actual contextual information, we just use random
    data in this demo.
    """

    USERS = ['jim', 'fred', 'sheila']
    IPS = ['123.231.231.123', '127.0.0.1', '192.168.0.1']

    def filter(self, record):

        record.ip = choice(ContextFilter.IPS)
        record.user = choice(ContextFilter.USERS)
        return True

if __name__ == '__main__':
   levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)
   logging.basicConfig(level=logging.DEBUG,
                       format='%(asctime)-15s %(name)-5s %(levelname)-8s IP: %(ip)-15s User: %(user)-8s %(message)s')
   a1 = logging.getLogger('a.b.c')
   a2 = logging.getLogger('d.e.f')

   f = ContextFilter()
   a1.addFilter(f)
   a2.addFilter(f)
   a1.debug('A debug message')
   a1.info('An info message with %s', 'some parameters')
   for x in range(10):
       lvl = choice(levels)
       lvlname = logging.getLevelName(lvl)
       a2.log(lvl, 'A message at %s level with %d %s', lvlname, 2, 'parameters')

上面为a1, a2两个logger对象增加了ContextFilter过滤. 过滤器中给record添加了ipuser属性, 并最终输出到日志中.

结合上面两点, 不难实现我们的功能, 但是在django中, 我们还需要了解下middleware

middleware

这个middleware说简单点就是若干hook. 我们可以在提供的hook点上执行我们自己的代码.

针对我们的需求, 值得关注的hook点为process_request:

process_request

process_request(request) request is an HttpRequest object.

process_request() is called on each request, before Django decides which view to execute.

It should return either None or an HttpResponse object. If it returns None, Django will continue processing this request, executing any other process_request() middleware, then, process_view() middleware, and finally, the appropriate view. If it returns an HttpResponse object, Django won’t bother calling any other request, view or exception middleware, or the appropriate view; it’ll apply response middleware to that HttpResponse, and return the result.

具体的例子可以参考django自身的middleware.

解决问题

结合上述基础, 我们可以开搞了:

  1. 自己写一个middleware注册到process\_request
  2. 在hook函数中获取request变量, 生成对应的id
  3. 将对应的id保存在threading.local对象中
  4. 为自己的logger注册一个filter
  5. filter中获取对应的id, 并写入record中
  6. 修改settings.py中的log配置

具体代码就不写了, 直接附上一个别人的实现django-log-request-id

~~~~

Comments