ARTICLE · INTELLIGENCE

战地情报 · 详情页

来自尧图项目组的一线实战观察与深度解析

Spring Boot AOP异步执行:彻底告别日志切面拖慢接口

Spring Boot AOP异步执行:彻底告别日志切面拖慢接口 做后端开发这几年我在日志记录和操作审计这类需求上栽过不少跟头。最早是直接在业务代码里一行行手写日志后来改用AOP切面统一处理切面是清爽了可新的问题又来了——日志接口慢、消息队列抖动、第三方通知超时不管哪个环节出幺蛾子业务接口就跟着遭殃。这时候我才意识到切面里的这些非核心动作压根就不该跟主流程绑在同一个线程里同步执行。于是就有了这套“Spring Boot AOP 异步执行方案”。说白了就是在AOP切面里把耗时的横切逻辑日志落库、操作审计、埋点上报、消息通知交给独立的线程池异步执行让主业务线程只干自己的正事。这篇文章会从方案选型、原理剖析、完整代码、实测踩坑四个层面展开适合刚接触Spring Boot的初级开发者也适合已经在用AOP但发现切面拖慢接口性能、想优化的人。读完你不仅能照抄一套能跑的代码还能搞清楚里面每个配置背后的为什么。1. 为什么必须用AOP异步一个日志切面拖慢接口的教训1.1 从同步切面到异步切面的真实背景先讲一个我实际遇到的场景。某个项目里给所有Controller层接口加了一个操作日志切面需求是记录每个请求的用户、路径、参数、响应时间和状态码。一开始逻辑很简单业务方法跑完切面里拼一条日志然后同步写入数据库日志表。单机低并发的时候一切正常接口响应时间差不多在30到50毫秒左右。后来数据量上来日志表膨胀插入语句从两毫秒慢慢涨到了十几毫秒碰上数据库锁竞争、连接池不够用的时候切面里的日志插入甚至要等上百毫秒。最要命的是日志写入失败还会直接抛出异常把原本正常的业务请求也给打挂了。这就是典型的横切逻辑对主流程的“反向污染”——你只是想记个日志结果它把接口搞超时了。为了解耦和提速我当时先想到的是把日志写入改成异步但最开始的实现很粗糙就是在切面方法里手动 new 一个线程去写日志。这样做的后果是每次请求都要创建新线程频繁的线程上下文切换开销反而更大而且线程不受Spring容器管理连接池、事务、异常处理全都跟不上。后来才老老实实回到Spring的 Async 体系用线程池统一管理异步任务。1.2 三个候选方案的取舍对比在确定用Spring自带异步之前我对比过三种常见的异步切面实现方式方案实现方式优点缺点手动创建线程切面里直接 new Thread简单粗暴代码量最少线程不受管控频繁创建销毁开销大无法复用无法监控消息队列通知切面里投递MQ消息下游消费解耦彻底削峰能力强适合重任务引入额外中间件排查问题链路变长小项目运维成本高Spring Async异步执行切面委托线程池执行任务原生支持线程可复用可用线程池监控和Spring事务/异常体系兼容需要正确配置线程池异步方法内部的事务和主事务是隔离的最终我选择了 Spring Async 方案。理由是这套方案对现有代码侵入最小、不需要额外部署中间件而且线程池可以精细控制核心线程数、队列容量、拒绝策略都能自己定制。对于日志记录、统计埋点这类轻量异步任务来说完全够用。1.3 先搞清楚AOP在Spring里的执行机制聊异步之前得先把AOP的底子捋一遍。Spring AOP的核心是动态代理它不像AspectJ那样去修改字节码而是利用JDK动态代理或CGLIB给目标Bean生成一个代理对象外部调用的时候实际调用的就是代理对象增强后的方法。JDK代理要求目标类实现接口生成的代理类只对接口方法生效CGLIB则是通过生成目标类的子类来实现代理不要求接口。Spring Boot 2.x之后默认优先用CGLIB除非手动设置 proxyTargetClassfalse。理解这个机制的意义在于后面排查“AOP没生效”时十有八九都和代理有关。AOP的通知类型里有五种Before前置、After后置、AfterReturning返回后、AfterThrowing异常后、Around环绕。在异步切面场景里位置不同语义完全不同。比如记录用户操作日志通常用Around比较合适因为它能同时拿到方法执行前参数、执行后的结果和执行耗时而单纯的接口访问统计Before加AfterReturning就够了。2. 核心原理剖析AOP切面里的异步到底发生了什么2.1 代理对象、切面Bean和异步执行的协作关系可能有人会问AOP和异步这两个机制是怎么串在一起的说出来其实很简单Spring的 Async 底层用的也是代理机制。当你在某个方法上标注 AsyncSpring会为主Bean再次生成一层异步代理。也就是说如果你的业务Bean先被AOP增强再被异步代理包裹那调用链路就是外部调用 - 异步代理 - AOP代理 - 目标方法。这也是为什么异步切面方案里切面类本身既是一个Spring Bean被AOP机制扫描切面方法内部又要调用异步Bean的方法去执行耗时任务。两者各司其职AOP负责拦截主流程的调用点异步代理负责把任务从当前线程中“丢”到线程池。有个关键细节必须强调切面切片只对Spring容器管理的Bean生效。如果你的目标类是被 new 出来的或者Bean的创建过程绕过了Spring IoC容器那么任何AOP都不会生效。很多新手把Controller、Service的实例手动new出来用结果切面一点反应都没有就是栽在这里。2.2 异步方法的事务问题跨线程就是跨事务这是整套方案里最容易翻车的知识点。Spring事务的底层实现是基于ThreadLocal把数据库连接绑定到当前线程上的DataSourceTransactionManager持有的连接本质上属于发起事务的那个线程。这意味着你在主线程里开启了事务A然后调用了一个异步方法去更新数据那个异步方法执行时用的是线程池里的另一个线程它不在事务A的上下文中只能自己开一个独立的事务。画个生活化类比事务就像一个只能在固定区间内行驶的工作证主线程办了证但异步线程是另一个区的员工没有这个证进去就得重新办一张临时证。所以异步方法里提交的数据要么用自己的新事务要么完全不参与事务绝不会被主线程的事务统一回滚。这就带来一个鲜明的实战后果如果你在切面里异步写日志主业务流程成功异步日志写入却在最后一步失败主流程不会感知日志也不会跟着回滚。对“日志能不能丢”这个问题业务上要有明确预期。我在做操作审计时这个特性其实是好事——审计和业务解耦业务失败也照样得记录失败日志。2.3 异步切面里的异常处理边界异步方法抛出的异常默认不向上传递。主线程调异步方法的那一刻如果任务丢进线程池就返回了异常发生在其他线程主线程根本接不到。如果不处理线程池任务异常会被Executor吞掉连个日志都不留排查问题的时候特别憋屈。所以异步方法内部的try-catch是必备操作尤其是做日志记录这种不能因为子线程失败影响主流程的场景。对需要感知结果的异步任务还可以用 Future 或 CompletableFuture 返回值主线程通过 get() 拿结果但要注意那样又会引入阻塞等待和异步的初衷相矛盾。实操经验是日志、埋点、通知类任务彻底不关心结果用完即走状态同步类任务最多用 CompletableFuture 在回调里处理后续逻辑而不是同步等待。3. 从零搭建一个完整的AOP异步执行示例3.1 环境准备与依赖引入这部分的示例基于 Spring Boot 2.7.xJDK 8及以上都行。核心依赖只有一个Spring Boot的web和aop starter其他的按项目实际需要加。下面是我用的 pom.xml 关键片段dependency groupIdorg.springframework.boot/groupId artifactIdspring-boot-starter-web/artifactId /dependency dependency groupIdorg.springframework.boot/groupId artifactIdspring-boot-starter-aop/artifactId /dependency dependency groupIdorg.springframework.boot/groupId artifactIdspring-boot-starter-jdbc/artifactId /dependency如果你是做日志落库的场景还需要把数据库相关的依赖加进来。但要注意aop starter是必须的它会把 aspectjweaver 和 Spring AOP 相关类都拉进来缺少这个依赖注解和切面类都不会生效。3.2 定义线程池配置核心参数的一次到位直接使用Spring默认的异步执行器不是不行但坑太多。默认的 SimpleAsyncTaskExecutor 有个特点它每次执行都会创建一个新线程不是真正意义上的复用高并发下线程数量会失控。更稳妥的做法是自建一个 ThreadPoolTaskExecutor 并且指定线程名前缀方便排查日志时知道是哪个线程跑的。下面是我项目里比较成熟的一套配置核心参数以“IO密集型任务”为基准设计Configuration EnableAsync public class AsyncPoolConfig { Bean(asyncExecutor) public ThreadPoolTaskExecutor asyncExecutor() { ThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor(); // 核心线程数日常并发量的大概值留点余量 executor.setCorePoolSize(8); // 最大线程数瞬时尖峰时的上限 executor.setMaxPoolSize(16); // 队列容量当核心线程满时任务先排队 executor.setQueueCapacity(200); // 线程名前缀日志和监控里一搜就能定位 executor.setThreadNamePrefix(async-log-); // 空闲线程存活时间 executor.setKeepAliveSeconds(60); // 拒绝策略队列和线程都满了由调用者线程执行 executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy()); executor.initialize(); return executor; } }这里的每个参数都不是拍脑袋定的需要结合业务量去推。核心线程数先按接口QPS估算一般日常请求量下查询或插入日志的耗时如果是10毫秒一个线程一秒能处理100个任务那么100 QPS只需要一个线程就能撑住考虑到波动留三四倍余量选的8个核心线程足够。队列容量不要设得太大太大虽然不丢任务但会造成任务积压日志延迟严重200这个值对日志类任务来说能容忍突发流量而不丢数据。拒绝策略我选 CallerRunsPolicy 是刻意的。线程池满了之后这个策略会让提交任务的线程也就是主业务线程自己去执行任务相当于降级回同步模式。这样做的优点是绝对不丢任务代价是某种极端情况下主线程会被拖慢。相比丢弃任务丢日志我更愿意接受偶尔的全同步兜底关键日志一条都不能少。还要注意最后一行 executor.initialize() 不是随便写的。ThreadPoolTaskExecutor 在容器启动时如果声明成 Bean 且注入位置正确通常Spring会帮你初始化但有些场景下提前调 getThreadPoolExecutor() 或使用 Lazy 注入时手动 initialize 能避免一些奇怪的懒加载问题。3.3 编写一个自定义操作日志注解有了线程池我们还需要一个入口来标记“哪些方法要走异步切面”。这里我选择自定义注解而不是直接写 Around(execution(...)) 这种大范围切点。自定义注解的好处是精确到方法级别想控制哪些接口需要记录就在方法上标一个注解不用去匹配包路径也不容易误伤其他方法。Target(ElementType.METHOD) Retention(RetentionPolicy.RUNTIME) Documented public interface OperationLog { // 操作模块名 String module() default ; // 操作类型如查询、新增、修改、删除 String type() default QUERY; // 备注信息 String desc() default ; }RetentionPolicy.RUNTIME 必须保留否则Spring AOP在运行期拿不到注解信息。这个注解本身不包含复杂逻辑它存在的意义是给切面一个“钩子”。3.4 编写异步切面类接下来是核心部分——异步切面。先直接放完整代码然后再逐段解释。Component Aspect public class OperationLogAspect { private static final Logger log LoggerFactory.getLogger(OperationLogAspect.class); Autowired private AsyncLogHandler asyncLogHandler; Around(annotation(operationLog)) public Object record(ProceedingJoinPoint joinPoint, OperationLog operationLog) throws Throwable { long startTime System.currentTimeMillis(); Object result; try { result joinPoint.proceed(); } catch (Throwable throwable) { // 业务方法执行失败也照常记录日志让审计知道发生了异常 asyncLogHandler.save(buildLog(joinPoint, operationLog, startTime, null, throwable.getMessage())); throw throwable; } long costTime System.currentTimeMillis() - startTime; // 业务成功异步记录正常日志 asyncLogHandler.save(buildLog(joinPoint, operationLog, startTime, costTime, null)); return result; } private OperationLogEntity buildLog(ProceedingJoinPoint joinPoint, OperationLog operationLog, long startTime, Long costTime, String errorMsg) { OperationLogEntity entity new OperationLogEntity(); entity.setModule(operationLog.module()); entity.setType(operationLog.type()); entity.setDesc(operationLog.desc()); entity.setMethod(joinPoint.getSignature().toShortString()); Object[] args joinPoint.getArgs(); if (args ! null args.length 0) { entity.setParams(JSON.toJSONString(args)); } entity.setStartTime(new Date(startTime)); entity.setCostTime(costTime); entity.setErrorMsg(errorMsg); return entity; } }切面本身的执行时机是在业务方法调用的线程里也就是说拦截、计时、参数拼接这些轻量操作依然消耗主线程时间只不过真正耗时的数据库写入被我们转嫁到了异步线程池。注意到切面里 try-catch 了业务方法的异常目的是保证无论业务成功还是失败操作系统日志都被记录不会因为主流程报错就丢失审计信息。可能有人会问既然用了Around通知是不是所有逻辑都写在切面里就够了为什么还要单独搞一个 AsyncLogHandler Bean原因很简单Async 注解必须作用在由Spring容器管理且通过代理调用的方法上如果你直接在切面类自己的方法上加 Async而被切面类内部直接调用的方法是不经过代理的异步就静默失效了。所以把异步方法抽到另一个独立Bean中通过自动注入来调用才能保证代理生效。Component public class AsyncLogHandler { private static final Logger log LoggerFactory.getLogger(AsyncLogHandler.class); Async(asyncExecutor) public void save(OperationLogEntity entity) { try { // 这里模拟真实落库或发送到消息队列 log.info(异步保存日志: {}, JSON.toJSONString(entity)); Thread.sleep(100); } catch (Exception e) { log.error(异步日志保存失败, e); } } }AsyncLogHandler 的 save 方法上有 Async(asyncExecutor)这个注解告诉Spring调用这个方法时不直接在当前线程里执行而是把它封装成一个任务丢进 asyncExecutor 这个线程池。方法内部我专门 try-catch 了一把虽然日志保存不会因为异常影响主流程但如果不捕获异常信息可能直接丢了后续想排查日志缺失原因都没得查。这里的 Thread.sleep(100) 是刻意模拟耗时场景用来在测试时验证主线程确实没被拖慢。如果只想对切面内一小部分逻辑做异步而不想引入额外的Async方法也可以结合CompletableFuture在切面里提交任务但实际效果不如独立异步Bean清晰推荐用上面的写法。3.5 在业务方法上打上注解然后是业务侧。拿一个简单的订单查询接口举例RestController RequestMapping(/order) public class OrderController { GetMapping(/detail) OperationLog(module 订单模块, type QUERY, desc 查询订单详情) public ResultString getOrderDetail(RequestParam(orderId) Long orderId) { // 模拟业务处理比如查库、调外部接口 return Result.success(订单详情数据); } }加上 OperationLog 之后这个接口一旦被调用切面就会拦截。你不需要在业务代码里写任何日志相关逻辑所有横切关注点都集中在切面和异步处理器里代码整洁度比过去一行行手写日志高出一大截。3.6 启动验证与耗时对比写一个小的测试Controller接口验证异步效果。开启两个请求第一个走没有异步切面的普通接口第二个走上文加了日志注解的接口。我用一个简单的循环调用接口100次统计平均响应时间。测试结果非常直观场景平均响应时间日志写入是否完成无AOP切面25ms无日志AOP同步写入日志145ms已完成AOP异步写入日志38ms异步完成日志稍后落库再看线程池日志输出里会出现类似 async-log-1、async-log-2 的线程名而主线程是 http-nio-8080-exec-XX。这从侧面印证了日志任务确实被移交给独立线程处理了主线程没有被阻塞。4. 实战中的坑与排查技巧4.1 异步静默失效为什么 Async 加了却没效果这个坑我遇到太多次了。典型场景是代码里明明写了 Async但是方法还是同步执行接口依旧被拖慢。原因无非下面几种首先检查启动类或配置类有没有加 EnableAsync。这个注解是开启异步代理的总开关漏了它Async 就是一个普通注释Spring根本不会处理。其次是代理失效问题。如果异步方法是被同类中的另一个方法直接调用的比如在同一个Service里methodA() 调 methodB()而 methodB() 上标注了 AsyncmethodA() 里直接调 methodB() 时走的是 this.methodB()不经过Spring生成的代理对象异步自然就失效了。正确做法是把 methodB 拆到另一个Service里或者注入自身的代理对象。再就是方法访问修饰符问题。Spring AOP默认只能代理public方法如果 Async 标注在private或protected方法上代理逻辑根本不会生效。这和AOP的CGLIB机制有关确保方法是public是基本要求。排查这个问题时可以开启Spring AOP的debug日志在 application.yml 里加这么一行配置logging: level: org.springframework.aop: DEBUG然后启动看控制台如果输出中包含“proxy”相关的增强日志说明AOP代理创建成功了。也可以用强制类型转换来验证AsyncLogHandler handler applicationContext.getBean(AsyncLogHandler.class); System.out.println(是否为代理对象: (handler instanceof org.springframework.aop.framework.ProxyFactoryBean));或者直接打印类名看到class ...$$EnhancerBySpringCGLIB$$...这样的后缀就说明代理生效了。4.2 事务不回滚异步任务里写的数据库到底算什么这个问题的场景特别容易混淆。假如你在一个事务方法里调用了异步日志方法异步方法内部自己去更新另一张表接着主事务抛异常回滚。很多人第一反应是“我都回滚了异步里写的数据也应该没了”但实际上异步方法用的是单独事务主事务的回滚管不到它。所以设计时有一条红线需要心里有数凡是和主业务有强一致性要求的写操作都不能放进异步切面。比如订单金额变更后更新账户余额表就不能用这种异步方案一旦主流程成功但异步更新失败数据就永久不一致了。只有日志、审计、通知这类允许最终一致甚至允许丢失的数据才适合放进异步逻辑。如果一定要在异步任务里做数据库操作建议方法上显式加上 Transactional(propagation Propagation.REQUIRES_NEW)让异步方法自己开启一个独立事务并确保你不希望它被主事务影响时业务是接受的。不要指望Spring默认行为帮你兜底。4.3 线程池满与拒绝策略的取舍线程池参数设计不合理最常见的现象有两种。一种是核心线程数太小、队列容量太小高并发时大量任务被拒绝日志大量丢失另一种是核心线程数开太大低并发时白白占着系统资源。我在线上项目经历过一次报警某次大促流量冲高接口QPS从平时的500飙到3000日志切面线程池队列迅速填满由于当时配置的是 DiscardPolicy 策略超出容量的任务全被静默丢弃了。虽然业务接口没受影响但事后复盘发现那段时间的操作日志缺口很大。从那之后我所有核心系统的线程池拒绝策略一律改成没得商量的一条要么CallerRunsPolicy要么AbortPolicy加报警。丢数据永远比拖慢接口更不可接受尤其是审计类数据少一条后续纠纷都说不清楚。CallerRunsPolicy虽然会让主线程在极端情况下帮忙干异步活但这是保数据的底线操作。同时线程池监控必须跟上。Spring的ThreadPoolTaskExecutor可以通过 Actuator 暴露指标或者你自己定时输出线程池活跃数、队列大小、任务完成数。我习惯在日志里每5分钟打一次线程池状态Scheduled(cron 0 */5 * * * ?) public void monitorAsyncPool() { ThreadPoolTaskExecutor executor SpringContextHolder.getBean(asyncExecutor); ThreadPoolExecutor poolExecutor executor.getThreadPoolExecutor(); log.info(线程池大小{}, 活跃数{}, 队列容量{}, 队列当前{}, 完成任务数{}, poolExecutor.getPoolSize(), poolExecutor.getActiveCount(), executor.getQueueCapacity(), poolExecutor.getQueue().size(), poolExecutor.getCompletedTaskCount()); }发现队列容量长时间一半以上就要考虑扩容或者排查是否有慢任务卡住了线程。异步任务也不能完全撒手不管监控在手心里不慌。4.4 异步任务内容膨胀从轻量日志到“伪异步”还有一个实战体会很多人搞完了异步切面觉得“反正都异步了”就把重业务逻辑也往异步里塞这是大忌。异步不改变任务本身的耗时它只是让耗时不再阻塞主线程但如果任务提交速度大于消费速度队列会积压最终表现为日志延迟越来越久甚至触发拒绝策略。有一次我们接了一个需求用户下单成功后切面异步调用推荐算法实时计算相似商品并更新推荐列表。这个算法单个就要跑两三秒并发高的时候队列里堆了几千个任务用户下单后可能十几分钟后才看到推荐更新。后来把这个重任务移到消息队列由独立服务异步消费才把问题解决。用AOP异步方案的准则是单个任务执行时间不超过几百毫秒任务本身无状态不依赖主流程返回结果允许一定的延迟到达。凡是满足不了这三点还是老老实实用MQ或定时任务去扛别在AOP切面里硬磨。5. 结合实际项目的一点总结与扩展建议这个方案在我项目里已经稳定运行一年多再聊几个扩展方向。如果日志数据量很大不需要每个异步任务都去实时写数据库可以先写到本地内存队列批量攒到一定条数或每隔几秒统一刷库减少数据库I/O压力。Spring的 Async 配合批量插入是天然契合的异步线程池本身就是一批一批地消费任务。如果对日志的完整性有更高要求还可以在切面里把日志实体先序列化为JSON异步任务里先写本地文件再由其他组件同步到日志平台。这样切面几乎零耗时也不依赖外部存储的可用性。总之思路是固定的AOP负责“截”数据异步负责“搬”数据线程池负责“稳住”吞吐。我在实际使用中还有一个体会可能就是这套方案最核心的底线思维异步化不能丢重点也不能全盘异步化。非核心动作才配异步核心链路该同步还是同步否则排查线上问题时你会发现明明功能正常数据却到处缺角那个滋味比接口慢一点难受得多。比例怎么拿捏多踩几次坑就有感觉了。
RELATED READING

延伸阅读

更多一线实战笔记与深度复盘,助您持续精进