您好,登錄后才能下訂單哦!
這篇文章將為大家詳細講解有關java中調用外網服務概率性失敗問題如何排查,小編覺得挺實用的,因此分享給大家做個參考,希望大家閱讀完這篇文章后可以有所收獲。
起因
新系統上線,需要PE執行操作。但是負責操作的PE確和另一個開發在互相糾纏,讓筆者等了半個小時之久。本著加速系統上線的想法,就想著能不能幫他們快速處理掉問題,好讓筆者早點發完回去coding。一打聽,這個問題竟然扯了3個月之久,問題現象如下:
每個client都會以將近1/2的概率失敗,而且報錯都為:
著手排查
和appserver開發以及對應的PE交流發現,appserver和nginx之間是短連接,由于是socketTimeOutException,于是能夠排除appserver和nginx建立連接之間的問題。去nginx上排查日志,發現一個奇異的現象,如下圖所示:
所有的appserver都是調用一臺nginx一直成功,而調用另一臺nginx大概率失敗。而兩臺nginx機器的配置一模一樣,還有一個奇怪的點是,只有在調用出問題的對端服務器時才會失敗,其它業務沒有任何影響,如下圖所示:
由于這兩個詭異的現象導致開發和PE爭執不下,按照第一個現象一臺nginx好一臺nginx報錯那么第二臺nginx有問題是合理的推斷,所以開發要求換nginx。按照第二個現象,只有調用這個業務才會出錯,其它業務沒有問題,那么肯定是對端業務服務器的問題,PE覺得應該不是nginx的鍋。爭執了半天后,初步擬定方案就是擴容nginx看看效果-_-!筆者覺得這個方案并不靠譜,盲目的擴容可能會引起反效果。還是先抓包看看情況吧。
抓包
其實筆者覺得nginx作為這么通用的組件不應該出現問題,問題應該出現在對端服務器上。而根據對端開發反應,他自己curl沒問題,并現場在他自己的服務器上做了N次curl也沒有任何問題(由于這個問題僵持不下,他被派到我們公司來協助排查)。于是找網工在防火墻外抓包,抓包結果如下:
時間點 源ip 目的ip 協議 info
2019-07-25 16:45:41 20.1.1.1 30.1.1.1 tcp 58850->443[SYN]
2019-07-25 16:45:42 20.1.1.1 30.1.1.1 tcp [TCP Retransmission]58850->443[SYN]
2019-07-25 16:45:44 20.1.1.1 30.1.1.1 tcp [TCP Retransmission]58850->443[SYN]
由于appserver端設置的ReadTimeOut超時時間是3s,所以在2次syn重傳后,對端就已經報錯。如下圖所示:
(注:nginx所在linux服務器設置的tcp_syn_retries是2)
抓包結果分析
從抓包得出的數據來看,第二臺nginx發送syn包給對端服務,對端服務沒有任何響應,導致了nginx2創建連接超時,進而導致了appserver端的ReadTimeOut超時(appserver對nginx是短連接)。
按照正常推論,應該是防火墻外到對端服務的SYN丟失了。而阿里云作為一個非常穩定的服務商,應該不可能出現如此大概率的丟失現象。而從對端服務器用的是非常成熟的SpringBoot來看,也不應該出現這種bug。那么最有可能的就是對端服務器本身的設置有問題。
登陸對端服務器進行排查
由于對方的開發來到了現場,于是筆者就直接用他的電腦登錄了服務所在的阿里云服務器。首先看了下dmesg,如下圖所示,有一堆報錯:
感覺有點關聯,但是僅靠這個信息無法定位問題。緊接著,筆者運行了下netstat -s:
這條命令給出了非常關鍵的信息,翻譯過來就是有16990個被動連接由于時間戳(time stamp)而拒絕!查了下資料發現這是由于設置了
在NAT情況下將會導致這個被動拒絕連接的問題。而為解決上面的dmesg日志,網上給出的解決方案就是設置tcp_tw_recycle=1而tcp_timestamps默認就是1,同時我們的客戶端調用也是從NAT出去的,符合了這個問題的所有特征。 于是筆者嘗試著將他們的tcp_timestamps設為0,
又做了幾十次調用,再也沒有任何報錯了!
linux源碼分析
問題雖然解決了,但是筆者想從源碼層面看一看這個問題到底是怎么回事,于是就開始研究對應的源碼(基于linux-2.6.32源碼)。 由于問題是發生在nginx與對端服務器第一次握手(即發送第一個syn)的時候,于是我們主要跟蹤下這一處的相關源碼:
關于tcp_timestamps的代碼就在tcp_v4_conn_request里面,我們繼續追蹤(以下代碼忽略了其它不必要的邏輯):
int tcp_v4_conn_request(struct sock *sk, struct sk_buff *skb) { ...... /* VJ's idea. We save last timestamp seen * from the destination in peer table, when entering * state TIME-WAIT, and check against it before * accepting new connection request. * 注釋大意為: * 我們在進入TIME_WAIT狀態的時候將最后的時間戳記錄到peer tables中, * 然后在新的連接請求進來的時候檢查這個時間戳 */ // 在tcp_timestamps和tcp_tw_recycle開啟的情況下 if (tmp_opt.saw_tstamp && tcp_death_row.sysctl_tw_recycle && (dst = inet_csk_route_req(sk, req)) != NULL && (peer = rt_get_peer((struct rtable *)dst)) != NULL && peer->v4daddr == saddr) { /** TCP_PAWS_MSL== 60 */ /** TCP_PAWS_WINDOW ==1 */ // 以下都是針對同一個對端ip // tcp_ts_stamp 對端ip的連接進入time_wait狀態后記錄的本機時間戳 // 當前時間在上一次進入time_wait記錄的實際戳后的一分鐘之內 if (get_seconds() < peer->tcp_ts_stamp + TCP_PAWS_MSL && // tcp_ts 最近接收的那個數據包的時間戳(對端帶過來的) // 對端當前請求帶過來的時間戳小于上次記錄的進入time_wait狀態后記錄的對端時間戳 (s32)(peer->tcp_ts - req->ts_recent) > TCP_PAWS_WINDOW) { // 增加被動連接拒絕的統計信息 NET_INC_STATS_BH(sock_net(sk), LINUX_MIB_PAWSPASSIVEREJECTED); // 進入丟棄和釋放階段 goto drop_and_release; } } ...... }
上述代碼的核心意思即是在tcp_timestamps和tcp_tw_recycle開啟的情況下,同樣ip的連接,在上個連接進入time_wait狀態的一分鐘內,如果有新的連接進來,而且新的連接的時間戳小于上個進入time_wait狀態的最后一個包的時間戳,則將這個syn丟棄,進入drop_and_release。我們繼續跟蹤drop_and_release:
我們繼續看下如果tcp_v4_conn_request返回0的話,系統是什么表現:
從源碼的跟蹤可以看出,出現此種情況直接丟棄對應的syn包,對端無法獲得任何響應從而進行syn重傳,這點和抓包結果一致。
和問題表象一一驗證
為什么會出現一臺nginx一直okay,一臺nginx失敗的情況
由于tcp的時間戳是指的并不是當前本機用date命令給出的時間戳。這個時間戳的計算規則就在這里不展開了,只需要知道每臺機器的時間戳都不相同即可(而且相差可能極大)。由于我們調用對端采用的是NAT,所以兩臺nginx在對端服務器看來是同一個ip,那么這兩臺的時間戳發送到對端服務器的時候就會混亂。nginx1的時間戳比nginx2的時間戳大,所以在一分鐘之內,只要出現nginx1的連接請求(短連接),那么之后的nginx2的連接請求就會一直被丟棄。如下圖所示:
為什么對端自測一直正常
因為本機調用本機的時時間戳是一臺機器(本機)上的,所以不會出現混亂。
為什么nginx2調用其它服務是正常的
因為其它外部服務所在服務器并沒有開啟tcp_tw_recycle。這個問題事實上將tcp_tw_recycle置為0也可以解決。另外,高版本的linux內核已經去掉了tcp_tw_recycle這個參數。
總結
由于當前ip地址緊缺和DNS報文大小的限制(512字節),大部分網絡架構都是采用NAT的方式去和外部交互,所以設置了tcp_tw_recycle為1基本都會出現問題。一般這種問題需要對tcp協議有一定的了解才能夠順藤摸瓜找到最終的根源。
關于“java中調用外網服務概率性失敗問題如何排查”這篇文章就分享到這里了,希望以上內容可以對大家有一定的幫助,使各位可以學到更多知識,如果覺得文章不錯,請把它分享出去讓更多的人看到。
免責聲明:本站發布的內容(圖片、視頻和文字)以原創、轉載和分享為主,文章觀點不代表本網站立場,如果涉及侵權請聯系站長郵箱:is@yisu.com進行舉報,并提供相關證據,一經查實,將立刻刪除涉嫌侵權內容。