AOP、拦截器与日志

第 9 章 · AOP、拦截器与日志

本章目标：使用 Spring AOP 与 @Aspect 实现方法耗时统计与操作审计；通过 HandlerInterceptor 记录 API 访问日志与请求上下文；配置 SLF4J + Logback 分环境日志级别、滚动文件与 MDC traceId；将横切能力接入 shop-spring-demo，为 ch10 异步任务与 ch11 测试打基础。

学时建议：4～5 小时（含 1 小时日志配置跟练）

前置：spring-boot-web ch07 统一响应；ch08 Profile 与 application-*.yml；了解 Spring Bean 生命周期。

9.1 横切关注点选型

HTTP 请求
  → Filter（可选：TraceId）
  → DispatcherServlet
  → HandlerInterceptor.preHandle
  → Controller → Service（@Aspect 环绕）
  → HandlerInterceptor.afterCompletion
  → 响应

教学项目统一使用 shop-spring-demo、域名示例 https://api.example.com；日志中禁止打印密码、Token 全文或真实用户隐私。

9.2 引入 AOP 依赖

pom.xml：

<dependency>
  <groupId>org.springframework.boot</groupId>
  <artifactId>spring-boot-starter-aop</artifactId>
</dependency>

Spring Boot 自动启用 AspectJ 自动代理（@EnableAspectJAutoProxy 默认开启）。

9.3 @Aspect 耗时统计

src/main/java/com/example/shop/aop/ExecutionTimeAspect.java：

package com.example.shop.aop;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class ExecutionTimeAspect {

    private static final Logger log = LoggerFactory.getLogger(ExecutionTimeAspect.class);

    @Around("within(com.example.shop.service..*)")
    public Object logExecutionTime(ProceedingJoinPoint pjp) throws Throwable {
        long start = System.currentTimeMillis();
        String signature = pjp.getSignature().toShortString();
        try {
            return pjp.proceed();
        } finally {
            long elapsed = System.currentTimeMillis() - start;
            if (elapsed > 500) {
                log.warn("慢调用 {} 耗时 {} ms", signature, elapsed);
            } else {
                log.debug("调用 {} 耗时 {} ms", signature, elapsed);
            }
        }
    }
}

自定义注解（推荐精确控制）：

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface Audited {
    String action();
}

@Around("@annotation(audited)")
public Object audit(ProceedingJoinPoint pjp, Audited audited) throws Throwable {
    log.info("审计 action={} method={}", audited.action(), pjp.getSignature());
    return pjp.proceed();
}

在 ProductService.create 上标注 @Audited(action = "PRODUCT_CREATE")。

9.4 操作审计切面

记录「谁、何时、做了什么」到日志（ch12 可扩展写入 audit_log 表）：

@AfterReturning(pointcut = "@annotation(audited)", returning = "result")
public void afterAudit(JoinPoint jp, Audited audited, Object result) {
    String username = SecurityContextHolder.getContext()
            .getAuthentication().getName();
    log.info("AUDIT user={} action={} args={}",
            username, audited.action(), jp.getArgs());
}

9.5 HandlerInterceptor 访问日志

AccessLogInterceptor.java：

package com.example.shop.web.interceptor;

import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.web.servlet.HandlerInterceptor;

@Component
public class AccessLogInterceptor implements HandlerInterceptor {

    private static final Logger log = LoggerFactory.getLogger("ACCESS");

    @Override
    public boolean preHandle(HttpServletRequest request,
                             HttpServletResponse response,
                             Object handler) {
        request.setAttribute("startTime", System.currentTimeMillis());
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request,
                                HttpServletResponse response,
                                Object handler,
                                Exception ex) {
        Long start = (Long) request.getAttribute("startTime");
        long elapsed = start == null ? -1 : System.currentTimeMillis() - start;
        log.info("{} {} status={} {}ms ip={}",
                request.getMethod(),
                request.getRequestURI(),
                response.getStatus(),
                elapsed,
                request.getRemoteAddr());
    }
}

注册拦截器：

@Configuration
public class WebMvcConfig implements WebMvcConfigurer {

    private final AccessLogInterceptor accessLogInterceptor;

    public WebMvcConfig(AccessLogInterceptor accessLogInterceptor) {
        this.accessLogInterceptor = accessLogInterceptor;
    }

    @Override