最近排查一個(gè)bug，發(fā)現(xiàn)了一系列有意思的東西，對(duì)「自定義線程池」、「Jetty線程模型」都有了一些新的認(rèn)識(shí)。

本文預(yù)計(jì)閱讀時(shí)間10分鐘，包括：

• 問(wèn)題表現(xiàn)

• 常見(jiàn)原因篩查

• 根因與源碼分析

• 最佳實(shí)踐

• 一些小TIPS

1、問(wèn)題表現(xiàn)

預(yù)發(fā)環(huán)境偶發(fā)請(qǐng)求失敗異常，服務(wù)端顯示錯(cuò)誤信息為：

Required String parameter 'seriesbaid' is not present

對(duì)應(yīng)controller的api為

乍一看，是一個(gè)非常簡(jiǎn)單的異常，請(qǐng)求參數(shù)里面沒(méi)有帶seriesbaid，導(dǎo)致失敗。

但是，經(jīng)過(guò)確認(rèn)，前端請(qǐng)求參數(shù)已經(jīng)攜帶了seriesbaid，而且為“偶發(fā)失敗”，并不是常見(jiàn)的參數(shù)傳遞問(wèn)題。

2、常見(jiàn)原因篩查

2.1 網(wǎng)關(guān)參數(shù)丟失？

由于前端請(qǐng)求到達(dá)后端服務(wù)中會(huì)經(jīng)過(guò)網(wǎng)關(guān)，所以一開始懷疑是否網(wǎng)關(guān)丟失了傳遞參數(shù)。

經(jīng)過(guò) 調(diào)用鏈分析，在偶發(fā)的失敗的請(qǐng)求中，也確認(rèn)已經(jīng)傳遞了querystring。所以網(wǎng)關(guān)沒(méi)有丟失參數(shù)傳遞。

2.2 特殊字符導(dǎo)致參數(shù)轉(zhuǎn)換失敗 ？

既然已經(jīng)傳遞了querystring到后端服務(wù)，那么一種常見(jiàn)的原因，由于queryString中帶有特殊字符而導(dǎo)致解析成queryParam失敗了。

會(huì)是這個(gè)問(wèn)題嗎？

我們通過(guò)在服務(wù)中繼承一個(gè)spring-web的OncePerRequestFilter，對(duì)請(qǐng)求參數(shù)進(jìn)行打印。

在偶發(fā)的失敗的請(qǐng)求中，找到了以下日志

2021-12-29 15:36:05,536 INFO [com.xxx.interceptor.RequestLoggingFilter] - shouldLog - swanparameter:traceId:fb2266d3687911ecb5f3cf045ea19ac3; query:seriesbaid=3FO4K4SLX2IW&x_plugin=custom&x_bz=&locale=zh_CN&x_resourceId=&x_resourceVersion=; parameterMap:{};

比較遺憾，我們確認(rèn)了請(qǐng)求中確實(shí)有querystring而沒(méi)有成功解析為queryParam，但是這個(gè)querystring中，并沒(méi)有期望的特殊字符，講道理是可以解析成功的。

既然常見(jiàn)原因無(wú)法解釋，只能去源碼撈一把了。

2.3 去源碼撈一把

我們的網(wǎng)絡(luò)容器使用了jetty，所以HttpServletRequest的實(shí)現(xiàn)是jetty的Request類。

Request類中，對(duì)queryString的解析是在?getParameters()?的時(shí)候。

我們發(fā)現(xiàn)，當(dāng)異常請(qǐng)求進(jìn)來(lái)的時(shí)候，這里的判斷
_queryParameter竟然不是null，而是一個(gè)空對(duì)象。

而正常請(qǐng)求，這里判斷_queryParameter為null，然后進(jìn)行解析。

所以，還是要從源碼去分析了。

3、根因與源碼分析

3.1 _queryParamter為什么不是null了？

我們通過(guò)在Request類中設(shè)置多個(gè)斷點(diǎn)，找到了原因。整理過(guò)程如下圖所示。

1）同步請(qǐng)求A快速完成返回。

當(dāng)請(qǐng)求A進(jìn)來(lái)，在一次Http請(qǐng)求結(jié)束后（controller方法返回客戶端），會(huì)進(jìn)行相應(yīng)的recycle()操作，這里包括Requst對(duì)象執(zhí)行recycle()方法，清理相關(guān)參數(shù)，包括_queryParameters。

2）異步任務(wù)延遲響應(yīng)，在recycle()后重新設(shè)置了_queryParameter屬性。

在請(qǐng)求A執(zhí)行過(guò)程中，使用「自定義線程池」異步執(zhí)行了一個(gè)方法B（方法較慢）。方法B中，從RequestContextHolder中獲取了HttpServletRequest，然后通過(guò)request.getParameter()獲取請(qǐng)求頭。

因?yàn)榇藭r(shí)_queryParameters為null，因此extractQueryParameters()方法就解析了一個(gè)空的對(duì)象放進(jìn)去。

3）新請(qǐng)求C進(jìn)入，返回異常。

當(dāng)新的請(qǐng)求C進(jìn)入后端服務(wù)，拿到了同一個(gè)Request對(duì)象，由于此時(shí)_queryParameters不為null，因此跳過(guò)了extractQueryParameters()，導(dǎo)致應(yīng)該解析的queryString無(wú)法被解析，controller拋出異常。

總結(jié)：一旦主線程執(zhí)行完畢，完成recycle過(guò)程，而異步線程執(zhí)行較慢，異步線程中的任何request.getParameter()行為會(huì)破壞Request對(duì)象的recycle，導(dǎo)致_queryParameters屬性為空對(duì)象而不是null，從而導(dǎo)致新的請(qǐng)求失敗。

3.2 異步線程中，RequestContextHolder還能拿到Request對(duì)象？（根本原因）

我們知道RequestContextHolder是基于ThreadLocal實(shí)現(xiàn)的。因此，在異步線程中，是無(wú)法直接通過(guò)

RequestContextHolder.getRequestAttributes()獲取主線程的HttpServletRequest。
問(wèn)題出在了「自定義線程池」
ThreadPoolExecutorWithMonitor中。

里面自定義實(shí)現(xiàn)了一個(gè)內(nèi)部類DecorateRunnableTask來(lái)處理任務(wù)。

內(nèi)部類DecorateRunnableTask繼承了內(nèi)部類DecorateTask，保存了主線程的RequestAttributes對(duì)象。

然后在異步線程執(zhí)行前，通過(guò)before()方法設(shè)置到了當(dāng)前線程的RequestContextHolder中。

總結(jié)：給異步線程傳遞RequestAttributes對(duì)象，是造成Request對(duì)象泄漏的根本原因！

3.3 兩個(gè)請(qǐng)求，為什么會(huì)共享一個(gè)Request對(duì)象？

本來(lái)上面的分析基本已經(jīng)找到了Bug的原因，但是我仔細(xì)想了下，又覺(jué)得有點(diǎn)奇怪。

兩個(gè)請(qǐng)求，為什么會(huì)共享一個(gè)Request對(duì)象？

如果是使用了相關(guān)池化技術(shù)，那怎么能在兩個(gè)請(qǐng)求找到同一個(gè)對(duì)象，然后穩(wěn)定復(fù)現(xiàn)呢？因此，又繼續(xù)去研究了下jetty的相關(guān)內(nèi)容。

jetty 9.x整體架構(gòu)圖：

SelectorManager + ManagedSelector +QueuedThreadPool?組成了「Reactor線程模型」。對(duì)于一個(gè)http請(qǐng)求，SelectorManager分配給某一個(gè)ManagedSelector創(chuàng)建HttpConnection對(duì)象，然后在QueuedThreadPool中執(zhí)行相應(yīng)的IO操作。

HttpConnection對(duì)象持有HttpChannel對(duì)象，HttpChannel中持有了Request對(duì)象（就是HttpServletRequest）。

網(wǎng)關(guān)到后端服務(wù)之間使用的是Http請(qǐng)求，默認(rèn)為長(zhǎng)連接，因此，在短時(shí)間內(nèi)的新的請(qǐng)求（長(zhǎng)連接結(jié)束前），會(huì)復(fù)用同一個(gè)HttpConnection對(duì)象。

4、最佳實(shí)踐

1. 不要給異步線程傳遞RequestAttributes對(duì)象并進(jìn)行保存。

2. 如果需要相關(guān)請(qǐng)求參數(shù)，可以新建上下文對(duì)象存儲(chǔ)參數(shù)后進(jìn)行傳遞?；蛘呤褂肨ransmittableThreadLocal。

5、一些小TIPS

5.1?jetty源碼不匹配

在對(duì)jetty的Request類進(jìn)行debug時(shí)，一開始這里遇到一個(gè)小坑，idea一直源碼匹配不上。從github上把 jetty源碼拉下來(lái)，按照引入的jetty版本進(jìn)行本地mvn install，還是不一致。

根據(jù)pom的依賴分析，可以看到引入的jetty版本為9.4.12。

后來(lái)突然想起來(lái)，這個(gè)項(xiàng)目雖然是springboot項(xiàng)目，但是并不是打成jar包通過(guò)內(nèi)置jetty容器啟動(dòng)的。而是打成了war包，本地通過(guò)jetty-maven-plugin的jetty:run啟動(dòng)的。這里使用的jetty版本為9.4.9。

所以，我們需要按照jetty-maven-plugin的版本來(lái)選擇jetty的源碼。

5.2?「偶發(fā)問(wèn)題」難以復(fù)現(xiàn)

考慮到篇幅原因與閱讀體驗(yàn)，本文在排查過(guò)程中，沒(méi)有展開說(shuō)明一個(gè)非常困難的地方————本地如何穩(wěn)定復(fù)現(xiàn)「偶發(fā)問(wèn)題」異常請(qǐng)求。

真實(shí)排查過(guò)程中，本地穩(wěn)定復(fù)現(xiàn)耗費(fèi)了大量時(shí)間。如果不是本地可以穩(wěn)定復(fù)現(xiàn)，后面的debug也無(wú)從談起。

后面主要根據(jù)代碼的近期變更情況，發(fā)現(xiàn)了一個(gè)異步請(qǐng)求的引入，將異步改為同步后，發(fā)現(xiàn)就不會(huì)再出現(xiàn)這個(gè)問(wèn)題了。

所以才從異步請(qǐng)求出發(fā)，多次嘗試后，進(jìn)行了穩(wěn)定復(fù)現(xiàn)。

所以本次排查的一個(gè)重要收獲，就是對(duì)于一些故障的排查，可以考慮從近期的「各種變更」中去尋找線索。

往期熱門筆記合集推薦：

• HBase原理與實(shí)戰(zhàn)筆記合集

• MySQL實(shí)戰(zhàn)筆記合集

• Canal/Otter源碼與實(shí)戰(zhàn)筆記合集

• Java實(shí)戰(zhàn)技巧筆記合集

原創(chuàng)：阿丸筆記（微信公眾號(hào)：aone_note），歡迎?分享，轉(zhuǎn)載請(qǐng)保留出處。

掃描下方二維碼可以關(guān)注我哦～

? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? 覺(jué)得不錯(cuò)，就點(diǎn)個(gè)?再看?吧??

如果有任何疑問(wèn)或者建議，歡迎?寫留言?或者?微信?和我聯(lián)系哦～