處理網絡超時問題的最佳實踐

對於雲上的用戶來講，業務日誌裏面報超時問題處理起來每每比價棘手，由於1) 問題點可能在雲基礎設施層，也有可能在業務軟件層，須要排查的範圍很是廣；2) 這類問題每每是不可復現問題，抓到現場比較難。在本文裏就分析下如何來分辨和排查這類問題的根本緣由。

業務超時 != 網絡丟包

因爲業務的形態不一樣，軟件實現語言和框架的不一樣，業務日誌中打印出的信息多是各不相同，好比以下關鍵字：

"SocketTimeOut", "Read timed out", "Request timeout" 等

從形式看都屬於網絡超時這一類，可是須要明確一個概念：這類問題是發生的緣由是請求超過了設定的timeout時間，這個設置有可能來自客戶端，服務器端或者網絡中間節點，這是直接緣由。網絡丟包可能會致使超時，可是並非充分條件。總結業務超時和網絡丟包的關係以下：

網絡丟包可能形成業務超時，可是業務超時的緣由不必定是丟包。

明確了這個因果關係後，咱們再來看怎麼分析業務超時。若是武斷地將業務超時等同於網絡抖動丟包，那這個排查分析過程就徹底錯過了業務軟件層自己的緣由，很容易進入困局。

本文會從雲基礎設施層和業務軟件層對業務超時作分析，整體來說基礎設置層面的丟包緣由相對容易排查，阿里雲有完善的底層監控，根據業務日誌報錯的對應時間段，從監控數據中能夠肯定是否有基礎設施網絡問題。而業務層的超時一般是軟件層面的設置，和軟件實現及業務形態都有關係，這種每每是更加難以排查的。

網絡丟包爲何致使業務超時

網絡抖動可能形成業務超時，其主要緣由是網絡抖動會帶來不一樣程度的延遲。本文以互聯網大部分應用以來的TCP爲對象來介紹，一個丟包對數據傳輸的完整性實際上是沒有影響的，由於TCP協議自己已經有精密的設計來處理丟包，亂序等異常狀況。而且全部重傳的處理都在內核TCP協議棧中完成，操做系統用戶空間的進程對這個處理其實是不感知的。丟包惟一的反作用的就是會增長延遲，若是這段延遲的時間足夠長，達到了應用進程設置的某個Timeout時間，那麼在業務應用側表現出來的就是業務超時。

丟包出現時會不會發生超時，取決於應用進程的Timeout設置。好比數據傳輸中的只丟了一個TCP數據包，引起200 ms後的超時重傳：

• 若是應用設置的Timeout爲100 ms，TCP協議棧沒有機會重傳，應用就認爲超時並關閉鏈接；
• 若是應用設置的Timeout爲500 ms，則TCP協議棧會完成重傳，這個處理過程對應用進程透明。應用惟一的感知就是處理此次報文交互比基線處理時長多了200 ms，對於時間敏感度不是很是高的應用來講這個影響很是小。

延遲到底有多大？

在設置應用進程Timeout時間時有沒有能夠參考的定量值呢？雖然TCP中的RTT/RTO都是動態變化的，但TCP丟包的產生的影響能夠作必定的定量總結。

對丟包產生的延遲主要有以下兩類：

• TCP建連超時。若是網絡抖動不幸丟掉了TCP的第一個建連SYN報文，對與不太老的內核版原本說，客戶端會在1秒(Draft RFC 2988bis-02中定義)後重傳SYN報文再次發起建連。1秒對於內網環境來講很是大，對於阿里雲一個區域的機房來講，正常的RTT都是小個位數毫秒級別，1秒內若是沒有丟包足夠完成百個數據報的交互。
• TCP中間數據包丟包。TCP協議處理中間的數據丟包有快速重傳和超時重傳兩種機制。快速重傳一般比較快，和RTT相關，沒有定量的值。超時重傳 (RTO, Retrasmission Timeout) 也和RTT相關，可是Linux中定義的RTO的最小值爲，TCP_RTO_MIN = 200ms。因此在RTT比較小的網絡環境下，即便RTT小於1ms，TCP超時重傳的RTO最小值也只能是200ms。這類丟包帶來的延遲相對小。

除了丟包，另一類比較常見的延遲是TCP Delayed ACK帶來的延遲。這個和協議設計相關，和丟包其實沒有關係，在這裏一併總結如延遲定量部分。在交互式數據流+Nagle算法的場景下比較容易觸發。Linux中定義的Delayed ACK的最小值TCP_DELACK_MIN是40 ms。

因此總結下來有以下幾個定量時間能夠供參考：

• 40 ms, 在交互數據流中TCP Delayed ACK + Nagle算法開啓的場景，最小delay值。
• 200 ms，在RTT比較小的正常網絡環境中，TCP數據包丟包，超時重傳的最小值。
• 1 s，較新內核版本TCP創建的第一個SYN包丟包時的重傳時間，RFC2988bis中定義的initial RTO value TCP_TIMEOUT_INIT。
• 3 s, 較老內核版本TCP創建的第一個SYN包丟包時的重傳時間，RFC 1122中定義的initial RTO value TCP_TIMEOUT_INIT。

雲基礎設施網絡丟包

基礎設施網絡丟包的緣由可能有多種，主要總結以下3類：

雲基礎設施網絡抖動

網絡鏈路，物理網絡設備，ECS/RDS等所在的宿主機虛擬化網絡都有可能出現軟硬件問題。雲基礎設施已經作了完備的冗餘，來保證出現問題時能快速隔離，切換和恢復。

現象: 由於有網絡冗餘設備並能夠快速恢復，這類問題一般表現爲某單一時間點網絡抖動，一般爲秒級。抖動的具體現象是在那個時段新建鏈接失敗，已創建的鏈接中斷，在業務上可能表現爲超時。
影響面: 網絡設備下一般掛不少主機，一般影響面比較大，好比同時影響多個ECS到RDS的鏈接。

雲產品的限速丟包

不少網絡雲產品在售賣的時候有規格和帶寬選項，好比ECS, SLB, NAT網關等。當雲產品的流量或者鏈接數超過規格或者帶寬限制時，也會出現丟包。這種丟包並不是雲廠商的故障，而是實際業務流量規模和選擇雲產品規格時的誤差所帶來。這種問題一般從雲產品提供的監控中就能分辨出來。

現象: 當流量或者鏈接數超過規格時，出現流量或者鏈接丟棄。問題可能間斷並持續地出現，網絡流量高峯期出現的機率更大。
影響面: 一般隻影響單一實例。但對於NAT網關作SNAT的場景，可能影響SNAT後的多個實例。

運營商網絡問題

在走公網的場景中，客戶端和服務器之間的報文交互每每要通過多個AS (autonomous system)。若運營商中間鏈路出現問題每每會致使端到端丟包。

現象: 用雙向mtr能夠看到在鏈路中間某跳開始丟包。
影響面: 影響面可能較大，可能影響通過某AS鏈路的報文交互。可是對於單用戶來講看到的影響一般只是對特定實例。

應用設置的Timeout引起的超時

上面分析了幾種基礎設施由於異常或限速等緣由丟包致使應用超時的狀況，整體來講只要能找出丟包點，就基本能找出根因。但有些狀況下，各類網絡監控代表並無任何丟包跡象，這個時候就要從應用側面來繼續排查下了。由於應用的形態多樣，下面以兩個典型例子來講明爲何在沒有網絡丟包的狀況下也會出現業務日誌中的超時。

ECS雲主機訪問第三方API超時的例子

問題現象

用戶雲上ECS服務器須要經過HTTP協議訪問第三方服務器的API，可是發現業務日誌中時不時出現訪問第三方API時的"Request timeout"報錯，須要查出根因。

排查思路

1. 根據基本思路，先從監控中查看ECS實例及鏈路有沒有丟包。結果發現並無能和業務日誌中出現timeout報錯時間點吻合的丟包。
2. 在這種狀況下，只能進一步利用問題復現時的抓包來一探究竟了。

抓包分析

拿到抓包後，能夠經過Wireshark的「分析-專家信息」或者以下表達式來過濾是否有重傳。

tcp.analysis.retransmission

結果確實沒有看到任何一個丟包，這個也反證了該問題並不是由丟包引發。若是不是丟包引發，那爲何會產生問題呢？這時候須要進一步來分析抓包。

咱們能夠注意到：在業務日誌裏其實有"Request Timeout"這樣的關鍵字，從字面理解就是往外的HTTP請求超時。用HTTP協議的話來講，能夠翻譯成：「HTTP請求已經發給對端，可是在一段時間內對端並無返回完整的響應」。沿着這個思路，咱們能夠看下報文裏是否存在只有HTTP請求而沒有HTTP響應的狀況。在Wireshark裏，能夠用以下方法過濾沒有HTTP響應的HTTP請求：

http.request.method == GET && !http.response_in

果真，咱們發現了一些這樣的HTTP請求。選擇其中的一個HTTP請求，而後跟一下TCP stream看下報文交互的全過程以下：

根據抓包會有以下一些發現：

• TCP stream中能夠看到一個TCP鏈接上有2個HTTP請求，因此ECS訪問第三方API是用的長鏈接。
• 第一次HTTP GET請求(735號包)，在65 ms後返回(778號包)。
• 第二次HTTP GET請求(780號包)沒有對應的HTTP響應返回 (咱們正是經過這個條件過濾的報文)。
• 第954號包，客戶端沒等收到HTTP響應就主動FIN掉了TCP鏈接。這是個很異常的行爲，而且是客戶端發起的。仔細觀察FIN和第二個HTTP GET請求發出的時間間隔，發現大約300 ms。接着查看其餘沒有響應的HTTP stream，這個時間間隔大約300 ms。

至此咱們有理由推斷是ECS服務器在對第三方API發出HTTP請求300 ms後主動FIN掉了TCP鏈接。這多是程序中客戶端設置的超時時間，業務程序超時後可能有本身的重試邏輯。

用戶最後確認了業務軟件中有該超時設置。

問題總結

1) 那這個300 ms的超時時間設置是否合理呢？
從抓包中能夠看出，ECS對端API服務器的RTT大約7 ms左右，推斷是一個同城的訪問。對於個位數毫秒級別的RTT，300 ms的超時時間其實已經有必定餘量了，而且甚至可能能夠容許一次超時重傳(200 ms)。

2) 問題的根因？
該問題主要是因爲對端API服務器處理請求的速度不穩定形成。有些請求在幾十毫秒內就處理返回完，有些300 ms都沒有處理完。這個不穩定可能和API服務器的資源水位和壓力相關，可是這個是黑盒，須要對端分析了。

3) 解決方案
1> 最佳解決方案是聯繫對端API服務器的owner找到根因並根除。
2> 臨時解決方案是調整增大ECS上設置的客戶端超時時間。

ECS內網訪問自建Redis超時的例子

ECS訪問雲服務RDS/Cache或者自建數據庫/Cache超時是另一類問題，下面用一個ECS內網訪問字節Redis超時來講明這類問題。

問題現象

ECS上用Redis客戶端Jedis訪問自建在ECS上的Redis服務器，偶爾會出現以下報錯：

redis.clients.jedis.exceptions.JedisConnectionException: java.Net.SocketTimeoutException: Read timed out

排查思路

1. 這類問題很常見的緣由是Redis慢查詢，用戶自查了Redis的大key和慢查詢狀況，沒有發現時間特別長的查詢。因此須要在網絡層面進一步確認。
2. 根據基本思路，先從監控中查看ECS實例及鏈路有沒有丟包。結果發現並無能和"Read timed out"報錯時間點吻合的丟包。
3. 進一步利用問題復現時的抓包來一探究竟了。由於問題偶發，須要在客戶端利用tcpdump -C -W參數部署循環抓包，問題出現後中止循環抓包來查看。

抓包分析

拿到抓包後，一樣先看有沒有丟包重傳，結果是沒有發現丟包重傳。和上一個例子不一樣，這個例子沒有辦法經過必定特徵來過濾數據包。因此只能根據Jedis日誌報錯的時間點找到對應包的位置來進一步看有沒有什麼線索。

根據Jedis日誌報錯的時間點找到對應的報文，跟TCP stream看下報文交互的全過程以下(Jedis客戶端是9.20，Redis服務器端是20.66)：

根據抓包有以下一些發現：

• 能夠看到中間沒有重傳，網絡上看起來是正常的。
• 客戶端利用長鏈接訪問服務器端，在結束鏈接以前已經包了很是多的Redis請求和響應。
• 181073 號包是服務器端FIN掉了鏈接，181078號包客戶端接着發了TCP Reset。

上面這些信息量顯然是不夠說明爲何有"Read timed out"的報錯。最後一個從客戶端發起的TCP Reset可能會是干擾項，能夠看到這個TCP Reset是在收到服務器端的FIN而發出的。對於正常TCP四次回收結束鏈接的過程，客戶端在收到服務器的FIN後應該也發送個FIN給服務器結束鏈接。可是TCP有個Linger選項，能夠控制這個行爲，設置了Linger選項後可讓客戶端直接回Reset，這樣可讓雙方快速關閉這組socket, 避免主動關閉放進入長達60秒的TIME_WAIT狀態。看起來是客戶端的Linger設置形成的，搜了下Jedis代碼，在Connection.java (以下)裏果真有這個設置，這樣就能結束爲何客戶端Reset掉TCP鏈接，這個行爲是符合邏輯的。

socket = new Socket();
socket.setReuseAddress(true);
socket.setKeepAlive(true); // Will monitor the TCP connection is valid
socket.setTcpNoDelay(true); // Socket buffer Whether closed, to ensure timely delivery of data
socket.setSoLinger(true, 0); // Control calls close () method, the underlying socket is closed immediately

接着來看報文交互中的Redis命令是否正常。跟蹤TCP stream能夠看到ASCII形式的數據，以下：

能夠看到客戶端發了DEL命令後，又發了QUIT命令，能夠對照報文看下。

1. 客戶端在181061號包發出了DEL命令。
2. 在3.9 ms後收到了Redis服務器的ACK，注意這只是個ACK包，報文長度是0，說明沒帶任何payload數據。
3. 第181070號包，客戶端又發出了QUIT命令，注意這個包和DEL命令的包相差間隔時間大概200 ms。Quit命令用於關閉與當前客戶端與Redis服務器的鏈接，一旦全部等待中的回覆(若是有的話)順利寫入到客戶端，鏈接就會被關閉。
4. 第181072號包，也就是在QUIT命令發出161 ms後，Redis服務器端回覆了":1"和"+OK"。其中":1"響應DEL命令，"+OK"響應QUIT命令。
5. 第181073號包，Redis用FIN報文結束了這個TCP長鏈接。

如上所述，這個鏈接被中斷的關鍵點是客戶端給Redis服務器發送了QUIT命令，至於爲何要發QUIT，而且是以前命令發出後200 ms沒返回時發送QUIT，頗有多是有超時設置。查看另外幾個TCP stream, 基本上都是以相似的模式結束了TCP長鏈接，基本上能夠下這個結論了。

這個案例和第一個案例很相似，不一樣之點是在抓包裏咱們沒法看到在超時時間事後客戶端直接FIN掉鏈接，而是發了Redis QUIT命令，最終等到前面的命令執行完後才關閉鏈接。相比較第一種，這是一種更優雅的方法，前提是由於Redis存在QUIT命令，而且Jedis內化了這個操做。這個案例更清晰地說明了具體業務對鏈接行爲的影響，須要利用報文來反推Redis客戶端和服務器交互的行爲。

總結

本文介紹了業務日誌裏面報超時問題處理起來須要考慮的兩個層面：雲基礎設施層和業務軟件層。有至關一部分的問題可能因爲基礎設施的網絡丟包引發，經過網絡監控和網絡產品的雲監控定位丟包點很重要，注意不要把業務超時等同於丟包；另外一類業務軟件層Timeout設置致使的超時，發生比例相對少，但須要更普遍的排查，而且不要輕易忽略了這類緣由致使的超時。

原文連接 本文爲雲棲社區原創內容，未經容許不得轉載。