NoHttpResponseException: xxx failed to respond 問題分析

問題

HttpClient偶爾報NoHttpResponseException: xxx failed to respond

feign.RetryableException: xxx:80 failed to respond executing POST http://xx

復(fù)現(xiàn)方法

google得知涝滴,這個只會在服務(wù)器端keep-alive剛好過期的時間我們進行訪問才能大概率復(fù)現(xiàn),方法如下:

wireshark進行抓包得出底層服務(wù)器的keep-alive時間

寫一段程序,用于探測底層服務(wù)器的keep-alive:


image.png

開啟wireshark進行抓包,執(zhí)行程序直到下圖出現(xiàn)即可停止

image.png

重點看左下角的紅色框,時間相差65秒左右闻镶,沒錯從而可以得知底層服務(wù)器的keep-alive 是 65秒,也就是當一個連接socket 65秒內(nèi)沒有數(shù)據(jù)交互,底層服務(wù)器就會認為這個連接可以關(guān)閉了弧械,因此才會在3分36秒進行揮手操作發(fā)送一個FIN包,這時我們稍微改造一下這個程序,如下:


image.png

相比第一個空民,有兩個改動

加了一個循環(huán)
每次調(diào)用的間隔改成和底層服務(wù)器相同的65秒
我們清空wireshark刃唐,運行該程序抓包羞迷,結(jié)果如下:


image.png

問題分析

image.png

紅色框1:前3個請求是建立連接的過程,三次握手画饥,接著4個請求就是client和server的數(shù)據(jù)交互衔瓮,著重看最后四個請求
9012 -> 59233 [FIN, ACK]:服務(wù)器主動進行關(guān)閉,給client發(fā)送了FIN包
59233 -> 9012 [ACK]:client進行回應(yīng)ACK包
69233 -> 9012 [FIN, ACK]:按照四次揮手原則抖甘,client發(fā)現(xiàn)目前數(shù)據(jù)已經(jīng)發(fā)送完畢了热鞍,因此也發(fā)出FIN包
9012 -> 59233 [RST]:服務(wù)器直接返回一個RST
紅色框2:同2
紅色框3:前面的7個步驟都是相同的,建立連接衔彻,數(shù)據(jù)交互薇宠,區(qū)別唯獨在于綠色框
9012 -> 59233 POST /hy/json: client認為服務(wù)器端可用,因此給服務(wù)器發(fā)送數(shù)據(jù)
9012 -> 59233 [FIN, ACK]:服務(wù)器認為此連接已經(jīng)失效艰额,因為超過了65的keep-alive時間澄港,主動進行關(guān)閉,給client發(fā)送了FIN包
59233 -> 9012 [ACK]:client進行回應(yīng)ACK包
69233 -> 9012 [FIN, ACK]:按照四次揮手原則柄沮,client發(fā)現(xiàn)目前數(shù)據(jù)已經(jīng)發(fā)送完畢了回梧,因此也發(fā)出FIN包
9012 -> 59233 [RST]:服務(wù)器直接返回一個RST 通過Seq=188,可判斷這條是給【9012 -> 59233 POST /hy/json】這個請求回的
9012 -> 59233 [RST]:服務(wù)器直接返回一個RST 通過Seq=189铡溪,可判斷這條是給【69233 -> 9012 [FIN, ACK]】回的
9012 -> 59233 [RST]:服務(wù)器直接返回一個RST 通過Seq=189漂辐,同6
通過分析抓包數(shù)據(jù),得出結(jié)果是棕硫,當client客戶端認為這條Socket連接有用髓涯,這時服務(wù)器端卻認為該Socket連接無用,并主動關(guān)閉哈扮,就會報錯,屬于臨界值沒有處理好的

這時有人就說了纬纪,為什么前兩次就沒有問題呢,原因是HttpClient會進行連接過期是否可用的檢查滑肉,那么也就能理解這是httpclient的一個bug包各,即使httpclient有做這么一件事情,但是由于網(wǎng)絡(luò)I/O原因靶庙,導(dǎo)致httpclient認為一個關(guān)閉了的連接是有效的问畅,才報了這個錯誤。

HttpClient為什么會復(fù)用一個已經(jīng)被關(guān)閉的連接

開啟debug日志


image.png

通過仔細分析HttpClient打印的debug日志,可發(fā)現(xiàn)左邊正常交互日志 打印了一串 "end of stream" 后進行了連接的重新建立六荒, connection established 护姆,而右邊錯誤日志打印了一串 "[read] I/O error: Read timed out" 后沒有進行連接的重新建立,因此就報錯了

那么可以通過打印 "[read] I/O error: Read timed out"日志的上下文日志縮小 排查代碼的范圍掏击,上文日志 Connection request卵皂,下文日志 Connection leased,進行代碼定位

image.png
image.png

基本上定位到了PooingHttpClientConnectionManager.java這個類砚亭,那么進行代碼跟蹤吧

image.png

追蹤到了 AbstractConnPool.java類灯变,那么這段代碼什么意思呢殴玛,這個就是進行連接是否能夠復(fù)用的檢查代碼

對validateAfterInactivity進行判斷,這個是服務(wù)器keep-alive的值

leasedEntry.getUpdated() + validateAfterInactivity <= System.currentTimeMillis():如果連接的最后一次使用時間 + 服務(wù)器keep-alive的時間 小于等于當前時間添祸,那么就認為該連接可能已經(jīng)失效了
!validate(leasedEntry): 因此會進行連接是否失效的檢查
跟進去看看

image.png

最終找到"end of stream" and "[read] I/O error: Read timed out" 打印的地方
然后回到如下圖代碼:

image.png

可以看到

當bytesRead 值為 -1 時滚粟,返回true,那么HttpClient就會認為該連接失效了,不能夠復(fù)用膝捞,并進行清理操作坦刀,
當拋出異常是ShockTimeoutException時會返回false, 那么HttpClient就會認為該連接可復(fù)用

解決方案

禁用HttpClient的連接復(fù)用(有點扯淡)
重試方案:http請求使用重發(fā)機制蔬咬,捕獲NohttpResponseException的異常,重新發(fā)送請求沐寺,重發(fā)3次后還是失敗才停止
根據(jù)keep Alive時間林艘,調(diào)整validateAfterInactivity小于keepAlive Time,但這種方法依舊不能避免同時關(guān)閉
系統(tǒng)主動檢查每個連接的空閑時間,并提前自動關(guān)閉連接混坞,避免服務(wù)端主動斷開
推薦使用重試方案

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末狐援,一起剝皮案震驚了整個濱河市,隨后出現(xiàn)的幾起案子究孕,更是在濱河造成了極大的恐慌啥酱,老刑警劉巖,帶你破解...
    沈念sama閱讀 217,542評論 6 504
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件厨诸,死亡現(xiàn)場離奇詭異镶殷,居然都是意外死亡,警方通過查閱死者的電腦和手機微酬,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 92,822評論 3 394
  • 文/潘曉璐 我一進店門绘趋,熙熙樓的掌柜王于貴愁眉苦臉地迎上來,“玉大人颗管,你說我怎么就攤上這事陷遮。” “怎么了垦江?”我有些...
    開封第一講書人閱讀 163,912評論 0 354
  • 文/不壞的土叔 我叫張陵帽馋,是天一觀的道長。 經(jīng)常有香客問我比吭,道長绽族,這世上最難降的妖魔是什么? 我笑而不...
    開封第一講書人閱讀 58,449評論 1 293
  • 正文 為了忘掉前任梗逮,我火速辦了婚禮项秉,結(jié)果婚禮上,老公的妹妹穿的比我還像新娘慷彤。我一直安慰自己娄蔼,他們只是感情好怖喻,可當我...
    茶點故事閱讀 67,500評論 6 392
  • 文/花漫 我一把揭開白布。 她就那樣靜靜地躺著岁诉,像睡著了一般锚沸。 火紅的嫁衣襯著肌膚如雪。 梳的紋絲不亂的頭發(fā)上涕癣,一...
    開封第一講書人閱讀 51,370評論 1 302
  • 那天哗蜈,我揣著相機與錄音,去河邊找鬼坠韩。 笑死距潘,一個胖子當著我的面吹牛,可吹牛的內(nèi)容都是我干的只搁。 我是一名探鬼主播音比,決...
    沈念sama閱讀 40,193評論 3 418
  • 文/蒼蘭香墨 我猛地睜開眼,長吁一口氣:“原來是場噩夢啊……” “哼氢惋!你這毒婦竟也來了洞翩?” 一聲冷哼從身側(cè)響起,我...
    開封第一講書人閱讀 39,074評論 0 276
  • 序言:老撾萬榮一對情侶失蹤焰望,失蹤者是張志新(化名)和其女友劉穎骚亿,沒想到半個月后,有當?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體熊赖,經(jīng)...
    沈念sama閱讀 45,505評論 1 314
  • 正文 獨居荒郊野嶺守林人離奇死亡来屠,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點故事閱讀 37,722評論 3 335
  • 正文 我和宋清朗相戀三年,在試婚紗的時候發(fā)現(xiàn)自己被綠了秫舌。 大學(xué)時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片的妖。...
    茶點故事閱讀 39,841評論 1 348
  • 序言:一個原本活蹦亂跳的男人離奇死亡,死狀恐怖足陨,靈堂內(nèi)的尸體忽然破棺而出嫂粟,到底是詐尸還是另有隱情,我是刑警寧澤墨缘,帶...
    沈念sama閱讀 35,569評論 5 345
  • 正文 年R本政府宣布星虹,位于F島的核電站,受9級特大地震影響镊讼,放射性物質(zhì)發(fā)生泄漏宽涌。R本人自食惡果不足惜,卻給世界環(huán)境...
    茶點故事閱讀 41,168評論 3 328
  • 文/蒙蒙 一蝶棋、第九天 我趴在偏房一處隱蔽的房頂上張望卸亮。 院中可真熱鬧,春花似錦玩裙、人聲如沸兼贸。這莊子的主人今日做“春日...
    開封第一講書人閱讀 31,783評論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽溶诞。三九已至鸯檬,卻和暖如春,著一層夾襖步出監(jiān)牢的瞬間螺垢,已是汗流浹背喧务。 一陣腳步聲響...
    開封第一講書人閱讀 32,918評論 1 269
  • 我被黑心中介騙來泰國打工, 沒想到剛下飛機就差點兒被人妖公主榨干…… 1. 我叫王不留枉圃,地道東北人功茴。 一個月前我還...
    沈念sama閱讀 47,962評論 2 370
  • 正文 我出身青樓,卻偏偏與公主長得像孽亲,于是被迫代替她去往敵國和親痊土。 傳聞我的和親對象是個殘疾皇子,可洞房花燭夜當晚...
    茶點故事閱讀 44,781評論 2 354

推薦閱讀更多精彩內(nèi)容