行：徹底告別日志切面拖慢接口)
做后端開發(fā)這幾年我在日志記錄和操作審計(jì)這類需求上栽過不少跟頭。最早是直接在業(yè)務(wù)代碼里一行行手寫日志后來(lái)改用AOP切面統(tǒng)一處理切面是清爽了可新的問題又來(lái)了——日志接口慢、消息隊(duì)列抖動(dòng)、第三方通知超時(shí)不管哪個(gè)環(huán)節(jié)出幺蛾子業(yè)務(wù)接口就跟著遭殃。這時(shí)候我才意識(shí)到切面里的這些非核心動(dòng)作壓根就不該跟主流程綁在同一個(gè)線程里同步執(zhí)行。于是就有了這套“Spring Boot AOP 異步執(zhí)行方案”。說白了就是在AOP切面里把耗時(shí)的橫切邏輯日志落庫(kù)、操作審計(jì)、埋點(diǎn)上報(bào)、消息通知交給獨(dú)立的線程池異步執(zhí)行讓主業(yè)務(wù)線程只干自己的正事。這篇文章會(huì)從方案選型、原理剖析、完整代碼、實(shí)測(cè)踩坑四個(gè)層面展開適合剛接觸Spring Boot的初級(jí)開發(fā)者也適合已經(jīng)在用AOP但發(fā)現(xiàn)切面拖慢接口性能、想優(yōu)化的人。讀完你不僅能照抄一套能跑的代碼還能搞清楚里面每個(gè)配置背后的為什么。1. 為什么必須用AOP異步一個(gè)日志切面拖慢接口的教訓(xùn)1.1 從同步切面到異步切面的真實(shí)背景先講一個(gè)我實(shí)際遇到的場(chǎng)景。某個(gè)項(xiàng)目里給所有Controller層接口加了一個(gè)操作日志切面需求是記錄每個(gè)請(qǐng)求的用戶、路徑、參數(shù)、響應(yīng)時(shí)間和狀態(tài)碼。一開始邏輯很簡(jiǎn)單業(yè)務(wù)方法跑完切面里拼一條日志然后同步寫入數(shù)據(jù)庫(kù)日志表。單機(jī)低并發(fā)的時(shí)候一切正常接口響應(yīng)時(shí)間差不多在30到50毫秒左右。后來(lái)數(shù)據(jù)量上來(lái)日志表膨脹插入語(yǔ)句從兩毫秒慢慢漲到了十幾毫秒碰上數(shù)據(jù)庫(kù)鎖競(jìng)爭(zhēng)、連接池不夠用的時(shí)候切面里的日志插入甚至要等上百毫秒。最要命的是日志寫入失敗還會(huì)直接拋出異常把原本正常的業(yè)務(wù)請(qǐng)求也給打掛了。這就是典型的橫切邏輯對(duì)主流程的“反向污染”——你只是想記個(gè)日志結(jié)果它把接口搞超時(shí)了。為了解耦和提速我當(dāng)時(shí)先想到的是把日志寫入改成異步但最開始的實(shí)現(xiàn)很粗糙就是在切面方法里手動(dòng) new 一個(gè)線程去寫日志。這樣做的后果是每次請(qǐng)求都要?jiǎng)?chuàng)建新線程頻繁的線程上下文切換開銷反而更大而且線程不受Spring容器管理連接池、事務(wù)、異常處理全都跟不上。后來(lái)才老老實(shí)實(shí)回到Spring的 Async 體系用線程池統(tǒng)一管理異步任務(wù)。1.2 三個(gè)候選方案的取舍對(duì)比在確定用Spring自帶異步之前我對(duì)比過三種常見的異步切面實(shí)現(xiàn)方式方案實(shí)現(xiàn)方式優(yōu)點(diǎn)缺點(diǎn)手動(dòng)創(chuàng)建線程切面里直接 new Thread簡(jiǎn)單粗暴代碼量最少線程不受管控頻繁創(chuàng)建銷毀開銷大無(wú)法復(fù)用無(wú)法監(jiān)控消息隊(duì)列通知切面里投遞MQ消息下游消費(fèi)解耦徹底削峰能力強(qiáng)適合重任務(wù)引入額外中間件排查問題鏈路變長(zhǎng)小項(xiàng)目運(yùn)維成本高Spring Async異步執(zhí)行切面委托線程池執(zhí)行任務(wù)原生支持線程可復(fù)用可用線程池監(jiān)控和Spring事務(wù)/異常體系兼容需要正確配置線程池異步方法內(nèi)部的事務(wù)和主事務(wù)是隔離的最終我選擇了 Spring Async 方案。理由是這套方案對(duì)現(xiàn)有代碼侵入最小、不需要額外部署中間件而且線程池可以精細(xì)控制核心線程數(shù)、隊(duì)列容量、拒絕策略都能自己定制。對(duì)于日志記錄、統(tǒng)計(jì)埋點(diǎn)這類輕量異步任務(wù)來(lái)說完全夠用。1.3 先搞清楚AOP在Spring里的執(zhí)行機(jī)制聊異步之前得先把AOP的底子捋一遍。Spring AOP的核心是動(dòng)態(tài)代理它不像AspectJ那樣去修改字節(jié)碼而是利用JDK動(dòng)態(tài)代理或CGLIB給目標(biāo)Bean生成一個(gè)代理對(duì)象外部調(diào)用的時(shí)候?qū)嶋H調(diào)用的就是代理對(duì)象增強(qiáng)后的方法。JDK代理要求目標(biāo)類實(shí)現(xiàn)接口生成的代理類只對(duì)接口方法生效CGLIB則是通過生成目標(biāo)類的子類來(lái)實(shí)現(xiàn)代理不要求接口。Spring Boot 2.x之后默認(rèn)優(yōu)先用CGLIB除非手動(dòng)設(shè)置 proxyTargetClassfalse。理解這個(gè)機(jī)制的意義在于后面排查“AOP沒生效”時(shí)十有八九都和代理有關(guān)。AOP的通知類型里有五種Before前置、After后置、AfterReturning返回后、AfterThrowing異常后、Around環(huán)繞。在異步切面場(chǎng)景里位置不同語(yǔ)義完全不同。比如記錄用戶操作日志通常用Around比較合適因?yàn)樗芡瑫r(shí)拿到方法執(zhí)行前參數(shù)、執(zhí)行后的結(jié)果和執(zhí)行耗時(shí)而單純的接口訪問統(tǒng)計(jì)Before加AfterReturning就夠了。2. 核心原理剖析AOP切面里的異步到底發(fā)生了什么2.1 代理對(duì)象、切面Bean和異步執(zhí)行的協(xié)作關(guān)系可能有人會(huì)問AOP和異步這兩個(gè)機(jī)制是怎么串在一起的說出來(lái)其實(shí)很簡(jiǎn)單Spring的 Async 底層用的也是代理機(jī)制。當(dāng)你在某個(gè)方法上標(biāo)注 AsyncSpring會(huì)為主Bean再次生成一層異步代理。也就是說如果你的業(yè)務(wù)Bean先被AOP增強(qiáng)再被異步代理包裹那調(diào)用鏈路就是外部調(diào)用 - 異步代理 - AOP代理 - 目標(biāo)方法。這也是為什么異步切面方案里切面類本身既是一個(gè)Spring Bean被AOP機(jī)制掃描切面方法內(nèi)部又要調(diào)用異步Bean的方法去執(zhí)行耗時(shí)任務(wù)。兩者各司其職AOP負(fù)責(zé)攔截主流程的調(diào)用點(diǎn)異步代理負(fù)責(zé)把任務(wù)從當(dāng)前線程中“丟”到線程池。有個(gè)關(guān)鍵細(xì)節(jié)必須強(qiáng)調(diào)切面切片只對(duì)Spring容器管理的Bean生效。如果你的目標(biāo)類是被 new 出來(lái)的或者Bean的創(chuàng)建過程繞過了Spring IoC容器那么任何AOP都不會(huì)生效。很多新手把Controller、Service的實(shí)例手動(dòng)new出來(lái)用結(jié)果切面一點(diǎn)反應(yīng)都沒有就是栽在這里。2.2 異步方法的事務(wù)問題跨線程就是跨事務(wù)這是整套方案里最容易翻車的知識(shí)點(diǎn)。Spring事務(wù)的底層實(shí)現(xiàn)是基于ThreadLocal把數(shù)據(jù)庫(kù)連接綁定到當(dāng)前線程上的DataSourceTransactionManager持有的連接本質(zhì)上屬于發(fā)起事務(wù)的那個(gè)線程。這意味著你在主線程里開啟了事務(wù)A然后調(diào)用了一個(gè)異步方法去更新數(shù)據(jù)那個(gè)異步方法執(zhí)行時(shí)用的是線程池里的另一個(gè)線程它不在事務(wù)A的上下文中只能自己開一個(gè)獨(dú)立的事務(wù)。畫個(gè)生活化類比事務(wù)就像一個(gè)只能在固定區(qū)間內(nèi)行駛的工作證主線程辦了證但異步線程是另一個(gè)區(qū)的員工沒有這個(gè)證進(jìn)去就得重新辦一張臨時(shí)證。所以異步方法里提交的數(shù)據(jù)要么用自己的新事務(wù)要么完全不參與事務(wù)絕不會(huì)被主線程的事務(wù)統(tǒng)一回滾。這就帶來(lái)一個(gè)鮮明的實(shí)戰(zhàn)后果如果你在切面里異步寫日志主業(yè)務(wù)流程成功異步日志寫入?yún)s在最后一步失敗主流程不會(huì)感知日志也不會(huì)跟著回滾。對(duì)“日志能不能丟”這個(gè)問題業(yè)務(wù)上要有明確預(yù)期。我在做操作審計(jì)時(shí)這個(gè)特性其實(shí)是好事——審計(jì)和業(yè)務(wù)解耦業(yè)務(wù)失敗也照樣得記錄失敗日志。2.3 異步切面里的異常處理邊界異步方法拋出的異常默認(rèn)不向上傳遞。主線程調(diào)異步方法的那一刻如果任務(wù)丟進(jìn)線程池就返回了異常發(fā)生在其他線程主線程根本接不到。如果不處理線程池任務(wù)異常會(huì)被Executor吞掉連個(gè)日志都不留排查問題的時(shí)候特別憋屈。所以異步方法內(nèi)部的try-catch是必備操作尤其是做日志記錄這種不能因?yàn)樽泳€程失敗影響主流程的場(chǎng)景。對(duì)需要感知結(jié)果的異步任務(wù)還可以用 Future 或 CompletableFuture 返回值主線程通過 get() 拿結(jié)果但要注意那樣又會(huì)引入阻塞等待和異步的初衷相矛盾。實(shí)操經(jīng)驗(yàn)是日志、埋點(diǎn)、通知類任務(wù)徹底不關(guān)心結(jié)果用完即走狀態(tài)同步類任務(wù)最多用 CompletableFuture 在回調(diào)里處理后續(xù)邏輯而不是同步等待。3. 從零搭建一個(gè)完整的AOP異步執(zhí)行示例3.1 環(huán)境準(zhǔn)備與依賴引入這部分的示例基于 Spring Boot 2.7.xJDK 8及以上都行。核心依賴只有一個(gè)Spring Boot的web和aop starter其他的按項(xiàng)目實(shí)際需要加。下面是我用的 pom.xml 關(guān)鍵片段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如果你是做日志落庫(kù)的場(chǎng)景還需要把數(shù)據(jù)庫(kù)相關(guān)的依賴加進(jìn)來(lái)。但要注意aop starter是必須的它會(huì)把 aspectjweaver 和 Spring AOP 相關(guān)類都拉進(jìn)來(lái)缺少這個(gè)依賴注解和切面類都不會(huì)生效。3.2 定義線程池配置核心參數(shù)的一次到位直接使用Spring默認(rèn)的異步執(zhí)行器不是不行但坑太多。默認(rèn)的 SimpleAsyncTaskExecutor 有個(gè)特點(diǎn)它每次執(zhí)行都會(huì)創(chuàng)建一個(gè)新線程不是真正意義上的復(fù)用高并發(fā)下線程數(shù)量會(huì)失控。更穩(wěn)妥的做法是自建一個(gè) ThreadPoolTaskExecutor 并且指定線程名前綴方便排查日志時(shí)知道是哪個(gè)線程跑的。下面是我項(xiàng)目里比較成熟的一套配置核心參數(shù)以“IO密集型任務(wù)”為基準(zhǔn)設(shè)計(jì)Configuration EnableAsync public class AsyncPoolConfig { Bean(asyncExecutor) public ThreadPoolTaskExecutor asyncExecutor() { ThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor(); // 核心線程數(shù)日常并發(fā)量的大概值留點(diǎn)余量 executor.setCorePoolSize(8); // 最大線程數(shù)瞬時(shí)尖峰時(shí)的上限 executor.setMaxPoolSize(16); // 隊(duì)列容量當(dāng)核心線程滿時(shí)任務(wù)先排隊(duì) executor.setQueueCapacity(200); // 線程名前綴日志和監(jiān)控里一搜就能定位 executor.setThreadNamePrefix(async-log-); // 空閑線程存活時(shí)間 executor.setKeepAliveSeconds(60); // 拒絕策略隊(duì)列和線程都滿了由調(diào)用者線程執(zhí)行 executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy()); executor.initialize(); return executor; } }這里的每個(gè)參數(shù)都不是拍腦袋定的需要結(jié)合業(yè)務(wù)量去推。核心線程數(shù)先按接口QPS估算一般日常請(qǐng)求量下查詢或插入日志的耗時(shí)如果是10毫秒一個(gè)線程一秒能處理100個(gè)任務(wù)那么100 QPS只需要一個(gè)線程就能撐住考慮到波動(dòng)留三四倍余量選的8個(gè)核心線程足夠。隊(duì)列容量不要設(shè)得太大太大雖然不丟任務(wù)但會(huì)造成任務(wù)積壓日志延遲嚴(yán)重200這個(gè)值對(duì)日志類任務(wù)來(lái)說能容忍突發(fā)流量而不丟數(shù)據(jù)。拒絕策略我選 CallerRunsPolicy 是刻意的。線程池滿了之后這個(gè)策略會(huì)讓提交任務(wù)的線程也就是主業(yè)務(wù)線程自己去執(zhí)行任務(wù)相當(dāng)于降級(jí)回同步模式。這樣做的優(yōu)點(diǎn)是絕對(duì)不丟任務(wù)代價(jià)是某種極端情況下主線程會(huì)被拖慢。相比丟棄任務(wù)丟日志我更愿意接受偶爾的全同步兜底關(guān)鍵日志一條都不能少。還要注意最后一行 executor.initialize() 不是隨便寫的。ThreadPoolTaskExecutor 在容器啟動(dòng)時(shí)如果聲明成 Bean 且注入位置正確通常Spring會(huì)幫你初始化但有些場(chǎng)景下提前調(diào) getThreadPoolExecutor() 或使用 Lazy 注入時(shí)手動(dòng) initialize 能避免一些奇怪的懶加載問題。3.3 編寫一個(gè)自定義操作日志注解有了線程池我們還需要一個(gè)入口來(lái)標(biāo)記“哪些方法要走異步切面”。這里我選擇自定義注解而不是直接寫 Around(execution(...)) 這種大范圍切點(diǎn)。自定義注解的好處是精確到方法級(jí)別想控制哪些接口需要記錄就在方法上標(biāo)一個(gè)注解不用去匹配包路徑也不容易誤傷其他方法。Target(ElementType.METHOD) Retention(RetentionPolicy.RUNTIME) Documented public interface OperationLog { // 操作模塊名 String module() default ; // 操作類型如查詢、新增、修改、刪除 String type() default QUERY; // 備注信息 String desc() default ; }RetentionPolicy.RUNTIME 必須保留否則Spring AOP在運(yùn)行期拿不到注解信息。這個(gè)注解本身不包含復(fù)雜邏輯它存在的意義是給切面一個(gè)“鉤子”。3.4 編寫異步切面類接下來(lái)是核心部分——異步切面。先直接放完整代碼然后再逐段解釋。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) { // 業(yè)務(wù)方法執(zhí)行失敗也照常記錄日志讓審計(jì)知道發(fā)生了異常 asyncLogHandler.save(buildLog(joinPoint, operationLog, startTime, null, throwable.getMessage())); throw throwable; } long costTime System.currentTimeMillis() - startTime; // 業(yè)務(wù)成功異步記錄正常日志 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; } }切面本身的執(zhí)行時(shí)機(jī)是在業(yè)務(wù)方法調(diào)用的線程里也就是說攔截、計(jì)時(shí)、參數(shù)拼接這些輕量操作依然消耗主線程時(shí)間只不過真正耗時(shí)的數(shù)據(jù)庫(kù)寫入被我們轉(zhuǎn)嫁到了異步線程池。注意到切面里 try-catch 了業(yè)務(wù)方法的異常目的是保證無(wú)論業(yè)務(wù)成功還是失敗操作系統(tǒng)日志都被記錄不會(huì)因?yàn)橹髁鞒虉?bào)錯(cuò)就丟失審計(jì)信息?？赡苡腥藭?huì)問既然用了Around通知是不是所有邏輯都寫在切面里就夠了為什么還要單獨(dú)搞一個(gè) AsyncLogHandler Bean原因很簡(jiǎn)單Async 注解必須作用在由Spring容器管理且通過代理調(diào)用的方法上如果你直接在切面類自己的方法上加 Async而被切面類內(nèi)部直接調(diào)用的方法是不經(jīng)過代理的異步就靜默失效了。所以把異步方法抽到另一個(gè)獨(dú)立Bean中通過自動(dòng)注入來(lái)調(diào)用才能保證代理生效。Component public class AsyncLogHandler { private static final Logger log LoggerFactory.getLogger(AsyncLogHandler.class); Async(asyncExecutor) public void save(OperationLogEntity entity) { try { // 這里模擬真實(shí)落庫(kù)或發(fā)送到消息隊(duì)列 log.info(異步保存日志: {}, JSON.toJSONString(entity)); Thread.sleep(100); } catch (Exception e) { log.error(異步日志保存失敗, e); } } }AsyncLogHandler 的 save 方法上有 Async(asyncExecutor)這個(gè)注解告訴Spring調(diào)用這個(gè)方法時(shí)不直接在當(dāng)前線程里執(zhí)行而是把它封裝成一個(gè)任務(wù)丟進(jìn) asyncExecutor 這個(gè)線程池。方法內(nèi)部我專門 try-catch 了一把雖然日志保存不會(huì)因?yàn)楫惓Ｓ绊懼髁鞒痰绻徊东@異常信息可能直接丟了后續(xù)想排查日志缺失原因都沒得查。這里的 Thread.sleep(100) 是刻意模擬耗時(shí)場(chǎng)景用來(lái)在測(cè)試時(shí)驗(yàn)證主線程確實(shí)沒被拖慢。如果只想對(duì)切面內(nèi)一小部分邏輯做異步而不想引入額外的Async方法也可以結(jié)合CompletableFuture在切面里提交任務(wù)但實(shí)際效果不如獨(dú)立異步Bean清晰推薦用上面的寫法。3.5 在業(yè)務(wù)方法上打上注解然后是業(yè)務(wù)側(cè)。拿一個(gè)簡(jiǎn)單的訂單查詢接口舉例RestController RequestMapping(/order) public class OrderController { GetMapping(/detail) OperationLog(module 訂單模塊, type QUERY, desc 查詢訂單詳情) public ResultString getOrderDetail(RequestParam(orderId) Long orderId) { // 模擬業(yè)務(wù)處理比如查庫(kù)、調(diào)外部接口 return Result.success(訂單詳情數(shù)據(jù)); } }加上 OperationLog 之后這個(gè)接口一旦被調(diào)用切面就會(huì)攔截。你不需要在業(yè)務(wù)代碼里寫任何日志相關(guān)邏輯所有橫切關(guān)注點(diǎn)都集中在切面和異步處理器里代碼整潔度比過去一行行手寫日志高出一大截。3.6 啟動(dòng)驗(yàn)證與耗時(shí)對(duì)比寫一個(gè)小的測(cè)試Controller接口驗(yàn)證異步效果。開啟兩個(gè)請(qǐng)求第一個(gè)走沒有異步切面的普通接口第二個(gè)走上文加了日志注解的接口。我用一個(gè)簡(jiǎn)單的循環(huán)調(diào)用接口100次統(tǒng)計(jì)平均響應(yīng)時(shí)間。測(cè)試結(jié)果非常直觀場(chǎng)景平均響應(yīng)時(shí)間日志寫入是否完成無(wú)AOP切面25ms無(wú)日志AOP同步寫入日志145ms已完成AOP異步寫入日志38ms異步完成日志稍后落庫(kù)再看線程池日志輸出里會(huì)出現(xiàn)類似 async-log-1、async-log-2 的線程名而主線程是 http-nio-8080-exec-XX。這從側(cè)面印證了日志任務(wù)確實(shí)被移交給獨(dú)立線程處理了主線程沒有被阻塞。4. 實(shí)戰(zhàn)中的坑與排查技巧4.1 異步靜默失效為什么 Async 加了卻沒效果這個(gè)坑我遇到太多次了。典型場(chǎng)景是代碼里明明寫了 Async但是方法還是同步執(zhí)行接口依舊被拖慢。原因無(wú)非下面幾種首先檢查啟動(dòng)類或配置類有沒有加 EnableAsync。這個(gè)注解是開啟異步代理的總開關(guān)漏了它Async 就是一個(gè)普通注釋Spring根本不會(huì)處理。其次是代理失效問題。如果異步方法是被同類中的另一個(gè)方法直接調(diào)用的比如在同一個(gè)Service里methodA() 調(diào) methodB()而 methodB() 上標(biāo)注了 AsyncmethodA() 里直接調(diào) methodB() 時(shí)走的是 this.methodB()不經(jīng)過Spring生成的代理對(duì)象異步自然就失效了。正確做法是把 methodB 拆到另一個(gè)Service里或者注入自身的代理對(duì)象。再就是方法訪問修飾符問題。Spring AOP默認(rèn)只能代理public方法如果 Async 標(biāo)注在private或protected方法上代理邏輯根本不會(huì)生效。這和AOP的CGLIB機(jī)制有關(guān)確保方法是public是基本要求。排查這個(gè)問題時(shí)可以開啟Spring AOP的debug日志在 application.yml 里加這么一行配置logging: level: org.springframework.aop: DEBUG然后啟動(dòng)看控制臺(tái)如果輸出中包含“proxy”相關(guān)的增強(qiáng)日志說明AOP代理創(chuàng)建成功了。也可以用強(qiáng)制類型轉(zhuǎn)換來(lái)驗(yàn)證AsyncLogHandler handler applicationContext.getBean(AsyncLogHandler.class); System.out.println(是否為代理對(duì)象: (handler instanceof org.springframework.aop.framework.ProxyFactoryBean));或者直接打印類名看到class ...$$EnhancerBySpringCGLIB$$...這樣的后綴就說明代理生效了。4.2 事務(wù)不回滾異步任務(wù)里寫的數(shù)據(jù)庫(kù)到底算什么這個(gè)問題的場(chǎng)景特別容易混淆。假如你在一個(gè)事務(wù)方法里調(diào)用了異步日志方法異步方法內(nèi)部自己去更新另一張表接著主事務(wù)拋異?；貪L。很多人第一反應(yīng)是“我都回滾了異步里寫的數(shù)據(jù)也應(yīng)該沒了”但實(shí)際上異步方法用的是單獨(dú)事務(wù)主事務(wù)的回滾管不到它。所以設(shè)計(jì)時(shí)有一條紅線需要心里有數(shù)凡是和主業(yè)務(wù)有強(qiáng)一致性要求的寫操作都不能放進(jìn)異步切面。比如訂單金額變更后更新賬戶余額表就不能用這種異步方案一旦主流程成功但異步更新失敗數(shù)據(jù)就永久不一致了。只有日志、審計(jì)、通知這類允許最終一致甚至允許丟失的數(shù)據(jù)才適合放進(jìn)異步邏輯。如果一定要在異步任務(wù)里做數(shù)據(jù)庫(kù)操作建議方法上顯式加上 Transactional(propagation Propagation.REQUIRES_NEW)讓異步方法自己開啟一個(gè)獨(dú)立事務(wù)并確保你不希望它被主事務(wù)影響時(shí)業(yè)務(wù)是接受的。不要指望Spring默認(rèn)行為幫你兜底。4.3 線程池滿與拒絕策略的取舍線程池參數(shù)設(shè)計(jì)不合理最常見的現(xiàn)象有兩種。一種是核心線程數(shù)太小、隊(duì)列容量太小高并發(fā)時(shí)大量任務(wù)被拒絕日志大量丟失另一種是核心線程數(shù)開太大低并發(fā)時(shí)白白占著系統(tǒng)資源。我在線上項(xiàng)目經(jīng)歷過一次報(bào)警某次大促流量沖高接口QPS從平時(shí)的500飆到3000日志切面線程池隊(duì)列迅速填滿由于當(dāng)時(shí)配置的是 DiscardPolicy 策略超出容量的任務(wù)全被靜默丟棄了。雖然業(yè)務(wù)接口沒受影響但事后復(fù)盤發(fā)現(xiàn)那段時(shí)間的操作日志缺口很大。從那之后我所有核心系統(tǒng)的線程池拒絕策略一律改成沒得商量的一條要么CallerRunsPolicy要么AbortPolicy加報(bào)警。丟數(shù)據(jù)永遠(yuǎn)比拖慢接口更不可接受尤其是審計(jì)類數(shù)據(jù)少一條后續(xù)糾紛都說不清楚。CallerRunsPolicy雖然會(huì)讓主線程在極端情況下幫忙干異步活但這是保數(shù)據(jù)的底線操作。同時(shí)線程池監(jiān)控必須跟上。Spring的ThreadPoolTaskExecutor可以通過 Actuator 暴露指標(biāo)或者你自己定時(shí)輸出線程池活躍數(shù)、隊(duì)列大小、任務(wù)完成數(shù)。我習(xí)慣在日志里每5分鐘打一次線程池狀態(tài)Scheduled(cron 0 */5 * * * ?) public void monitorAsyncPool() { ThreadPoolTaskExecutor executor SpringContextHolder.getBean(asyncExecutor); ThreadPoolExecutor poolExecutor executor.getThreadPoolExecutor(); log.info(線程池大小{}, 活躍數(shù){}, 隊(duì)列容量{}, 隊(duì)列當(dāng)前{}, 完成任務(wù)數(shù){}, poolExecutor.getPoolSize(), poolExecutor.getActiveCount(), executor.getQueueCapacity(), poolExecutor.getQueue().size(), poolExecutor.getCompletedTaskCount()); }發(fā)現(xiàn)隊(duì)列容量長(zhǎng)時(shí)間一半以上就要考慮擴(kuò)容或者排查是否有慢任務(wù)卡住了線程。異步任務(wù)也不能完全撒手不管監(jiān)控在手心里不慌。4.4 異步任務(wù)內(nèi)容膨脹從輕量日志到“偽異步”還有一個(gè)實(shí)戰(zhàn)體會(huì)很多人搞完了異步切面覺得“反正都異步了”就把重業(yè)務(wù)邏輯也往異步里塞這是大忌。異步不改變?nèi)蝿?wù)本身的耗時(shí)它只是讓耗時(shí)不再阻塞主線程但如果任務(wù)提交速度大于消費(fèi)速度隊(duì)列會(huì)積壓最終表現(xiàn)為日志延遲越來(lái)越久甚至觸發(fā)拒絕策略。有一次我們接了一個(gè)需求用戶下單成功后切面異步調(diào)用推薦算法實(shí)時(shí)計(jì)算相似商品并更新推薦列表。這個(gè)算法單個(gè)就要跑兩三秒并發(fā)高的時(shí)候隊(duì)列里堆了幾千個(gè)任務(wù)用戶下單后可能十幾分鐘后才看到推薦更新。后來(lái)把這個(gè)重任務(wù)移到消息隊(duì)列由獨(dú)立服務(wù)異步消費(fèi)才把問題解決。用AOP異步方案的準(zhǔn)則是單個(gè)任務(wù)執(zhí)行時(shí)間不超過幾百毫秒任務(wù)本身無(wú)狀態(tài)不依賴主流程返回結(jié)果允許一定的延遲到達(dá)。凡是滿足不了這三點(diǎn)還是老老實(shí)實(shí)用MQ或定時(shí)任務(wù)去扛別在AOP切面里硬磨。5. 結(jié)合實(shí)際項(xiàng)目的一點(diǎn)總結(jié)與擴(kuò)展建議這個(gè)方案在我項(xiàng)目里已經(jīng)穩(wěn)定運(yùn)行一年多再聊幾個(gè)擴(kuò)展方向。如果日志數(shù)據(jù)量很大不需要每個(gè)異步任務(wù)都去實(shí)時(shí)寫數(shù)據(jù)庫(kù)可以先寫到本地內(nèi)存隊(duì)列批量攢到一定條數(shù)或每隔幾秒統(tǒng)一刷庫(kù)減少數(shù)據(jù)庫(kù)I/O壓力。Spring的 Async 配合批量插入是天然契合的異步線程池本身就是一批一批地消費(fèi)任務(wù)。如果對(duì)日志的完整性有更高要求還可以在切面里把日志實(shí)體先序列化為JSON異步任務(wù)里先寫本地文件再由其他組件同步到日志平臺(tái)。這樣切面幾乎零耗時(shí)也不依賴外部存儲(chǔ)的可用性?？傊悸肥枪潭ǖ腁OP負(fù)責(zé)“截”數(shù)據(jù)異步負(fù)責(zé)“搬”數(shù)據(jù)線程池負(fù)責(zé)“穩(wěn)住”吞吐。我在實(shí)際使用中還有一個(gè)體會(huì)可能就是這套方案最核心的底線思維異步化不能丟重點(diǎn)也不能全盤異步化。非核心動(dòng)作才配異步核心鏈路該同步還是同步否則排查線上問題時(shí)你會(huì)發(fā)現(xiàn)明明功能正常數(shù)據(jù)卻到處缺角那個(gè)滋味比接口慢一點(diǎn)難受得多。比例怎么拿捏多踩幾次坑就有感覺了。 Spring Boot AOP異步執(zhí)行：徹底告別日志切面拖慢接口
做后端開發(fā)這幾年我在日志記錄和操作審計(jì)這類需求上栽過不少跟頭。最早是直接在業(yè)務(wù)代碼里一行行手寫日志后來(lái)改用AOP切面統(tǒng)一處理切面是清爽了可新的問題又來(lái)了——日志接口慢、消息隊(duì)列抖動(dòng)、第三方通知超時(shí)不管哪個(gè)環(huán)節(jié)出幺蛾子業(yè)務(wù)接口就跟著遭殃。這時(shí)候我才意識(shí)到切面里的這些非核心動(dòng)作壓根就不該跟主流程綁在同一個(gè)線程里同步執(zhí)行。于是就有了這套“Spring Boot AOP 異步執(zhí)行方案”。說白了就是在AOP切面里把耗時(shí)的橫切邏輯日志落庫(kù)、操作審計(jì)、埋點(diǎn)上報(bào)、消息通知交給獨(dú)立的線程池異步執(zhí)行讓主業(yè)務(wù)線程只干自己的正事。這篇文章會(huì)從方案選型、原理剖析、完整代碼、實(shí)測(cè)踩坑四個(gè)層面展開適合剛接觸Spring Boot的初級(jí)開發(fā)者也適合已經(jīng)在用AOP但發(fā)現(xiàn)切面拖慢接口性能、想優(yōu)化的人。讀完你不僅能照抄一套能跑的代碼還能搞清楚里面每個(gè)配置背后的為什么。1. 為什么必須用AOP異步一個(gè)日志切面拖慢接口的教訓(xùn)1.1 從同步切面到異步切面的真實(shí)背景先講一個(gè)我實(shí)際遇到的場(chǎng)景。某個(gè)項(xiàng)目里給所有Controller層接口加了一個(gè)操作日志切面需求是記錄每個(gè)請(qǐng)求的用戶、路徑、參數(shù)、響應(yīng)時(shí)間和狀態(tài)碼。一開始邏輯很簡(jiǎn)單業(yè)務(wù)方法跑完切面里拼一條日志然后同步寫入數(shù)據(jù)庫(kù)日志表。單機(jī)低并發(fā)的時(shí)候一切正常接口響應(yīng)時(shí)間差不多在30到50毫秒左右。后來(lái)數(shù)據(jù)量上來(lái)日志表膨脹插入語(yǔ)句從兩毫秒慢慢漲到了十幾毫秒碰上數(shù)據(jù)庫(kù)鎖競(jìng)爭(zhēng)、連接池不夠用的時(shí)候切面里的日志插入甚至要等上百毫秒。最要命的是日志寫入失敗還會(huì)直接拋出異常把原本正常的業(yè)務(wù)請(qǐng)求也給打掛了。這就是典型的橫切邏輯對(duì)主流程的“反向污染”——你只是想記個(gè)日志結(jié)果它把接口搞超時(shí)了。為了解耦和提速我當(dāng)時(shí)先想到的是把日志寫入改成異步但最開始的實(shí)現(xiàn)很粗糙就是在切面方法里手動(dòng) new 一個(gè)線程去寫日志。這樣做的后果是每次請(qǐng)求都要?jiǎng)?chuàng)建新線程頻繁的線程上下文切換開銷反而更大而且線程不受Spring容器管理連接池、事務(wù)、異常處理全都跟不上。后來(lái)才老老實(shí)實(shí)回到Spring的 Async 體系用線程池統(tǒng)一管理異步任務(wù)。1.2 三個(gè)候選方案的取舍對(duì)比在確定用Spring自帶異步之前我對(duì)比過三種常見的異步切面實(shí)現(xiàn)方式方案實(shí)現(xiàn)方式優(yōu)點(diǎn)缺點(diǎn)手動(dòng)創(chuàng)建線程切面里直接 new Thread簡(jiǎn)單粗暴代碼量最少線程不受管控頻繁創(chuàng)建銷毀開銷大無(wú)法復(fù)用無(wú)法監(jiān)控消息隊(duì)列通知切面里投遞MQ消息下游消費(fèi)解耦徹底削峰能力強(qiáng)適合重任務(wù)引入額外中間件排查問題鏈路變長(zhǎng)小項(xiàng)目運(yùn)維成本高Spring Async異步執(zhí)行切面委托線程池執(zhí)行任務(wù)原生支持線程可復(fù)用可用線程池監(jiān)控和Spring事務(wù)/異常體系兼容需要正確配置線程池異步方法內(nèi)部的事務(wù)和主事務(wù)是隔離的最終我選擇了 Spring Async 方案。理由是這套方案對(duì)現(xiàn)有代碼侵入最小、不需要額外部署中間件而且線程池可以精細(xì)控制核心線程數(shù)、隊(duì)列容量、拒絕策略都能自己定制。對(duì)于日志記錄、統(tǒng)計(jì)埋點(diǎn)這類輕量異步任務(wù)來(lái)說完全夠用。1.3 先搞清楚AOP在Spring里的執(zhí)行機(jī)制聊異步之前得先把AOP的底子捋一遍。Spring AOP的核心是動(dòng)態(tài)代理它不像AspectJ那樣去修改字節(jié)碼而是利用JDK動(dòng)態(tài)代理或CGLIB給目標(biāo)Bean生成一個(gè)代理對(duì)象外部調(diào)用的時(shí)候?qū)嶋H調(diào)用的就是代理對(duì)象增強(qiáng)后的方法。JDK代理要求目標(biāo)類實(shí)現(xiàn)接口生成的代理類只對(duì)接口方法生效CGLIB則是通過生成目標(biāo)類的子類來(lái)實(shí)現(xiàn)代理不要求接口。Spring Boot 2.x之后默認(rèn)優(yōu)先用CGLIB除非手動(dòng)設(shè)置 proxyTargetClassfalse。理解這個(gè)機(jī)制的意義在于后面排查“AOP沒生效”時(shí)十有八九都和代理有關(guān)。AOP的通知類型里有五種Before前置、After后置、AfterReturning返回后、AfterThrowing異常后、Around環(huán)繞。在異步切面場(chǎng)景里位置不同語(yǔ)義完全不同。比如記錄用戶操作日志通常用Around比較合適因?yàn)樗芡瑫r(shí)拿到方法執(zhí)行前參數(shù)、執(zhí)行后的結(jié)果和執(zhí)行耗時(shí)而單純的接口訪問統(tǒng)計(jì)Before加AfterReturning就夠了。2. 核心原理剖析AOP切面里的異步到底發(fā)生了什么2.1 代理對(duì)象、切面Bean和異步執(zhí)行的協(xié)作關(guān)系可能有人會(huì)問AOP和異步這兩個(gè)機(jī)制是怎么串在一起的說出來(lái)其實(shí)很簡(jiǎn)單Spring的 Async 底層用的也是代理機(jī)制。當(dāng)你在某個(gè)方法上標(biāo)注 AsyncSpring會(huì)為主Bean再次生成一層異步代理。也就是說如果你的業(yè)務(wù)Bean先被AOP增強(qiáng)再被異步代理包裹那調(diào)用鏈路就是外部調(diào)用 - 異步代理 - AOP代理 - 目標(biāo)方法。這也是為什么異步切面方案里切面類本身既是一個(gè)Spring Bean被AOP機(jī)制掃描切面方法內(nèi)部又要調(diào)用異步Bean的方法去執(zhí)行耗時(shí)任務(wù)。兩者各司其職AOP負(fù)責(zé)攔截主流程的調(diào)用點(diǎn)異步代理負(fù)責(zé)把任務(wù)從當(dāng)前線程中“丟”到線程池。有個(gè)關(guān)鍵細(xì)節(jié)必須強(qiáng)調(diào)切面切片只對(duì)Spring容器管理的Bean生效。如果你的目標(biāo)類是被 new 出來(lái)的或者Bean的創(chuàng)建過程繞過了Spring IoC容器那么任何AOP都不會(huì)生效。很多新手把Controller、Service的實(shí)例手動(dòng)new出來(lái)用結(jié)果切面一點(diǎn)反應(yīng)都沒有就是栽在這里。2.2 異步方法的事務(wù)問題跨線程就是跨事務(wù)這是整套方案里最容易翻車的知識(shí)點(diǎn)。Spring事務(wù)的底層實(shí)現(xiàn)是基于ThreadLocal把數(shù)據(jù)庫(kù)連接綁定到當(dāng)前線程上的DataSourceTransactionManager持有的連接本質(zhì)上屬于發(fā)起事務(wù)的那個(gè)線程。這意味著你在主線程里開啟了事務(wù)A然后調(diào)用了一個(gè)異步方法去更新數(shù)據(jù)那個(gè)異步方法執(zhí)行時(shí)用的是線程池里的另一個(gè)線程它不在事務(wù)A的上下文中只能自己開一個(gè)獨(dú)立的事務(wù)。畫個(gè)生活化類比事務(wù)就像一個(gè)只能在固定區(qū)間內(nèi)行駛的工作證主線程辦了證但異步線程是另一個(gè)區(qū)的員工沒有這個(gè)證進(jìn)去就得重新辦一張臨時(shí)證。所以異步方法里提交的數(shù)據(jù)要么用自己的新事務(wù)要么完全不參與事務(wù)絕不會(huì)被主線程的事務(wù)統(tǒng)一回滾。這就帶來(lái)一個(gè)鮮明的實(shí)戰(zhàn)后果如果你在切面里異步寫日志主業(yè)務(wù)流程成功異步日志寫入?yún)s在最后一步失敗主流程不會(huì)感知日志也不會(huì)跟著回滾。對(duì)“日志能不能丟”這個(gè)問題業(yè)務(wù)上要有明確預(yù)期。我在做操作審計(jì)時(shí)這個(gè)特性其實(shí)是好事——審計(jì)和業(yè)務(wù)解耦業(yè)務(wù)失敗也照樣得記錄失敗日志。2.3 異步切面里的異常處理邊界異步方法拋出的異常默認(rèn)不向上傳遞。主線程調(diào)異步方法的那一刻如果任務(wù)丟進(jìn)線程池就返回了異常發(fā)生在其他線程主線程根本接不到。如果不處理線程池任務(wù)異常會(huì)被Executor吞掉連個(gè)日志都不留排查問題的時(shí)候特別憋屈。所以異步方法內(nèi)部的try-catch是必備操作尤其是做日志記錄這種不能因?yàn)樽泳€程失敗影響主流程的場(chǎng)景。對(duì)需要感知結(jié)果的異步任務(wù)還可以用 Future 或 CompletableFuture 返回值主線程通過 get() 拿結(jié)果但要注意那樣又會(huì)引入阻塞等待和異步的初衷相矛盾。實(shí)操經(jīng)驗(yàn)是日志、埋點(diǎn)、通知類任務(wù)徹底不關(guān)心結(jié)果用完即走狀態(tài)同步類任務(wù)最多用 CompletableFuture 在回調(diào)里處理后續(xù)邏輯而不是同步等待。3. 從零搭建一個(gè)完整的AOP異步執(zhí)行示例3.1 環(huán)境準(zhǔn)備與依賴引入這部分的示例基于 Spring Boot 2.7.xJDK 8及以上都行。核心依賴只有一個(gè)Spring Boot的web和aop starter其他的按項(xiàng)目實(shí)際需要加。下面是我用的 pom.xml 關(guān)鍵片段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如果你是做日志落庫(kù)的場(chǎng)景還需要把數(shù)據(jù)庫(kù)相關(guān)的依賴加進(jìn)來(lái)。但要注意aop starter是必須的它會(huì)把 aspectjweaver 和 Spring AOP 相關(guān)類都拉進(jìn)來(lái)缺少這個(gè)依賴注解和切面類都不會(huì)生效。3.2 定義線程池配置核心參數(shù)的一次到位直接使用Spring默認(rèn)的異步執(zhí)行器不是不行但坑太多。默認(rèn)的 SimpleAsyncTaskExecutor 有個(gè)特點(diǎn)它每次執(zhí)行都會(huì)創(chuàng)建一個(gè)新線程不是真正意義上的復(fù)用高并發(fā)下線程數(shù)量會(huì)失控。更穩(wěn)妥的做法是自建一個(gè) ThreadPoolTaskExecutor 并且指定線程名前綴方便排查日志時(shí)知道是哪個(gè)線程跑的。下面是我項(xiàng)目里比較成熟的一套配置核心參數(shù)以“IO密集型任務(wù)”為基準(zhǔn)設(shè)計(jì)Configuration EnableAsync public class AsyncPoolConfig { Bean(asyncExecutor) public ThreadPoolTaskExecutor asyncExecutor() { ThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor(); // 核心線程數(shù)日常并發(fā)量的大概值留點(diǎn)余量 executor.setCorePoolSize(8); // 最大線程數(shù)瞬時(shí)尖峰時(shí)的上限 executor.setMaxPoolSize(16); // 隊(duì)列容量當(dāng)核心線程滿時(shí)任務(wù)先排隊(duì) executor.setQueueCapacity(200); // 線程名前綴日志和監(jiān)控里一搜就能定位 executor.setThreadNamePrefix(async-log-); // 空閑線程存活時(shí)間 executor.setKeepAliveSeconds(60); // 拒絕策略隊(duì)列和線程都滿了由調(diào)用者線程執(zhí)行 executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy()); executor.initialize(); return executor; } }這里的每個(gè)參數(shù)都不是拍腦袋定的需要結(jié)合業(yè)務(wù)量去推。核心線程數(shù)先按接口QPS估算一般日常請(qǐng)求量下查詢或插入日志的耗時(shí)如果是10毫秒一個(gè)線程一秒能處理100個(gè)任務(wù)那么100 QPS只需要一個(gè)線程就能撐住考慮到波動(dòng)留三四倍余量選的8個(gè)核心線程足夠。隊(duì)列容量不要設(shè)得太大太大雖然不丟任務(wù)但會(huì)造成任務(wù)積壓日志延遲嚴(yán)重200這個(gè)值對(duì)日志類任務(wù)來(lái)說能容忍突發(fā)流量而不丟數(shù)據(jù)。拒絕策略我選 CallerRunsPolicy 是刻意的。線程池滿了之后這個(gè)策略會(huì)讓提交任務(wù)的線程也就是主業(yè)務(wù)線程自己去執(zhí)行任務(wù)相當(dāng)于降級(jí)回同步模式。這樣做的優(yōu)點(diǎn)是絕對(duì)不丟任務(wù)代價(jià)是某種極端情況下主線程會(huì)被拖慢。相比丟棄任務(wù)丟日志我更愿意接受偶爾的全同步兜底關(guān)鍵日志一條都不能少。還要注意最后一行 executor.initialize() 不是隨便寫的。ThreadPoolTaskExecutor 在容器啟動(dòng)時(shí)如果聲明成 Bean 且注入位置正確通常Spring會(huì)幫你初始化但有些場(chǎng)景下提前調(diào) getThreadPoolExecutor() 或使用 Lazy 注入時(shí)手動(dòng) initialize 能避免一些奇怪的懶加載問題。3.3 編寫一個(gè)自定義操作日志注解有了線程池我們還需要一個(gè)入口來(lái)標(biāo)記“哪些方法要走異步切面”。這里我選擇自定義注解而不是直接寫 Around(execution(...)) 這種大范圍切點(diǎn)。自定義注解的好處是精確到方法級(jí)別想控制哪些接口需要記錄就在方法上標(biāo)一個(gè)注解不用去匹配包路徑也不容易誤傷其他方法。Target(ElementType.METHOD) Retention(RetentionPolicy.RUNTIME) Documented public interface OperationLog { // 操作模塊名 String module() default ; // 操作類型如查詢、新增、修改、刪除 String type() default QUERY; // 備注信息 String desc() default ; }RetentionPolicy.RUNTIME 必須保留否則Spring AOP在運(yùn)行期拿不到注解信息。這個(gè)注解本身不包含復(fù)雜邏輯它存在的意義是給切面一個(gè)“鉤子”。3.4 編寫異步切面類接下來(lái)是核心部分——異步切面。先直接放完整代碼然后再逐段解釋。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) { // 業(yè)務(wù)方法執(zhí)行失敗也照常記錄日志讓審計(jì)知道發(fā)生了異常 asyncLogHandler.save(buildLog(joinPoint, operationLog, startTime, null, throwable.getMessage())); throw throwable; } long costTime System.currentTimeMillis() - startTime; // 業(yè)務(wù)成功異步記錄正常日志 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; } }切面本身的執(zhí)行時(shí)機(jī)是在業(yè)務(wù)方法調(diào)用的線程里也就是說攔截、計(jì)時(shí)、參數(shù)拼接這些輕量操作依然消耗主線程時(shí)間只不過真正耗時(shí)的數(shù)據(jù)庫(kù)寫入被我們轉(zhuǎn)嫁到了異步線程池。注意到切面里 try-catch 了業(yè)務(wù)方法的異常目的是保證無(wú)論業(yè)務(wù)成功還是失敗操作系統(tǒng)日志都被記錄不會(huì)因?yàn)橹髁鞒虉?bào)錯(cuò)就丟失審計(jì)信息?？赡苡腥藭?huì)問既然用了Around通知是不是所有邏輯都寫在切面里就夠了為什么還要單獨(dú)搞一個(gè) AsyncLogHandler Bean原因很簡(jiǎn)單Async 注解必須作用在由Spring容器管理且通過代理調(diào)用的方法上如果你直接在切面類自己的方法上加 Async而被切面類內(nèi)部直接調(diào)用的方法是不經(jīng)過代理的異步就靜默失效了。所以把異步方法抽到另一個(gè)獨(dú)立Bean中通過自動(dòng)注入來(lái)調(diào)用才能保證代理生效。Component public class AsyncLogHandler { private static final Logger log LoggerFactory.getLogger(AsyncLogHandler.class); Async(asyncExecutor) public void save(OperationLogEntity entity) { try { // 這里模擬真實(shí)落庫(kù)或發(fā)送到消息隊(duì)列 log.info(異步保存日志: {}, JSON.toJSONString(entity)); Thread.sleep(100); } catch (Exception e) { log.error(異步日志保存失敗, e); } } }AsyncLogHandler 的 save 方法上有 Async(asyncExecutor)這個(gè)注解告訴Spring調(diào)用這個(gè)方法時(shí)不直接在當(dāng)前線程里執(zhí)行而是把它封裝成一個(gè)任務(wù)丟進(jìn) asyncExecutor 這個(gè)線程池。方法內(nèi)部我專門 try-catch 了一把雖然日志保存不會(huì)因?yàn)楫惓Ｓ绊懼髁鞒痰绻徊东@異常信息可能直接丟了后續(xù)想排查日志缺失原因都沒得查。這里的 Thread.sleep(100) 是刻意模擬耗時(shí)場(chǎng)景用來(lái)在測(cè)試時(shí)驗(yàn)證主線程確實(shí)沒被拖慢。如果只想對(duì)切面內(nèi)一小部分邏輯做異步而不想引入額外的Async方法也可以結(jié)合CompletableFuture在切面里提交任務(wù)但實(shí)際效果不如獨(dú)立異步Bean清晰推薦用上面的寫法。3.5 在業(yè)務(wù)方法上打上注解然后是業(yè)務(wù)側(cè)。拿一個(gè)簡(jiǎn)單的訂單查詢接口舉例RestController RequestMapping(/order) public class OrderController { GetMapping(/detail) OperationLog(module 訂單模塊, type QUERY, desc 查詢訂單詳情) public ResultString getOrderDetail(RequestParam(orderId) Long orderId) { // 模擬業(yè)務(wù)處理比如查庫(kù)、調(diào)外部接口 return Result.success(訂單詳情數(shù)據(jù)); } }加上 OperationLog 之后這個(gè)接口一旦被調(diào)用切面就會(huì)攔截。你不需要在業(yè)務(wù)代碼里寫任何日志相關(guān)邏輯所有橫切關(guān)注點(diǎn)都集中在切面和異步處理器里代碼整潔度比過去一行行手寫日志高出一大截。3.6 啟動(dòng)驗(yàn)證與耗時(shí)對(duì)比寫一個(gè)小的測(cè)試Controller接口驗(yàn)證異步效果。開啟兩個(gè)請(qǐng)求第一個(gè)走沒有異步切面的普通接口第二個(gè)走上文加了日志注解的接口。我用一個(gè)簡(jiǎn)單的循環(huán)調(diào)用接口100次統(tǒng)計(jì)平均響應(yīng)時(shí)間。測(cè)試結(jié)果非常直觀場(chǎng)景平均響應(yīng)時(shí)間日志寫入是否完成無(wú)AOP切面25ms無(wú)日志AOP同步寫入日志145ms已完成AOP異步寫入日志38ms異步完成日志稍后落庫(kù)再看線程池日志輸出里會(huì)出現(xiàn)類似 async-log-1、async-log-2 的線程名而主線程是 http-nio-8080-exec-XX。這從側(cè)面印證了日志任務(wù)確實(shí)被移交給獨(dú)立線程處理了主線程沒有被阻塞。4. 實(shí)戰(zhàn)中的坑與排查技巧4.1 異步靜默失效為什么 Async 加了卻沒效果這個(gè)坑我遇到太多次了。典型場(chǎng)景是代碼里明明寫了 Async但是方法還是同步執(zhí)行接口依舊被拖慢。原因無(wú)非下面幾種首先檢查啟動(dòng)類或配置類有沒有加 EnableAsync。這個(gè)注解是開啟異步代理的總開關(guān)漏了它Async 就是一個(gè)普通注釋Spring根本不會(huì)處理。其次是代理失效問題。如果異步方法是被同類中的另一個(gè)方法直接調(diào)用的比如在同一個(gè)Service里methodA() 調(diào) methodB()而 methodB() 上標(biāo)注了 AsyncmethodA() 里直接調(diào) methodB() 時(shí)走的是 this.methodB()不經(jīng)過Spring生成的代理對(duì)象異步自然就失效了。正確做法是把 methodB 拆到另一個(gè)Service里或者注入自身的代理對(duì)象。再就是方法訪問修飾符問題。Spring AOP默認(rèn)只能代理public方法如果 Async 標(biāo)注在private或protected方法上代理邏輯根本不會(huì)生效。這和AOP的CGLIB機(jī)制有關(guān)確保方法是public是基本要求。排查這個(gè)問題時(shí)可以開啟Spring AOP的debug日志在 application.yml 里加這么一行配置logging: level: org.springframework.aop: DEBUG然后啟動(dòng)看控制臺(tái)如果輸出中包含“proxy”相關(guān)的增強(qiáng)日志說明AOP代理創(chuàng)建成功了。也可以用強(qiáng)制類型轉(zhuǎn)換來(lái)驗(yàn)證AsyncLogHandler handler applicationContext.getBean(AsyncLogHandler.class); System.out.println(是否為代理對(duì)象: (handler instanceof org.springframework.aop.framework.ProxyFactoryBean));或者直接打印類名看到class ...$$EnhancerBySpringCGLIB$$...這樣的后綴就說明代理生效了。4.2 事務(wù)不回滾異步任務(wù)里寫的數(shù)據(jù)庫(kù)到底算什么這個(gè)問題的場(chǎng)景特別容易混淆。假如你在一個(gè)事務(wù)方法里調(diào)用了異步日志方法異步方法內(nèi)部自己去更新另一張表接著主事務(wù)拋異?；貪L。很多人第一反應(yīng)是“我都回滾了異步里寫的數(shù)據(jù)也應(yīng)該沒了”但實(shí)際上異步方法用的是單獨(dú)事務(wù)主事務(wù)的回滾管不到它。所以設(shè)計(jì)時(shí)有一條紅線需要心里有數(shù)凡是和主業(yè)務(wù)有強(qiáng)一致性要求的寫操作都不能放進(jìn)異步切面。比如訂單金額變更后更新賬戶余額表就不能用這種異步方案一旦主流程成功但異步更新失敗數(shù)據(jù)就永久不一致了。只有日志、審計(jì)、通知這類允許最終一致甚至允許丟失的數(shù)據(jù)才適合放進(jìn)異步邏輯。如果一定要在異步任務(wù)里做數(shù)據(jù)庫(kù)操作建議方法上顯式加上 Transactional(propagation Propagation.REQUIRES_NEW)讓異步方法自己開啟一個(gè)獨(dú)立事務(wù)并確保你不希望它被主事務(wù)影響時(shí)業(yè)務(wù)是接受的。不要指望Spring默認(rèn)行為幫你兜底。4.3 線程池滿與拒絕策略的取舍線程池參數(shù)設(shè)計(jì)不合理最常見的現(xiàn)象有兩種。一種是核心線程數(shù)太小、隊(duì)列容量太小高并發(fā)時(shí)大量任務(wù)被拒絕日志大量丟失另一種是核心線程數(shù)開太大低并發(fā)時(shí)白白占著系統(tǒng)資源。我在線上項(xiàng)目經(jīng)歷過一次報(bào)警某次大促流量沖高接口QPS從平時(shí)的500飆到3000日志切面線程池隊(duì)列迅速填滿由于當(dāng)時(shí)配置的是 DiscardPolicy 策略超出容量的任務(wù)全被靜默丟棄了。雖然業(yè)務(wù)接口沒受影響但事后復(fù)盤發(fā)現(xiàn)那段時(shí)間的操作日志缺口很大。從那之后我所有核心系統(tǒng)的線程池拒絕策略一律改成沒得商量的一條要么CallerRunsPolicy要么AbortPolicy加報(bào)警。丟數(shù)據(jù)永遠(yuǎn)比拖慢接口更不可接受尤其是審計(jì)類數(shù)據(jù)少一條后續(xù)糾紛都說不清楚。CallerRunsPolicy雖然會(huì)讓主線程在極端情況下幫忙干異步活但這是保數(shù)據(jù)的底線操作。同時(shí)線程池監(jiān)控必須跟上。Spring的ThreadPoolTaskExecutor可以通過 Actuator 暴露指標(biāo)或者你自己定時(shí)輸出線程池活躍數(shù)、隊(duì)列大小、任務(wù)完成數(shù)。我習(xí)慣在日志里每5分鐘打一次線程池狀態(tài)Scheduled(cron 0 */5 * * * ?) public void monitorAsyncPool() { ThreadPoolTaskExecutor executor SpringContextHolder.getBean(asyncExecutor); ThreadPoolExecutor poolExecutor executor.getThreadPoolExecutor(); log.info(線程池大小{}, 活躍數(shù){}, 隊(duì)列容量{}, 隊(duì)列當(dāng)前{}, 完成任務(wù)數(shù){}, poolExecutor.getPoolSize(), poolExecutor.getActiveCount(), executor.getQueueCapacity(), poolExecutor.getQueue().size(), poolExecutor.getCompletedTaskCount()); }發(fā)現(xiàn)隊(duì)列容量長(zhǎng)時(shí)間一半以上就要考慮擴(kuò)容或者排查是否有慢任務(wù)卡住了線程。異步任務(wù)也不能完全撒手不管監(jiān)控在手心里不慌。4.4 異步任務(wù)內(nèi)容膨脹從輕量日志到“偽異步”還有一個(gè)實(shí)戰(zhàn)體會(huì)很多人搞完了異步切面覺得“反正都異步了”就把重業(yè)務(wù)邏輯也往異步里塞這是大忌。異步不改變?nèi)蝿?wù)本身的耗時(shí)它只是讓耗時(shí)不再阻塞主線程但如果任務(wù)提交速度大于消費(fèi)速度隊(duì)列會(huì)積壓最終表現(xiàn)為日志延遲越來(lái)越久甚至觸發(fā)拒絕策略。有一次我們接了一個(gè)需求用戶下單成功后切面異步調(diào)用推薦算法實(shí)時(shí)計(jì)算相似商品并更新推薦列表。這個(gè)算法單個(gè)就要跑兩三秒并發(fā)高的時(shí)候隊(duì)列里堆了幾千個(gè)任務(wù)用戶下單后可能十幾分鐘后才看到推薦更新。后來(lái)把這個(gè)重任務(wù)移到消息隊(duì)列由獨(dú)立服務(wù)異步消費(fèi)才把問題解決。用AOP異步方案的準(zhǔn)則是單個(gè)任務(wù)執(zhí)行時(shí)間不超過幾百毫秒任務(wù)本身無(wú)狀態(tài)不依賴主流程返回結(jié)果允許一定的延遲到達(dá)。凡是滿足不了這三點(diǎn)還是老老實(shí)實(shí)用MQ或定時(shí)任務(wù)去扛別在AOP切面里硬磨。5. 結(jié)合實(shí)際項(xiàng)目的一點(diǎn)總結(jié)與擴(kuò)展建議這個(gè)方案在我項(xiàng)目里已經(jīng)穩(wěn)定運(yùn)行一年多再聊幾個(gè)擴(kuò)展方向。如果日志數(shù)據(jù)量很大不需要每個(gè)異步任務(wù)都去實(shí)時(shí)寫數(shù)據(jù)庫(kù)可以先寫到本地內(nèi)存隊(duì)列批量攢到一定條數(shù)或每隔幾秒統(tǒng)一刷庫(kù)減少數(shù)據(jù)庫(kù)I/O壓力。Spring的 Async 配合批量插入是天然契合的異步線程池本身就是一批一批地消費(fèi)任務(wù)。如果對(duì)日志的完整性有更高要求還可以在切面里把日志實(shí)體先序列化為JSON異步任務(wù)里先寫本地文件再由其他組件同步到日志平臺(tái)。這樣切面幾乎零耗時(shí)也不依賴外部存儲(chǔ)的可用性?？傊悸肥枪潭ǖ腁OP負(fù)責(zé)“截”數(shù)據(jù)異步負(fù)責(zé)“搬”數(shù)據(jù)線程池負(fù)責(zé)“穩(wěn)住”吞吐。我在實(shí)際使用中還有一個(gè)體會(huì)可能就是這套方案最核心的底線思維異步化不能丟重點(diǎn)也不能全盤異步化。非核心動(dòng)作才配異步核心鏈路該同步還是同步否則排查線上問題時(shí)你會(huì)發(fā)現(xiàn)明明功能正常數(shù)據(jù)卻到處缺角那個(gè)滋味比接口慢一點(diǎn)難受得多。比例怎么拿捏多踩幾次坑就有感覺了。