
上周帮朋友排查一个线上接口某个查询接口平均耗时从 80ms 涨到了 900ms压测环境却一切正常。大家第一反应是看 SQL、看慢查询结果 MySQL 那边一切正常Redis 命中率也高。折腾了半天最后用耗时追踪把调用链路上每个环节的耗时打出来才发现问题出在框架里一个毫不起眼的 JSON 序列化工具上——某个版本升级后兜底逻辑走了反射单次序列化多了 3ms高峰期一叠加接口直接被打爆。这就是 Java 性能调优最真实的样子大部分性能问题不是某个大函数写得烂而是散落在调用链路上的小热点。而找到这些小热点靠猜是猜不出来的必须有耗时追踪工具把“时间花在哪了”客观地摆出来。这次我要分享的就是一套非常轻量的方案核心就一行注解能让你在现有 Spring 项目里快速实现毫秒级耗时追踪定位热点效率翻几倍。这套方案适用于绝大多数 Java 开发者不管你是刚接触 Java 基础的新人还是在维护老项目的资深工程师都能用得上。它也经常出现在 Java 面试题和八股文里——代理模式、反射、AOP、性能监控全是高频考点。更重要的是它不像 APM 全家桶那样需要引入一堆重量级组件轻量、可控、能落地看完你就能直接抄作业。1. 内容整体设计与思路拆解1.1 为什么耗时追踪才是性能调优的第一步很多人调优的第一反应是“优化代码”比如把 for 循环改成 stream、把 synchronized 换成 CAS、给 HashMap 预设初始容量。这些操作不是没用而是顺序错了。在没有数据支撑的情况下做局部优化就像在黑屋子里找一只黑猫大概率白费功夫。耗时追踪解决的是“时间花在哪”的问题。一次接口调用从进入 Controller 到返回中间可能经过拦截器、鉴权、参数校验、业务逻辑、多次数据库查询、Redis 缓存、外部 HTTP 调用、JSON 序列化每一环都在消耗时间。如果不知道每一环各花了多少毫秒你根本不知道从哪下手。举个真实的例子。我优化过一个分页查询接口最初以为瓶颈在 SQL 上因为数据量到了百万级。结果给 DAO 层加了耗时追踪之后发现SQL 执行只占 20% 的时间剩下的 60% 都耗在了一个循环里反复调用某个工具类的类型转换方法上。把那一处改掉之后接口整体耗时从 600ms 降到 150ms效果立竿见影。所以说性能调优的正确打开方式永远是先追踪、后优化。谁耗时最长谁就是重点照顾对象。这比任何经验主义都靠谱。1.2 方案选型为什么用注解 AOP 而不是手动打点实现耗时追踪最简单粗暴的方式是在每个方法里的前后各加一行 System.currentTimeMillis()然后相减。这个方法不是不行但问题很现实侵入性太强代码里到处是计时器的变量改起来麻烦删起来也麻烦而且同一个逻辑复制到十来个方法里本身就是一种坏味道。更优雅的做法是把“计时”这个横切逻辑抽出来通过注解 AOP 切面的方式统一处理。你在目标方法上打一个 CostTime 注解切面自动在方法执行前后记录时间然后输出日志。这样业务代码零侵入想追踪哪个方法就标哪个方法不想要了删掉注解即可。这套思路背后其实是 Java 动态代理和反射机制。Spring AOP 在运行时为目标对象生成代理对象调用目标方法时先经过代理代理里就能插入计时逻辑。对于实际开发来说你不需要手写代理代码Spring 已经帮你封装好了你只需要定义好切面逻辑和注解规则。为什么选注解而不是配置项因为注解的可读性最好。你看到CostTime(queryOrderList)就知道这个方法需要被追踪语义清晰代码即文档。相比之下在 XML 或 properties 里维护一长串方法名列表后期维护成本太高而且修改配置不一定比修改注解安全。2. 核心细节解析与实操要点2.1 自定义注解与切面的完整实现先看注解的定义。这里需要定义一个运行时注解作用于方法上Target(ElementType.METHOD) Retention(RetentionPolicy.RUNTIME) public interface CostTime { String value() default ; }Retention(RetentionPolicy.RUNTIME)这行非常关键它决定了注解在运行时是否还能被读取。如果写成了SOURCE或CLASS反射拿不到AOP 切面也就无法识别。新手经常在这里踩坑切记。切面的实现使用 Spring AOP 的Around环绕通知Aspect Component public class CostTimeAspect { private static final Logger log LoggerFactory.getLogger(CostTimeAspect.class); Around(annotation(costTime)) public Object around(ProceedingJoinPoint joinPoint, CostTime costTime) throws Throwable { long start System.nanoTime(); String methodName joinPoint.getSignature().toShortString(); try { return joinPoint.proceed(); } finally { long costMs TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start); String bizName costTime.value(); if (bizName null || bizName.isEmpty()) { bizName methodName; } log.info([耗时追踪] {} 耗时 {} ms, bizName, costMs); } } }几个细节值得展开。第一计时单位用System.nanoTime()而不是System.currentTimeMillis()。纳秒级时间戳不是墙钟时间而是专门用来测量时间间隔的不受系统时间调整影响精度也更高。虽然日志里我把它转成了毫秒输出但计算过程用纳秒能避免部分场景下毫秒精度不够的问题。第二joinPoint.proceed()放在 try 块里finally里做日志输出。这样即使目标方法抛异常也能记录耗时不会因为异常导致计时逻辑失效。当然如果你不想记录异常场景的耗时也可以在 catch 里单独处理但大多数情况建议 finally。第三切面表达式的写法。annotation(costTime)这种绑定方式会把注解对象直接注入通知方法的参数里方便读取注解上配置的业务名。如果你不需要读取注解属性也可以简化为Around(annotation(com.example.CostTime))后者写法更通用但拿不到注解实例。2.2 为什么用 AOP 而不是字节码增强说到耗时追踪实现方案其实不止 AOP 一条路。业内常用的还有 Java Agent 字节码增强、Instrumentation、OpenTelemetry 等。它们各有优劣需要根据场景选。字节码增强是很多 APM 工具的底层原理比如 SkyWalking、Arthas 的某些能力就是用字节码插桩实现的。这种方式能做到完全无侵入连注解都不用加启动时通过 premain 在类加载前改写字节码把计时逻辑织入目标方法。听起来更“黑科技”但代价是复杂度高、排错难而且对团队的技术门槛要求不低。Spring AOP 的优点是足够简单。它基于动态代理在运行时创建代理对象逻辑集中在切面类里出了问题最多是代理不生效不会影响业务功能本身。对于绝大多数业务系统来说这个方案已经足够。说到 AOP 的原理这里插一句这也是 Java 面试题的高频考点。Spring AOP 默认使用 JDK 动态代理如果目标类实现了接口代理类通过Proxy.newProxyInstance生成如果目标类没有实现接口Spring 会自动切换到 CGLIB 代理通过生成目标类的子类来实现增强。理解这一点对排查问题很重要因为 JDK 代理只能作用于接口方法CGLIB 可以作用于类方法。如果你在调用链路上发现某个类明明加了注解但切面不生效优先排查是不是代理机制引起的比如当前对象使用this调用内部方法此时this是原生对象而不是代理对象切面自然就绕过去了。3. 实操过程与核心环节实现3.1 环境准备与基础配置开始之前先确认项目环境。这套方案基于 Spring Boot但不强求版本只要用了 Spring AOP 即可。这里我以 Spring Boot 2.7.x 为例。第一步确认依赖。在pom.xml里确保有spring-boot-starter-aopdependency groupIdorg.springframework.boot/groupId artifactIdspring-boot-starter-aop/artifactId /dependency有的项目之前没引入过 AOP只装了 Web 依赖这一步容易漏。引入之后 Spring Boot 会自动开启 AOP 支持。第二步定义注解和切面类代码就是上面那一套。建议把注解和切面放在独立包里比如com.example.cost方便管理和复用。第三步在启动类上加不加EnableAspectJAutoProxySpring Boot 项目通常不用显式加因为spring-boot-starter-aop会自动配置。如果你是非 Spring Boot 的 Spring 项目就需要在 XML 或配置类里显式开启aop:aspectj-autoproxy/或EnableAspectJAutoProxy。配置完成后写个测试接口验证效果RestController RequestMapping(/demo) public class DemoController { CostTime(查询用户信息) GetMapping(/user) public String getUser() throws InterruptedException { Thread.sleep(200); return ok; } }启动项目访问接口然后去控制台看日志。正常情况下能看到类似输出[耗时追踪] 查询用户信息 耗时 201 ms看到这行日志说明整条链路已经通了。接下来所有要追踪的方法只要复制一行CostTime(业务说明)即可。3.2 让耗时数据发挥更大价值接入 Metrics 与慢请求告警日志输出只是第一步。在真实的性能调优场景里日志看久了会疲劳而且你不可能一直盯着控制台。更靠谱的做法是把耗时数据接入 Metrics 体系让数据自动聚合、自动告警。我这里推荐一个成本很低的方案Micrometer。它是 Spring Boot 默认的指标门面接入 Prometheus 只需要加一个依赖dependency groupIdio.micrometer/groupId artifactIdmicrometer-registry-prometheus/artifactId /dependency然后在切面里把耗时数据注册到 MeterRegistry 里。改进后的切面类似这样Aspect Component public class CostTimeAspect { private final MeterRegistry registry; public CostTimeAspect(MeterRegistry registry) { this.registry registry; } Around(annotation(costTime)) public Object around(ProceedingJoinPoint joinPoint, CostTime costTime) throws Throwable { long start System.nanoTime(); String bizName costTime.value(); try { return joinPoint.proceed(); } finally { long costMs TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start); registry.timer(method.cost.time, biz, bizName) .record(costMs, TimeUnit.MILLISECONDS); } } }Micrometer 的 Timer 会帮你在内部聚合 P50、P95、P99 等分位数这些指标在性能调优里非常有用。P99 能告诉你最差的 1% 请求慢到什么程度比平均值实在得多——平均值很容易被极端值拉偏而 P99 才能真正反映用户体感。接入 Prometheus 之后通过 Grafana 面板可以看到每个业务方法的耗时趋势。配合阈值告警比如某方法 P99 超过 300ms 就触发告警你就能在用户投诉之前发现问题。这已经是完整的性能监控闭环了而代码层面你依然只是加了一行注解。3.3 实测效果一次真实调优的对比数据我用一个实际案例来说明这个方案的效率提升。某项目的一个聚合接口代码里依次调用了用户服务、订单服务、商品服务三次 RPC 调用加上本地的数据组装总量不算大但用户反馈“转圈很久”。加注解追踪之后切面日志清晰展示方法耗时queryUserBaseInfo45msqueryUserOrders380msqueryProductInfo120ms本地数据组装90ms合计635ms问题一目了然订单查询占了 60% 的耗时。顺着这个方向深挖发现订单服务里一个查询走了 MySQL 的深分页OFFSET拉到了 5 万行后面导致 SQL 执行越来越慢。改成游标分页之后该方法耗时降到 40ms接口总耗时从 635ms 降到 180ms 左右。这个优化过程里耗时追踪帮我把排查范围从整个接口缩小到具体方法至少节省了半天的排查时间。用“效率飙升 300%”来形容并不夸张——以前靠猜和盲查大概率要在好几个方向上反复试错。4. 常见问题与排查技巧实录4.1 切面不生效的五种原因这个方案写起来简单但实际用起来最常见的问题就是“注解加了日志没输出”。下面这五种原因是我见过最多的。第一忘记引入 AOP 依赖。单独使用spring-boot-starter-web是不会自动带 AOP 能力的必须显式加上spring-boot-starter-aop。第二注解的Retention写错。注解设计阶段RetentionPolicy.RUNTIME是硬性要求写成了 CLASS 或 SOURCE运行时反射读不到切面自然拿不到通知。第三this调用问题。在一个 Bean 的内部方法里直接调用另一个加了注解的方法此时this指向原始对象而不是代理对象切面不会触发。解决方法是用AopContext.currentProxy()或把被调方法拆到另一个 Bean 里。第四切面类没有被 Spring 管理。切面需要标注Component或在配置里显式声明为 Bean否则 Spring 不会创建代理。第五Around表达式写错。建议直接使用annotation(costTime)这种绑定式写法不容易出错。4.2 高并发场景下的性能损耗控制有人担心加 AOP 切面会影响性能这个担心是合理的。AOP 本身通过代理调用多了一层方法调用确实有额外开销但这个开销通常非常小一次代理调用大约在微秒级。真正需要关注的不是代理本身而是切面里的代码。不要在切面里做耗时操作比如打印大对象、做字符串拼接、同步调用外部接口。切面代码越轻量越好。日志输出也要注意如果接口 QPS 很高每行日志都会对性能造成压力这时候就要结合采样来追踪比如只记录超过 100ms 的请求或者按比例采样。给切面加上阈值控制的示例Around(annotation(costTime)) public Object around(ProceedingJoinPoint joinPoint, CostTime costTime) throws Throwable { long start System.nanoTime(); try { return joinPoint.proceed(); } finally { long costMs TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start); if (costMs 100) { log.info([耗时追踪] {} 耗时 {} ms, costTime.value(), costMs); } } }这样只记录慢请求日志量大幅减少问题反而更容易暴露。性能调优的目标是守护接口的 SLA而不是记录每一个请求的完整轨迹。4.3 耗时数据如何与 MySQL 慢查询关联既然提到了 MySQL 性能调优这里多说一句。很多时候接口耗时高的根源在数据库但只看应用层的耗时追踪还不够需要把应用层的耗时数据和 MySQL 的慢查询日志关联起来。具体怎么做在切面里可以额外记录一个 traceId然后在日志里输出。同时在 MySQL 的慢查询日志里或者通过 performance_schema 记录的 SQL 执行时间用 traceId 或者大致时间窗口去对齐就能看到一次慢接口对应的具体 SQL。在切面里集成 traceId 的简易写法String traceId UUID.randomUUID().toString().replace(-, ); log.info([耗时追踪] traceId{} {} 耗时 {} ms, traceId, costTime.value(), costMs);更规范的方案是引入 SLF4J 的 MDC在进入请求时埋入 traceId日志里自动带上这里给个思路不再展开。关联上之后你会发现自己排查慢接口的能力会上一个台阶应用链路追踪定位方法SQL 日志定位具体语句双管齐下MySQL 慢查询的优化也就有方向了。5. 进阶玩法与后续扩展思路5.1 支持异步方法与自定义返回阈值如果项目里用了Async那切面默认是拿不到子线程里的耗时的因为异步方法会在线程池里执行代理逻辑和业务逻辑不在同一个线程。解决办法有两种要么在异步方法内部同步打点要么把耗时追踪从 AOP 换成 TTLTransmittableThreadLocal方案阿里开源的一个专门解决线程池上下文传递的工具。对于大多数业务场景我更建议简单做异步方法内部自己计时或者不追踪异步方法只追踪入口。异步链路的追踪属于可观测性的深水区没有足够的收益不值得为了它引入复杂度。自定义返回值阈值的思路也值得做。上面提到了只记录慢请求但不同业务方的“慢”标准不一样订单接口 200ms 就算慢报表导出接口 2s 都能接受。可以在注解里加一个threshold属性比如CostTime(value 导出报表, threshold 1000)切面逻辑里只有在超过阈值时才输出日志。这样同一套代码适配所有业务但每个方法的告警标准又能独立配置。5.2 从代码追踪走向链路追踪全景最后说一个方向当你把单个方法的耗时追踪做熟练之后会发现一个局限——它只能告诉你“这个方法的耗时是多少”但没法告诉你在分布式环境下一次跨服务的请求全链路是怎么走完的。这时候就需要接触到链路追踪体系了。Java 生态里比较常见的方案有 Zipkin、SkyWalking、OpenTelemetry它们的核心思想是给一次请求分配全局唯一的 traceId每一段调用都挂在同一个 traceId 下形成一个完整的调用树。和 AOP 耗时追踪的关系是互补的AOP 适合快速定位单应用内的方法级热点链路追踪适合跨应用排查调用关系和网络耗时。我的建议是先把这个轻量方案用熟再按需升级。在项目体量还没到多服务治理的复杂度时一行注解带来的收益已经很大了。等真正需要跨服务排查时再考虑引入 SkyWalking 或 OpenTelemetry会平滑得多。6. 实操心得与个人建议这套方案从第一次写出来到现在我在好几个项目里反复用过最大的体会是性能调优工具不在于多在于能不能一句话说清楚“慢在哪”。一行CostTime能做到的恰恰就是让慢点无所遁形。最后再分享一个小技巧。给业务方法取名时不要随便写个英文名用中文描述最佳比如“查询订单列表”“导出对账单”。为什么因为日志输出之后你大概率不会再去翻代码看这个英文方法名对应什么业务直接中文描述能省掉很多脑力劳动。团队协作时这个细节对排查问题效率的提升非常明显。还有一点切面里的日志级别建议用 info 而不是 debug。生产环境日志级别通常不会开到 debug一旦开 debug 日志量爆炸误伤系统。用 info 级别平时正常输出配合阈值控制既不会刷屏又能保留关键信息。我个人使用下来的最终版本是这样的AOP 切面负责采集数据Micrometer 负责聚合指标Prometheus Grafana 负责展示和告警MySQL 慢查询日志负责兜底排查 DB 层。整条链路加起来不超过 200 行代码但性能问题的定位效率提升了不止一个量级。希望你这边的项目也能从第一个CostTime注解开始告别抓瞎式调优。