中间件、信号与日志

第 9 章 · 中间件、信号与日志

本章目标：理解 Django 中间件执行顺序；编写自定义中间件记录请求日志与耗时；使用 django.dispatch 信号 在 post_save 等时机解耦业务；为模型添加审计字段（创建人、更新人、时间戳）；配置结构化日志输出，支撑 shop-demo 后台排障。

学时建议：4 小时（含 1.5 小时信号跟练）

前置：本模块 ch01 请求生命周期；ch03 用户认证；ch05 ORM；ch07 API 视图。HTTP 基础见 frontend-web ch08。

9.1 请求在 Django 中的旅程

HTTP Request
  → SecurityMiddleware
  → SessionMiddleware
  → CommonMiddleware
  → CsrfViewMiddleware
  → AuthenticationMiddleware
  → ... 自定义中间件 ...
  → URL 路由 → View → Response
  ← 中间件 process_response 逆序返回

中间件可在进入视图前与离开视图后介入，适合：日志、计时、全站维护模式、IP 限流、注入 request 属性。

示例项目 shop-demo 为教学虚构电商；日志字段使用 user-demo 账号，不记录任何真实生产流量。

9.2 自定义请求日志中间件

core/middleware.py（新建 core 应用或在 shopdemo 包内）：

import logging
import time
import uuid

logger = logging.getLogger("shopdemo.request")


class RequestLogMiddleware:
    """记录每个 HTTP 请求的方法、路径、状态码与耗时。"""

    def __init__(self, get_response):
        self.get_response = get_response

    def __call__(self, request):
        request_id = request.META.get("HTTP_X_REQUEST_ID") or str(uuid.uuid4())[:8]
        request.request_id = request_id
        start = time.perf_counter()

        response = self.get_response(request)

        duration_ms = (time.perf_counter() - start) * 1000
        user = getattr(request, "user", None)
        username = user.username if user and user.is_authenticated else "-"

        logger.info(
            "request_id=%s method=%s path=%s status=%s duration_ms=%.1f user=%s ip=%s",
            request_id,
            request.method,
            request.get_full_path(),
            response.status_code,
            duration_ms,
            username,
            self._client_ip(request),
        )
        response["X-Request-ID"] = request_id
        return response

    @staticmethod
    def _client_ip(request):
        forwarded = request.META.get("HTTP_X_FORWARDED_FOR")
        if forwarded:
            return forwarded.split(",")[0].strip()
        return request.META.get("REMOTE_ADDR", "-")

注册（顺序很重要，建议放在 AuthenticationMiddleware 之后以便读到 request.user）：

MIDDLEWARE = [
    "django.middleware.security.SecurityMiddleware",
    "django.contrib.sessions.middleware.SessionMiddleware",
    "django.middleware.common.CommonMiddleware",
    "django.middleware.csrf.CsrfViewMiddleware",
    "django.contrib.auth.middleware.AuthenticationMiddleware",
    "core.middleware.RequestLogMiddleware",  # 自定义
    "django.middleware.clickjacking.XFrameOptionsMiddleware",
]

慢请求告警（选修）：耗时超过 500ms 时写 shopdemo.slow 日志。

9.3 日志配置

shopdemo/settings.py：

LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "verbose": {
            "format": "{asctime} {levelname} {name} {message}",
            "style": "{",
        },
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "verbose",
        },
        "file": {
            "class": "logging.handlers.RotatingFileHandler",
            "filename": BASE_DIR / "logs" / "shopdemo.log",
            "maxBytes": 5 * 1024 * 1024,
            "backupCount": 3,
            "formatter": "verbose",
        },
    },
    "loggers": {
        "shopdemo.request": {"handlers": ["console", "file"], "level": "INFO"},
        "shopdemo.audit": {"handlers": ["file"], "level": "INFO"},
        "django.db.backends": {"handlers": ["console"], "level": "WARNING"},  # SQL 调试时改 DEBUG
    },
}

创建 logs/ 目录并加入 .gitignore。

在视图中使用：

import logging
logger = logging.getLogger("shopdemo.catalog")

def some_view(request):
    logger.debug("query params=%s", request.GET)

9.4 Django 信号机制

信号实现观察者模式：发送方不直接调用接收方，降低耦合。

Model.save()
    → pre_save 信号
    → 写入数据库
    → post_save 信号  → 审计、缓存失效、发通知

常用内置信号：

9.5 审计字段抽象基类

core/models.py：