用logging + Middleware记录Django API请求日志

场景

用Django REST framework来构建Result API，需要记录用户请求的时间、方法、数据、响应状态等。

实现方法

用Python的logging模块结合Django框架的Middleware，来将每次API请求的详细信息记录下来。

settings新增LOGGING配置

定义一个专门记录API日志的logger，命名为api。

# LOGGING settings
LOG_DIR = BASE_DIR + "/log"
LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        'standard': {
            'format': '%(asctime)s FuncName:%(funcName)s LINE:%(lineno)d [%(levelname)s]- %(message)s'
        },
        'simple': {
            'format': '%(levelname)s %(message)s'
        },
        'verbose': {
            'format': '%(levelname)s %(asctime)s %(module)s %(funcName)s %(message)s'
        },
    },
    'filters': {
        'require_debug_false': {
            '()': 'django.utils.log.RequireDebugFalse'
        }
    },
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'standard'
        },
        'default': {
            'level': 'INFO',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': os.path.join(LOG_DIR, 'info.log'),
            'maxBytes': 1024*1024*50,   # 50 MB
            'backupCount': 2,
            'formatter': 'standard',
        },
        'default_debug': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': os.path.join(LOG_DIR, 'debug.log'),
            'maxBytes': 1024*1024*50,  # 50 MB
            'backupCount': 2,
            'formatter': 'standard',
        },
        'request_handler': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': os.path.join(LOG_DIR, 'common.log'),
            'maxBytes': 1024*1024*50,  # 50 MB
            'backupCount': 2,
            'formatter': 'standard',
        },
        'restful_api': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': os.path.join(LOG_DIR, 'api.log'),
            'maxBytes': 1024*1024*50,  # 50 MB
            'backupCount': 2,
            'formatter': 'verbose',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['console', 'default_debug'],
            'level': 'INFO',
            'propagate': False
        },
        'django.request': {
            'handlers': ['request_handler'],
            'level': 'INFO',
            'propagate': False
        },
        'common': {
            'handlers': ['default', 'console'],
            'level': 'INFO',
            'propagate': True
        },
        'api': {
            'handlers': ['restful_api'],
            'level': 'INFO',
            'propagate': True
        },
    }
}

自定义日志记录中间件ApiLoggingMiddleware

在合适的位置新建文件middleware.py，自定义日志记录中间件ApiLoggingMiddleware。

# -*- coding: utf-8 -*-
from __future__ import unicode_literals

import logging
import json


class ApiLoggingMiddleware(object):
    def __init__(self, get_response):
        self.get_response = get_response
        self.apiLogger = logging.getLogger('api')

    def __call__(self, request):
        try:
            body = json.loads(request.body)
        except Exception:
            body = dict()
        body.update(dict(request.POST))
        response = self.get_response(request)
        if request.method != 'GET':
            self.apiLogger.info("{} {} {} {} {} {}".format(
                request.user, request.method, request.path, body,
                response.status_code, response.reason_phrase))
        return response

在settings中加入中间件ApiLoggingMiddleware

由于中间件对request的处理是顺序执行的，对response处理是逆序执行的，故将ApiLoggingMiddlewar放在MIDDLEWARE_CLASSES的最后面。

MIDDLEWARE_CLASSES = [
    'django.middleware.security.SecurityMiddleware',
    'django.contrib.sessions.middleware.SessionMiddleware',
    'django.middleware.common.CommonMiddleware',
    'django.middleware.csrf.CsrfViewMiddleware',
    'django.contrib.auth.middleware.AuthenticationMiddleware',
    'django.contrib.messages.middleware.MessageMiddleware',
    'django.middleware.clickjacking.XFrameOptionsMiddleware',
    'lib.mypath.middleware.ApiLoggingMiddleware',
]

记录效果

INFO 2019-01-11 15:28:50,652 middleware process_response username POST /api/product/ {u'csrfmiddlewaretoken': [u'jAlRDXXXXXXXXzK8UnluvSzaz2yacdDzTwRE005aCVvYnINSG7xvraqi0Pu5QHur'], u'code': [u'test'], u'name': [u'\u53d1\u5e03\u7cfb\u7edf']} 201 Created
INFO 2019-01-11 15:29:10,598 middleware process_response username GET /api/product/9/ {} 200 OK
INFO 2019-01-11 15:29:15,252 middleware process_response username PUT /api/product/9/ {u'code': [u'test'], u'name': [u'\u53d1\u5e03']} 200 OK
INFO 2019-01-11 15:29:27,603 middleware process_response username DELETE /api/product/9/ {} 200 OK
INFO 2019-01-11 15:29:37,961 middleware process_response username GET /api/product/ {} 200 OK