给 Django 日志加上 request id,方便追踪请求

注：本文大部分内容参考自：https://blog.csdn.net/handsomekang/article/details/78661392 但是因为原文有些点没有说的太清楚，不是面向初学者的，特把相关点说清楚

---

request id 用来标识同一个请求的日志，方便检索和分析。

request_id用一个小算法自动生成。如果请求头有 X-Request-ID，就用请求头的，这样一个请求涉及多个服务调用的时候可以把request_id带过去，标识为同一个请求的request_id.

下面是代码示例

本例整体目标是 1、在请求一开始打印请求基础信息(如 request path、get params) 2、打印日志时将 request id 带上，方便追踪请求

---

1. 定义 Middleware 和 Logging Filter

注：本示例文件路径为 dataStatistics.log_middleware.py

# -*- coding: utf-8 -*- from __future__ import unicode_literals import logging import threading from django.utils.deprecation import MiddlewareMixin local = threading.local() logger = logging.getLogger('tracer') class RequestIDFilter(logging.Filter): def filter(self, record): record.request_id = getattr(local, 'request_id', "none") return True def get_current_time(format=None): from datetime import datetime dt = datetime.now() if format: result = dt.strftime(format) else: result = dt.strftime("%Y/%m/%d %H:%M:%S") return result def base_n(num, b): return ((num == 0) and "0") or \ (base_n(num // b, b).lstrip("0") + "0123456789abcdefghijklmnopqrstuvwxyz"[num % b]) def generate_sid(): sid = get_current_time("%H%M%S%f") sid = int(sid) # 将 10 进制转为 32 进制 sid = base_n(sid, 32) # 反转 return "{}".format(sid)[::-1] class RequestIDMiddleware(MiddlewareMixin): def process_request(self, request): local.request_id = request.META.get('HTTP_X_REQUEST_ID', generate_sid()) logger.info("+++++ request_begin: [{}] [{}] {}".format(request.path, request.method, list(request.GET.items()))) def process_response(self, request, response): logger.info("----- request_end: [{}]".format(request.path)) if hasattr(request, 'request_id'): response['X-Request-ID'] = local.request_id try: del local.request_id except AttributeError: pass return response

2. 在 settings.py 中注册 自定义的 Middleware 并 使用 filter

MIDDLEWARE配置示例：

MIDDLEWARE = [ 'dataStatistics.log_middleware.RequestIDMiddleware' ]

LOGGING配置示例：

LOGGING = { 'version': 1, 'disable_existing_loggers': False, 'formatters': { 'track': { 'format': '%(levelname)s [%(asctime)s] [%(request_id)s] : %(message)s' # 这里使用filter request_id里的request_id字段 }, 'simple': { 'format': '{levelname} {message}', 'style': '{', }, }, 'filters': { 'require_debug_true': { '()': 'django.utils.log.RequireDebugTrue', }, 'request_id': { # 自定义的filter '()': 'dataStatistics.log_middleware.RequestIDFilter' } }, 'handlers': { 'console': { 'level': 'DEBUG', 'filters': ['require_debug_true'], 'class': 'logging.StreamHandler', 'formatter': 'track' }, 'tracer': { 'level': 'DEBUG', 'class': 'logging.StreamHandler', 'filters': ['request_id'], # 对应 formatters 中 的 track 'formatter': 'track' } }, 'loggers': { 'django': { 'handlers': ['console'], 'propagate': True, }, 'tracer': { # 对应 handlers 中的 tracer 'handlers': ['tracer'], # change debug level as appropiate 'level': 'DEBUG', 'propagate': True, } } }

3. 在代码中使用

首先拿到配置的 logger 对象：

logger 其实都是 settings.py 中 loggers 所定义的

logger = logging.getLogger('tracer') 然后使用时直接调用即可，如：logger.debug("my debug demo") logger.info("my info demo")

效果如下：

INFO [2019-11-01 16:28:12,744] [pfja6kn4] : +++++ request_begin: [/warehouse/demo/] [GET] [('parm1', 'value1'), ('parm2', 'value2')] DEBUG [2019-11-01 16:28:12,746] [pfja6kn4] : my debug demo INFO [2019-11-01 16:28:12,746] [pfja6kn4] : my info demo INFO [2019-11-01 16:28:12,750] [pfja6kn4] : ----- request_end: [/warehouse/demo/]