最近排查一個bug，發現了一系列有意思的東西，對「自定義執行緒池」、「Jetty執行緒模型」都有了一些新的認識。
本文預計閱讀時間10分鐘，包括：
- 問題表現
- 常見原因篩查
- 根因與原始碼分析
- 最佳實踐
- 一些小TIPS
1.問題表現
預發環境偶發請求失敗異常，服務端顯示錯誤資訊為：
Required String parameter 'seriesbaid' is not present對應controller的api為
@PostMapping
public Object getUserParameter(
HttpServletRequest request,
HttpServletResponse response,
@RequestParam(value = "seriesbaid") String seriesbaid){
}
乍一看，是一個非常簡單的異常，請求引數裡面沒有帶seriesbaid，導致失敗。
但是，經過確認，前端請求引數已經攜帶了seriesbaid，而且為“偶發失敗”，並不是常見的引數傳遞問題。
2.常見原因篩查
2.1 閘道器引數丟失？？
由於前端請求到達後端服務中會經過閘道器，所以一開始懷疑是否閘道器丟失了傳遞引數。
經過 呼叫鏈分析，在偶發的失敗的請求中，也確認已經傳遞了querystring。所以閘道器沒有丟失引數傳遞。
2.2 特殊字元導致引數轉換失敗 ？？
既然已經傳遞了querystring到後端服務，那麼一種常見的原因，由於queryString中帶有特殊字元而導致解析成queryParam失敗了。
會是這個問題嗎？
我們通過在服務中繼承一個spring-web的OncePerRequestFilter，對請求引數進行列印
@Override
protected void doFilterInternal(
HttpServletRequest request,
HttpServletResponse response,
FilterChain filterChain)
throws ServletException, IOException {
if ("/api/swanparameter".equals(request.getServletPath())) {
LOG.message("shouldLog - swanparameter")
.with("traceId", HunterUtils.getTraceId())
.with("query", request.getQueryString())
.with("parameterMap", JsonUtil.toJsonString(request.getParameterMap()))
.info();
}
}
在偶發的失敗的請求中，找到了以下日誌
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:{};比較遺憾，我們確認了請求中確實有querystring而沒有成功解析為queryParam，但是這個querystring中，並沒有期望的特殊字元，講道理是可以解析成功的。
既然常見原因無法解釋，只能去原始碼撈一把了。
2.3 去原始碼撈一把
我們的網路容器使用了jetty，所以HttpServletRequest的實現是jetty的Request類。
Request類中，對queryString的解析是在 getParameters() 的時候。
我們發現，當異常請求進來的時候，這裡的判斷
_queryParameter竟然不是null，而是一個空物件。
而正常請求，這裡判斷_queryParameter為null，然後進行解析。
所以，還是要從原始碼去分析了。
3. 根因與原始碼分析
3.1_queryParamter為什麼不是null了？
我們通過在Request類中設定多個斷點，找到了原因。整理過程如下圖所示。
1）同步請求A快速完成返回。
當請求A進來，在一次Http請求結束後（controller方法返回客戶端），會進行相應的recycle()操作，這裡包括Requst物件執行recycle()方法，清理相關引數，包括_queryParameters。
2）非同步任務延遲響應，在recycle()後重新設定了_queryParameter屬性。
在請求A執行過程中，使用「自定義執行緒池」非同步執行了一個方法B（方法較慢）。方法B中，從RequestContextHolder中獲取了HttpServletRequest，然後通過request.getParameter()獲取請求頭。
因為此時_queryParameters為null，因此extractQueryParameters()方法就解析了一個空的物件放進去。
3）新請求C進入，返回異常。
當新的請求C進入後端服務，拿到了同一個Request物件，由於此時_queryParameters不為null，因此跳過了extractQueryParameters()，導致應該解析的queryString無法被解析，controller丟擲異常。
總結：一旦主執行緒執行完畢，完成recycle過程，而非同步執行緒執行較慢，非同步執行緒中的任何request.getParameter()行為會破壞Request物件的recycle，導致_queryParameters屬性為空物件而不是null，從而導致新的請求失敗。
3.2 非同步執行緒中，RequestContextHolder還能拿到Request物件？（根本原因）
我們知道RequestContextHolder是基於ThreadLocal實現的。因此，在非同步執行緒中，是無法直接通過
RequestContextHolder.getRequestAttributes()獲取主執行緒的HttpServletRequest。
問題出在了「自定義執行緒池」
ThreadPoolExecutorWithMonitor中。
裡面自定義實現了一個內部類DecorateRunnableTask來處理任務。
內部類DecorateRunnableTask繼承了內部類DecorateTask，儲存了主執行緒的RequestAttributes物件。
然後在非同步執行緒執行前，通過before()方法設定到了當前執行緒的RequestContextHolder中。
總結：給非同步執行緒傳遞RequestAttributes物件，是造成Request物件洩漏的根本原因！
3.3 兩個請求，為什麼會共享一個Request物件？
本來上面的分析基本已經找到了Bug的原因，但是我仔細想了下，又覺得有點奇怪。
兩個請求，為什麼會共享一個Request物件？
如果是使用了相關池化技術，那怎麼能在兩個請求找到同一個物件，然後穩定復現呢？因此，又繼續去研究了下jetty的相關內容。
jetty 9.x整體架構圖：
SelectorManager + ManagedSelector +QueuedThreadPool 組成了「Reactor執行緒模型」。對於一個http請求，SelectorManager分配給某一個ManagedSelector建立HttpConnection物件，然後在QueuedThreadPool中執行相應的IO操作。
HttpConnection物件持有HttpChannel物件，HttpChannel中持有了Request物件（就是HttpServletRequest）。
閘道器到後端服務之間使用的是Http請求，預設為長連線，因此，在短時間內的新的請求（長連線結束前），會複用同一個HttpConnection物件。
4.最佳實踐
1）不要給非同步執行緒傳遞RequestAttributes物件並進行儲存
2）如果需要相關請求引數，可以新建上下文物件儲存引數後進行傳遞。或者使用TransmittableThreadLocal。
5.一些小TIPS
5.1 jetty原始碼不匹配
在對jetty的Request類進行debug時，一開始這裡遇到一個小坑，
idea一直原始碼匹配不上。從github上把 jetty原始碼拉下來，按照引入的jetty版本進行本地mvn install，還是不一致。
根據pom的依賴分析，可以看到引入的jetty版本為9.4.12。
後來突然想起來，這個專案雖然是springboot專案，但是並不是打成jar包通過內建jetty容器啟動的。而是打成了war包，本地通過jetty-maven-plugin的jetty:run啟動的。這裡使用的jetty版本為9.4.9。
所以，我們需要按照jetty-maven-plugin的版本來選擇jetty的原始碼。
5.2「偶發問題」難以復現
考慮到篇幅原因與閱讀體驗，本文在排查過程中，沒有展開說明一個非常困難的地方————本地如何穩定復現「偶發問題」異常請求。
真實排查過程中，本地穩定復現耗費了大量時間。如果不是本地可以穩定復現，後面的debug也無從談起。
後面主要根據程式碼的近期變更情況，發現了一個非同步請求的引入，將非同步改為同步後，發現就不會再出現這個問題了。
所以才從非同步請求出發，多次嘗試後，進行了穩定復現。
所以本次排查的一個重要收穫，就是對於一些故障的排查，可以考慮從近期的「各種變更」中去尋找線索。
都看到最後了，原創不易，點個關注，點個贊吧～
文章持續更新，可以微信搜尋「阿丸筆記 」第一時間閱讀，回覆【筆記】獲取Canal、MySQL、HBase、JAVA實戰筆記，回覆【資料】獲取一線大廠面試資料。
知識碎片重新梳理，構建Java知識圖譜：github.com/saigu/JavaK…（歷史文章查閱非常方便）