Spring Boot AOP 自定义计时注解：定位同类调用不生效的问题

报价接口返回了正确金额，方法上的计时注解也还在，偏偏某条调用路径没有计时记录。这类问题先看调用经过哪里，比反复调整切点表达式更有效：Spring AOP 拦截的是经过代理的方法调用，同一个对象内部的普通 Java 调用不会重新穿过代理。

这里做一个能直接观察差别的小项目。报价单价为 129 元，数量限制为 1～100，业务只返回数量与总分值；自定义注解负责给报价方法加计时。三个 HTTP 入口调用同一套计算规则，但调用路线不同。跑完以后，可以同时看到正常计时、同类自调用漏计时，以及把调用放到另一个 Bean 后恢复计时。

示例使用 JDK 17、Maven 3.8.8、Spring Boot 3.5.0，采用 Spring AOP 的代理模式，不使用 AspectJ 编译期或加载期织入。这里只观察同步方法的执行区间，不能拿下面的纳秒值当作报价性能评测，也不能把它当成从浏览器到服务器的整条请求耗时。

先把计时与报价分开

新建 aop-method-lab 目录。下面所有路径都相对于项目根目录，包名统一为 lab.aop。Web 依赖用于展示结果，AOP 依赖带入注解与自动代理支持，测试依赖用于证明切面没有改变正常返回或异常传播。

pom.xml：

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
  <modelVersion>4.0.0</modelVersion>
  <parent><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-parent</artifactId><version>3.5.0</version><relativePath/></parent>
  <groupId>lab</groupId><artifactId>aop-method-lab</artifactId><version>1.0.0</version>
  <properties><java.version>17</java.version><project.build.sourceEncoding>UTF-8</project.build.sourceEncoding></properties>
  <dependencies>
    <dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-web</artifactId></dependency>
    <dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-aop</artifactId></dependency>
    <dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-test</artifactId><scope>test</scope></dependency>
  </dependencies>
  <build><plugins><plugin><groupId>org.springframework.boot</groupId><artifactId>spring-boot-maven-plugin</artifactId></plugin></plugins></build>
</project>

src/main/resources/application.properties：

server.address=127.0.0.1
server.port=31892
spring.main.banner-mode=off

src/main/java/lab/aop/AopApplication.java：

package lab.aop;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
@SpringBootApplication
public class AopApplication {
    public static void main(String[] args) { SpringApplication.run(AopApplication.class, args); }
}

注解的值是稳定的业务动作名。这里没有把请求参数拼成动作名，也没有打印所有参数和返回对象：方法耗时需要的是可聚合的标签，而订单内容、用户资料等值通常不适合直接落日志。RUNTIME 保证运行时可以取到注解，目标限制为方法。

src/main/java/lab/aop/Measured.java：

package lab.aop;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface Measured { String value(); }

为了让请求结果容易核对，记录器保留最近 100 条样本，并将动作、结果与耗时打印到标准输出。读、写和清空共用同步锁，查询返回列表快照，不把内部队列交给 Controller 修改。满 100 条后丢弃最早一条，因此它是观察窗口，不是完整审计记录。

src/main/java/lab/aop/Measurements.java：

package lab.aop;
import java.util.ArrayDeque;
import java.util.List;
import org.springframework.stereotype.Component;
@Component
public class Measurements {
    public record Sample(String action, String outcome, long durationNanos) {}
    private final ArrayDeque<Sample> samples = new ArrayDeque<>();
    public synchronized void add(Sample sample) {
        if (samples.size() == 100) samples.removeFirst();
        samples.addLast(sample);
        System.out.println("MEASURE " + sample.action() + " " + sample.outcome() + " durationNanos=" + sample.durationNanos());
    }
    public synchronized List<Sample> snapshot() { return List.copyOf(samples); }
    public synchronized void clear() { samples.clear(); }
}

环绕通知里真正执行业务的是 point.proceed()。漏掉它，报价方法就不会运行；调用两次，业务也会运行两次。这里正常返回时原样返回对象，业务抛异常时记录异常类型并重新抛出同一个异常。收尾放在 finally，成功和失败都能记录。

System.nanoTime() 用来计算经过时间，不是时间戳。采样点位于执行 proceed 前后，写入记录器发生在算出时间之后，所以该字段也不包含随后写记录与输出日志的耗时。如果以后把记录器改成远程上报或数据库写入，需要另外设计上报失败的处理，不能让监控链路随意盖掉业务异常。

src/main/java/lab/aop/TimingAspect.java：

package lab.aop;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.stereotype.Component;
@Aspect
@Component
public class TimingAspect {
    private final Measurements measurements;
    public TimingAspect(Measurements measurements) { this.measurements = measurements; }
    @Around(value = "@annotation(measured)", argNames = "point,measured")
    public Object measure(ProceedingJoinPoint point, Measured measured) throws Throwable {
        long start = System.nanoTime();
        String outcome = "success";
        try { return point.proceed(); }
        catch (Throwable failure) {
            outcome = "error:" + failure.getClass().getSimpleName();
            throw failure;
        } finally {
            measurements.add(new Measurements.Sample(measured.value(), outcome, System.nanoTime() - start));
        }
    }
}

故意保留一条没有穿过代理的路线

报价 Service 中，quote 带注解，throughSelf 则在同一个对象内调用 quote。没有第二套价格公式，这样结果差异只能来自调用路线，而不是算价规则。

src/main/java/lab/aop/QuoteService.java：

package lab.aop;
import org.springframework.stereotype.Service;
@Service
public class QuoteService {
    public record Quote(int quantity, long totalCents) {}
    @Measured("quote.calculate")
    public Quote quote(int quantity) {
        if (quantity < 1 || quantity > 100) throw new IllegalArgumentException("quantity must be1..100");
        return new Quote(quantity, 12900L * quantity);
    }
    public Quote throughSelf(int quantity) { return quote(quantity); }
}

另一个 QuoteFacade 通过构造器接收 Spring 管理的 QuoteService。这条路线适合表达两个服务职责之间的调用：外层负责流程，内层负责报价。它用来对照自调用，不意味着每遇到一个注解就必须机械拆一层类。

src/main/java/lab/aop/QuoteFacade.java：

package lab.aop;
import org.springframework.stereotype.Service;
@Service
public class QuoteFacade {
    private final QuoteService service;
    public QuoteFacade(QuoteService service) { this.service = service; }
    public QuoteService.Quote quote(int quantity) { return service.quote(quantity); }
}

三个入口分别调用 service.quote、service.throughSelf 和 facade.quote。观察接口与清空接口只是本机练习工具，没有鉴权，不应直接复制到公开管理界面。应用已绑定回环地址。

src/main/java/lab/aop/QuoteController.java：

package lab.aop;
import java.util.List;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.PostMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;
@RestController
public class QuoteController {
    private final QuoteService service;
    private final QuoteFacade facade;
    private final Measurements measurements;
    public QuoteController(QuoteService service, QuoteFacade facade, Measurements measurements) {
        this.service = service; this.facade = facade; this.measurements = measurements;
    }
    @GetMapping("/quotes")
    public QuoteService.Quote direct(@RequestParam int quantity) { return service.quote(quantity); }
    @GetMapping("/quotes/self")
    public QuoteService.Quote self(@RequestParam int quantity) { return service.throughSelf(quantity); }
    @GetMapping("/quotes/facade")
    public QuoteService.Quote facade(@RequestParam int quantity) { return facade.quote(quantity); }
    @GetMapping("/measurements")
    public List<Measurements.Sample> samples() { return measurements.snapshot(); }
    @PostMapping("/measurements/reset")
    public void reset() { measurements.clear(); }
}

src/main/java/lab/aop/QuoteErrors.java：

package lab.aop;
import java.util.Map;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.ExceptionHandler;
import org.springframework.web.bind.annotation.RestControllerAdvice;
@RestControllerAdvice
public class QuoteErrors {
    @ExceptionHandler(IllegalArgumentException.class)
    public ResponseEntity<Map<String,String>> handle(IllegalArgumentException failure) {
        return ResponseEntity.badRequest().body(Map.of("code", "BAD_QUANTITY", "message", failure.getMessage()));
    }
}

从项目根目录构建并启动，运行中的终端保持打开：

mvn clean package
java -jar target/aop-method-lab-1.0.0.jar

另开终端依次执行下面的请求。先清空记录，再查一次正常报价：

curl -sS -X POST http://127.0.0.1:31892/measurements/reset
curl -sS 'http://127.0.0.1:31892/quotes?quantity=3'
curl -sS http://127.0.0.1:31892/measurements

报价应为 {"quantity":3,"totalCents":38700}，样本列表有一条 quote.calculate，结果为 success，durationNanos 是本次运行得到的值。接下来走同类自调用：

curl -sS 'http://127.0.0.1:31892/quotes/self?quantity=3'
curl -sS http://127.0.0.1:31892/measurements
curl -sS 'http://127.0.0.1:31892/quotes/facade?quantity=2'
curl -sS http://127.0.0.1:31892/measurements

self 仍返回 38700 分，但样本数保持一条。最后 facade 返回 25800 分，样本数变成两条。这是一次完整的对照：进入代理的 throughSelf 本身没有注解，它内部调用目标对象自己的 quote 时，已经不再经过代理上的切面；Facade 持有并调用的是 Spring 注入的 Service 代理，因此又能命中注解。

Boot 在这组依赖与默认配置下使用类代理。不要因此推断所有方法都能被增强：private 方法无法由子类重写，final 方法也无法这样增强。另一个常见漏点是自己 new QuoteService()，那不是容器交付的代理对象。排查时先确认对象来源与调用方向，再看注解和切点。

失败请求应当保留失败

计时不是容错，不能把报价失败变成成功响应。分别试一次业务参数错误和一次 HTTP 参数绑定错误：

curl -i 'http://127.0.0.1:31892/quotes?quantity=0'
curl -sS http://127.0.0.1:31892/measurements
curl -i 'http://127.0.0.1:31892/quotes?quantity=not-a-number'
curl -sS http://127.0.0.1:31892/measurements

数量 0 会真正进入报价方法，得到 HTTP 400 和 BAD_QUANTITY，同时增加一条 error:IllegalArgumentException。字符串不能绑定为整数则在 MVC 参数处理阶段失败，报价方法没被调用，不会增加报价样本。看到一个 400 却没计时，并不能直接判定 AOP 失效，需要先弄清失败发生在哪一层。

下面的测试文件把这些调用关系固定下来，还检查异常对象身份与内存记录上限。保存文件后重新执行 mvn clean package，应运行六个测试。若想验证测试能发现切面未注册，可以在练习副本中去掉 TimingAspect 上的 @Component 再运行 mvn test；此时正常业务仍能算出金额，但计时条数相关测试会失败。做完恢复注解后再构建。

src/test/java/lab/aop/TimingTest.java：

package lab.aop;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Test;
import org.springframework.aop.aspectj.annotation.AspectJProxyFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import static org.junit.jupiter.api.Assertions.*;
@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.NONE)
class TimingTest {
    @Autowired QuoteService service;
    @Autowired QuoteFacade facade;
    @Autowired Measurements measurements;
    @BeforeEach void reset() { measurements.clear(); }
    @Test void externalCallMeasured() {
        assertEquals(38700, service.quote(3).totalCents());
        assertEquals(1, measurements.snapshot().size());
        assertEquals("success", measurements.snapshot().get(0).outcome());
    }
    @Test void selfCallSkipsProxy() {
        assertEquals(38700, service.throughSelf(3).totalCents());
        assertTrue(measurements.snapshot().isEmpty());
    }
    @Test void anotherBeanUsesProxy() {
        assertEquals(25800, facade.quote(2).totalCents());
        assertEquals(1, measurements.snapshot().size());
    }
    @Test void failureStillThrowsAndIsMeasured() {
        assertThrows(IllegalArgumentException.class, () -> service.quote(0));
        assertEquals("error:IllegalArgumentException", measurements.snapshot().get(0).outcome());
    }
    public static class FailureProbe {
        final RuntimeException failure;
        FailureProbe(RuntimeException failure) { this.failure = failure; }
        @Measured("probe.failure") public void fail() { throw failure; }
    }
    @Test void proxyRetainsSameExceptionObject() {
        RuntimeException marker = new IllegalStateException("marker");
        AspectJProxyFactory factory = new AspectJProxyFactory(new FailureProbe(marker));
        factory.addAspect(new TimingAspect(measurements));
        FailureProbe proxy = factory.getProxy();
        assertSame(marker, assertThrows(IllegalStateException.class, proxy::fail));
    }
    @Test void memoryRecorderOnlyRetainsLatest100() {
        for (int i = 0; i < 120; i++) measurements.add(new Measurements.Sample("fixture" + i, "success", i));
        assertEquals(100, measurements.snapshot().size());
        assertEquals("fixture20", measurements.snapshot().get(0).action());
    }
}

这段切面只适用于示例里的同步工作。方法如果返回 CompletableFuture，proceed() 返回时异步任务可能还没结束，当前数字测到的是创建或提交任务的区间。真要计异步完成耗时，应在完成回调处记录，不能沿用这里的字段解释。练习结束后，在启动应用的终端按 Ctrl+C 即可停止服务。