ElIauk

Spring Boot AOP 日志与埋点

为什么要用切面记日志 接口日志这件事,刚开始大家都是在 Controller 里手写:方法进来打一行,出去打一行,再算个耗时。写三五个接口还行,写到三十个就会发现两个问题:一是重复代码多,二是总有几个接口忘了加。等线上要统计"哪个接口慢",日志格式还各不相同,根本没法聚合。 AOP 适合处理这类"横

评论
Spring Boot AOP 日志与埋点

为什么要用切面记日志

接口日志这件事,刚开始大家都是在 Controller 里手写:方法进来打一行,出去打一行,再算个耗时。写三五个接口还行,写到三十个就会发现两个问题:一是重复代码多,二是总有几个接口忘了加。等线上要统计"哪个接口慢",日志格式还各不相同,根本没法聚合。

AOP 适合处理这类"横切"逻辑:它不改变业务代码,而是在方法调用前后插入统一的动作。除了记日志,权限校验、幂等判断、埋点上报也常用这个套路。这篇文章给出一套可以直接落地的日志切面,并说明它在哪些情况下会失效。

一个能用的切面

先定义一个注解,让"要不要记日志"由业务方法自己声明:

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface LogTrace {
    String value() default "";
}

再写切面。注意 @Around 必须调用 proceed(),否则业务方法根本不会执行:

@Slf4j
@Aspect
@Component
@Order(1)
public class LogTraceAspect {

    @Around("@annotation(trace)")
    public Object around(ProceedingJoinPoint pjp, LogTrace trace) throws Throwable {
        String method = pjp.getSignature().toShortString();
        long start = System.currentTimeMillis();
        log.info("[{}] 入参={}", method, briefArgs(pjp.getArgs()));
        try {
            Object result = pjp.proceed();
            log.info("[{}] 耗时={}ms", method, System.currentTimeMillis() - start);
            return result;
        } catch (Throwable e) {
            log.warn("[{}] 异常={}", method, e.getMessage(), e);
            throw e;
        }
    }

    private String briefArgs(Object[] args) {
        return Arrays.stream(args).map(arg -> {
            if (arg == null) {
                return "null";
            }
            if (arg instanceof MultipartFile || arg instanceof InputStream) {
                return arg.getClass().getSimpleName();
            }
            String text = String.valueOf(arg);
            return text.length() > 200 ? text.substring(0, 200) + "..." : text;
        }).collect(Collectors.joining(", ", "[", "]"));
    }
}

使用时在方法上加 @LogTrace 即可。如果项目已经接了 traceId,可以在切面里把 MDC.get("traceId") 一并打出来,排查时能直接串起一次请求。

切点表达式与执行顺序

常用的切点有四种写法,按影响范围从小到大排列:

写法 匹配范围 适用场景
@annotation(com.example.LogTrace) 标了注解的方法 精准埋点
execution(* com.example.controller..*.*(..)) 指定包下所有方法 Controller 统一耗时
@within(org.springframework.web.bind.annotation.RestController) 类上带注解的所有方法 按类批量
bean(*Controller) Bean 名称匹配 简单场景,少用

多个切面同时存在时,顺序由 @Order 或 Ordered 接口决定。数值越小越靠外:@Order(1) 的切面先进入、后退出。日志切面和事务切面一起用时要想清楚顺序——如果日志切面在外层,它统计到的耗时会包含事务提交的时间;如果在内层,事务还没提交日志就已经打完了。一般建议日志切面放在外层,耗时更接近用户真实感受。

常见坑

1. 同类内部调用不生效

这是 Spring AOP 最常见的问题。this.save() 这种自调用不经过代理,注解等于没写。解决办法是把方法拆到另一个 Bean,或者注入自身代理(不推荐,容易循环依赖)。

2. private、final、static 方法切不到

Spring AOP 基于动态代理,private 方法无法被代理;final 方法在 CGLIB 下也无法增强;static 方法不属于实例。切点写在这些方法上不会报错,只是永远不触发。

3. @Around 忘了 proceed()

写了通知却没调用 proceed(),业务方法会被静默跳过,接口返回 null。这类问题在测试环境很容易被当成"业务逻辑没生效",实际是切面的锅。

4. 切点包名写错

多模块项目里包名重构后,execution 里的包路径没跟着改,切面就悄悄失效了。启动时打开 logging.level.org.springframework.aop=DEBUG,能看到哪些 Bean 被代理、匹配了哪些切点。

5. 日志把大对象和敏感字段打出来

把整个 MultipartFile、几 MB 的 JSON、身份证号、手机号原样打进日志,既拖慢接口又可能违规。入参要做长度截断和脱敏,文件流只记录类型和大小。

6. 异常被切面吞掉

catch 之后只打日志不重新抛出,事务不会回滚,调用方也拿不到失败信号。切面里要么原样 throw,要么明确转换成业务异常。

7. 异步线程里 MDC 丢失

@Async 方法运行在另一个线程,MDC 不会自动传递。需要配合 TaskDecorator 在任务提交时复制上下文,否则异步日志里的 traceId 是空的。

排查步骤

切面不生效时,按这个顺序确认:

  1. 启动类或配置类上有没有 @EnableAspectJAutoProxy(Spring Boot 的 spring-boot-starter-aop 会自动开启);
  2. 切面类是否被 Spring 管理,有没有 @Aspect 和 @Component;
  3. 目标方法是不是通过代理调用的,可以用 AopUtils.isAopProxy(bean) 打印确认;
  4. 切点表达式能否匹配,打开 AOP 的 DEBUG 日志看匹配结果;
  5. 方法本身是不是 private、final、static,或者被同类自调用。

多数"切面没反应"的问题,最后都落在第 3 步和第 5 步上。

参考

评论

推荐阅读

订阅邮件

订阅更新,及时收到最新文章。

作者