Spring Boot 用 AOP 做方法级日志与耗时统计:@Around 切面实战

Spring Boot 用 AOP 做方法级日志与耗时统计:Around 切面实战排查线上慢接口时,最想知道的是「到底哪个方法慢」。最土的办法是在每个 Service 方法开头long start System.currentTimeMillis(),结尾算差值打日志。写三五个方法还行,几十个方法全手动埋点,代码里到处是和业务无关的计时噪声,还容易漏掉某个 return 分支导致日志不打。Spring AOP 就是干这个的:把「记日志、算耗时」这种横切关注点从业务代码里剥离,用一个切面统一织入。这篇手把手写一个Around切面,自动给指定方法打入参、出参、耗时和异常日志,顺带讲清几个新手必踩的坑。朴素写法:计时代码淹没业务先看手动埋点长什么样:publicOrdercreateOrder(LonguserId,BigDecimalamount){longstartSystem.currentTimeMillis();log.info(createOrder 入参 userId{}, amount{},userId,amount);try{OrderorderdoCreate(userId,amount);// 真正的业务就这一行log.info(createOrder 耗时 {}ms,System.currentTimeMillis()-start);returnorder;}catch(Exceptione){log.error(createOrder 异常,e);throwe;}}真正的业务只有doCreate一行,其余全是计时和日志。每个方法都这么写,重复且易错——比如某个 early return 分支忘了打耗时日志,排查时就断线了。第一步:引依赖,开一个自定义注解先加 AOP 依赖(Spring Boot 里一个 starter 搞定):dependencygroupIdorg.springframework.boot/groupIdartifactIdspring-boot-starter-aop/artifactId/dependency我们不想给「所有方法」都织日志,而是想精确控制哪些方法要统计。用一个自定义注解当「标记」最清晰:importjava.lang.annotation.*;Target(ElementType.METHOD)// 只能标在方法上Retention(RetentionPolicy.RUNTIME)// 运行时可反射读到,AOP 才能识别publicinterfaceLogExecution{Stringvalue()default;// 可选:给这次统计起个业务名}Retention(RUNTIME)是关键——注解信息必须保留到运行时,切面才读得到。写成默认的CLASS级别,运行期就拿不到注解,切面永远不触发。第二步:写一个 Around 切面Around是环绕通知,能力最全:方法执行前后都能插代码,还能拿到入参、控制是否放行、捕获返回值和异常。importorg.aspectj.lang.ProceedingJoinPoint;importorg.aspectj.lang.annotation.Around;importorg.aspectj.lang.annotation.Aspect;importorg.aspectj.lang.reflect.MethodSignature;importorg.slf4j.*;importorg.springframework.stereotype.Component;importjava.util.Arrays;AspectComponent// 必须交给 Spring 管理,切面才生效publicclassLogExecutionAspect{privatestaticfinalLoggerlogLoggerFactory.getLogger(LogExecutionAspect.class);// 切点:所有标了 LogExecution 的方法Around(annotation(logExecution))publicObjectaround(ProceedingJoinPointpjp,LogExecutionlogExecution)throwsThrowable{MethodSignaturesig(MethodSignature)pjp.getSignature();StringnamelogExecution.value().isEmpty()?sig.getMethod().getName()// 没起名就用方法名:logExecution.value();log.info([{}] 入参: {},name,Arrays.toString(pjp.getArgs()));longstartSystem.currentTimeMillis();try{Objectresultpjp.proceed();// 放行,执行真正的业务方法longcostSystem.currentTimeMillis()-start;log.info([{}] 返回: {}, 耗时: {}ms,name,result,cost);returnresult;// 必须把结果原样返回}catch(Throwablee){longcostSystem.currentTimeMillis()-start;log.error([{}] 异常: {}, 耗时: {}ms,name,e.getMessage(),cost);throwe;// 必须重新抛出,别把异常吞了}}}两个「必须」划重点:pjp.proceed()的返回值必须原样 return。忘了 return,业务方法的结果就被切面吞掉,调用方永远拿到null。catch 里必须throw e重新抛。切面只是旁观记录,不该改变业务的异常语义。吞掉异常会让上层以为一切正常,是极隐蔽的 bug。第三步:在业务方法上贴注解ServicepublicclassOrderService{LogExecution(创建订单)publicOrdercreateOrder(LonguserId,BigDecimalamount){returndoCreate(userId,amount);// 业务干净了,埋点交给切面}}调用后日志自动产出:[创建订单] 入参: [1001, 99.90] [创建订单] 返回: Order(id8, ...), 耗时: 43ms业务代码回归纯净,计时和日志被切面统一接管。想给哪个方法加统计,贴个注解即可,再不用复制那堆System.currentTimeMillis()。最容易踩的坑:同类内部调用,切面不生效这是 Spring AOP 的头号陷阱。AOP 靠代理对象拦截方法,只有「从外部通过 Spring 注入的 bean 调进来」才会走代理。同一个类里 A 方法直接调用本类的 B 方法(this.B()),走的是原始对象,绕过了代理,切面不触发:ServicepublicclassOrderService{publicvoidbatchCreate(ListReqreqs){for(Reqr:reqs){createOrder(r.userId,r.amount);// this.createOrder,切面不生效!}}LogExecution(创建订单)publicOrdercreateOrder(LonguserId,BigDecimalamount){...}}batchCreate里调createOrder,日志一条都不打——因为是this自调用,没经过代理。解决办法有几种,最简单的是把被切的方法拆到另一个 bean里,通过注入调用:ServicepublicclassOrderService{privatefinalOrderCreatorcreator;// 注入另一个 beanpublicOrderService(OrderCreatorcreator){this.creatorcreator;}publicvoidbatchCreate(ListReqreqs){for(Reqr:reqs){creator.createOrder(r.userId,r.amount);// 走代理,切面生效}}}记住这条规律:AOP 只拦「跨 bean」的调用,同类自调用一律失效。这和 SpringTransactional、Async失效是同一个根因,理解一次受用三处。小结AOP 剥离横切关注点:日志、耗时、鉴权这类和业务无关的代码,用切面统一织入,业务方法回归纯净。自定义注解当开关:注解Retention必须是RUNTIME,配合Around(annotation(...))精确控制切哪些方法。Around两个必须:proceed()的返回值原样 return、catch 里重新throw,否则会吞返回值或吞异常。切面类要Aspect Component:交给 Spring 管理才生效。头号坑:同类自调用失效。AOP 靠代理拦截,this.method()绕过代理;把被切方法拆到另一个 bean、经注入调用即可。这和Transactional/Async自调用失效同源。一句话记忆:AOP 是给方法「套壳」记账的代理,注解标 RUNTIME、around 别吞返回值和异常、自调用记得走别的 bean。