最近排查一個bug，發現了一系列有意思的東西，對「自定義線程池」、「Jetty線程模型」都有了一些新的認識。

本文預計閱讀時間10分鐘，包括：

• 問題表現
• 常見原因篩查
• 根因與源碼分析
• 最佳實踐
• 一些小TIPS

1、問題表現

預發環境偶發請求失敗異常，服務端顯示錯誤信息為：

Required String parameter 'seriesbaid' is not present 

對應controller的api為

乍一看，是一個非常簡單的異常，請求參數里面沒有帶seriesbaid，導致失敗。

但是，經過確認，前端請求參數已經攜帶了seriesbaid，而且為“偶發失敗”，并不是常見的參數傳遞問題。

2、常見原因篩查

2.1 網關參數丟失?

由于前端請求到達后端服務中會經過網關，所以一開始懷疑是否網關丟失了傳遞參數。

經過 調用鏈分析，在偶發的失敗的請求中，也確認已經傳遞了querystring。所以網關沒有丟失參數傳遞。

2.2 特殊字符導致參數轉換失敗 ?

既然已經傳遞了querystring到后端服務，那么一種常見的原因，由于queryString中帶有特殊字符而導致解析成queryParam失敗了。

會是這個問題嗎?

我們通過在服務中繼承一個spring-web的OncePerRequestFilter，對請求參數進行打印。

在偶發的失敗的請求中，找到了以下日志

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、最佳實踐

不要給異步線程傳遞RequestAttributes對象并進行保存。

如果需要相關請求參數，可以新建上下文對象存儲參數后進行傳遞。或者使用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也無從談起。

后面主要根據代碼的近期變更情況，發現了一個異步請求的引入，將異步改為同步后，發現就不會再出現這個問題了。

所以才從異步請求出發，多次嘗試后，進行了穩定復現。

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