HttpClient SSL Session默認(rèn)設(shè)置導(dǎo)致線程阻塞幾分鐘的案例分析
問題描述
幾年前在做某學(xué)習(xí)APP的時(shí)候,評(píng)論服務(wù)(comment)訪問評(píng)論后端服務(wù)(comment-server)正常RT在【幾毫秒 ~ 幾十毫秒】,偶爾(每隔幾天)RT達(dá)到幾十秒甚至幾分鐘,造成用戶看不到評(píng)論列表,發(fā)表評(píng)論失敗等不好的體驗(yàn)。
分析過程
系統(tǒng)交互關(guān)系

系統(tǒng)交互關(guān)系
- 網(wǎng)關(guān)與comment之間通訊協(xié)議是LWP(LaiWang Protocol)
- comment與SLB之間通訊協(xié)議是https
comment調(diào)用comment-server超時(shí)?
在應(yīng)用調(diào)用依賴服務(wù)的時(shí)候,會(huì)記錄下【時(shí)間戳,依賴類別,調(diào)用的接口,響應(yīng)時(shí)間,狀態(tài)碼】等指標(biāo)信息。
通過監(jiān)控及日志信息,出現(xiàn)問題的時(shí)候與SLB交互的RT是【452秒】,初步定位是【SLB】或【comment-server】處理慢導(dǎo)致的,所以聯(lián)系了運(yùn)維同學(xué)、負(fù)責(zé)【comment-server】的同學(xué)一起排查。
與SLB交互耗時(shí)

SLB日志
其中request_time:0.004秒,upstream_response_time:0.004秒
comment-server處理耗時(shí)

應(yīng)用日志
處理耗時(shí)【4毫秒】,看來鍋是自己的。
Review代碼
應(yīng)用訪問SLB使用的是Apache HttpClient,代碼抽象表達(dá)如下:

代碼示例
這個(gè)代碼哪里似乎有問題?
GC導(dǎo)致的阻塞?
通過查看GC Log,發(fā)現(xiàn)CMS GC耗時(shí)較長(zhǎng),與超時(shí)的時(shí)間點(diǎn)是能夠?qū)?yīng)上的,終于發(fā)現(xiàn)了線索。
發(fā)生CMS GC的時(shí)候,線程都在忙些什么呢?這時(shí)候LWP框架的線程dump起到了關(guān)鍵作用,下面對(duì)LWP簡(jiǎn)單做下介紹。
線程模型
LWP是一個(gè)RPC框架,網(wǎng)絡(luò)通訊框架使用的是netty。

線程模型
業(yè)務(wù)線程池
線程池初始化

線程池配置
拒絕策略

拒絕策略
在線程blocked的時(shí)候,LWP框架打印出了當(dāng)時(shí)的線程棧信息,發(fā)現(xiàn)所有業(yè)務(wù)線程都阻塞在了SSL交互過程中。
問題根因
SSLSessionContext’s ssl session緩存(which is a SoftReference cache) 超時(shí)時(shí)間默認(rèn)是86400s (24小時(shí)),ssl session緩存大小默認(rèn)是沒有限制的,導(dǎo)致CMS GC處理SoftReference的時(shí)候耗時(shí)較長(zhǎng)導(dǎo)致的。
算是JDK的一個(gè)Bug,如下:

JDK Bug描述
解決辦法
設(shè)置SSLContext實(shí)例的sessionCacheSize、sessionTimeout,示例:
不僅https,對(duì)于使用SSL通訊的應(yīng)用同樣需要注意上面的問題。





















