最近做效能測試時，發現連線第三方系統時會有約1%的交易提示如下錯誤 ```java nested exception is org.apache.commons.httpclient.ConnectTimeoutException: The host did not accept the connection within timeout of 10000 ms ``` 起先抱著能google就google的思路去找，結果沒找到相應的解決方案，只能自己一步一步去排查了，下面記錄下排查過程。 #### 抓拍問題現場 ***涉及到網路的問題，先抓個包，tcpdump走一波。*** ```shell tcpdump -i eth0 host xxx.xxx.xxx.xxx > tcp.dmp ``` > 節選了一次TCP連線的整個內容,從三次握手到報文傳送到四次揮手,下面將一次通訊分為三個部分進行講解 ##### 包格式講解 ``` 時間戳 協議型別 請求方地址>接收方地址 Flags [xxx], seq xxx,......,length ``` **協議型別**：此處針對TCP/IP協議，為IP **Flags常見值及含義** | 標識 | 含義 | | ---- | ------------------------------------------------ | | S | 即SYN，用於建立連線 | | . | .即ACK，可與其他組合使用比如[S.]代表SYN的ACK回執 | | P | 即PSH，指示接收方應立即將資料交給上層 | | F | 即FIN，用於斷開連線 | ##### 三次握手 ``` 09:23:00.038908 IP 192.168.1.100.51777 > 192.168.1.200.39045: Flags [S], seq 2590465106, win 29200, options [mss 1460,sackOK,TS val 1752507811 ecr 0,nop,wscale 7], length 0 09:23:00.039329 IP 192.168.1.200.39045 > 192.168.1.100.51777: Flags [S.], seq 148046299, ack 2590465107, win 14480, options [mss 1460,sackOK,TS val 2174555693 ecr 1752507811,nop,wscale 7], length 0 09:23:00.039341 IP 192.168.1.100.51777 > 192.168.1.200.39045: Flags [.], ack 1, win 229, options [nop,nop,TS val 1752507811 ecr 2174555693], length 0 ```  1. 客戶端傳送`SYN=1,seq=隨機生成的序號`到服務端，對應第一個包內容 2. 服務端響應`SYN=1,seq=服務端隨機序號,ack=第一步中的seq+1`給客戶端，對應第二個包內容 3. 客戶端傳送`SYN=0,seq=第一步中的seq+2，ack=服務端的隨機序號+1`給服務端，對應第三個包 至此連線建立完成 > TCP連線為全雙工的，既可以C->S,亦可S->C ##### 請求傳送/響應接收 ``` 09:23:00.039406 IP 192.168.1.100.51777 > 192.168.1.200.39045: Flags [P.], seq 1:167, ack 1, win 229, options [nop,nop,TS val 1752507811 ecr 2174555693], length 166 09:23:00.039426 IP 192.168.1.100.51777 > 192.168.1.200.39045: Flags [P.], seq 167:2259, ack 1, win 229, options [nop,nop,TS val 1752507811 ecr 2174555693], length 2092 09:23:00.039778 IP 192.168.1.200.39045 > 192.168.1.100.51777: Flags [.], ack 167, win 122, options [nop,nop,TS val 2174555693 ecr 1752507811], length 0 09:23:00.039784 IP 192.168.1.200.39045 > 192.168.1.100.51777: Flags [.], ack 2259, win 155, options [nop,nop,TS val 2174555693 ecr 1752507811], length 0 09:23:00.533102 IP 192.168.1.200.39045 > 192.168.1.100.51777: Flags [P.], seq 1:972, ack 2259, win 155, options [nop,nop,TS val 2174555817 ecr 1752507811], length 971 09:23:00.533114 IP 192.168.1.100.51777 > 192.168.1.200.39045: Flags [.], ack 972, win 244, options [nop,nop,TS val 1752507935 ecr 2174555817], length 0 ```  1. 每傳送一次報文，對端需要做一次ACK回執，保證TCP傳輸的可靠 2. 包1和包2是客戶端向服務端請求的，包3和包4是服務端回執的，包5是服務端響應的內容，包6是客戶端對響應做的回執。 ##### 四次揮手 ``` 09:23:00.533121 IP 192.168.1.200.39045 > 192.168.1.100.51777: Flags [F.], seq 972, ack 2259, win 155, options [nop,nop,TS val 2174555817 ecr 1752507811], length 0 09:23:00.533166 IP 192.168.1.100.51777 > 192.168.1.200.39045: Flags [F.], seq 2259, ack 973, win 244, options [nop,nop,TS val 1752507935 ecr 2174555817], length 0 09:23:00.533479 IP 192.168.1.200.39045 > 192.168.1.100.51777: Flags [.], ack 2260, win 155, options [nop,nop,TS val 2174555817 ecr 1752507935], length 0 ```  > 此處因為使用了HTTP協議，且在系統頭中設定了`Connection=close`,所以在請求處理完成後,服務端便會將連線關閉。 1. 第一步:服務端傳送`FIN`到客戶端，對應包1。 2. 第二步:客戶端回執`ACK`到服務端，對應包2。 3. 第三步:客戶端傳送`FIN`到服務端，對應包2。 > 因為第二、第三步都是從客戶端傳送到服務端，TCP協議實現時在此處做了合併，將ACK和FIN一併發給對端，減少了網路消耗。 5. 第四步:服務端回執`ACK`到客戶端，對應包3，連線釋放完成。 #### 問題分析 包是抓到了，可是在效能測試時,業務量特別大,如果純粹靠手工分析的話，怕是要找到地老天荒了，為此寫了一段Python程式碼來分析tcpdump的包，因為本次的問題為請求連線有問題，必然是三次握手的時候存在問題，所以以下程式碼主要分析三次握手時的情況。 **Packet.py** > 解析包內容 ```python import re class Packet(object): '分組' timestamp = '00:00:00.000000' # 時間戳 from_addr = '0.0.0.0' # 源地址 to_addr = '0.0.0.0' # 目的地址 protocol_type = 'IP' # 協議型別 flags = '[S]' seq = '0' ack = '0' length = 0 # 資料包長度 def __init__(self, packet_str): hb = re.split(': ', packet_str) header = hb[0] body = hb[1] hs = re.split('[\s]', header) self.timestamp = hs[0] self.protocol_type = hs[1] self.from_addr = hs[2] self.to_addr = hs[4] bs = re.split(',\s', body) for b in bs: kv = re.split('\s', b, 1) k = kv[0] v = kv[1] if 'Flags' == k: self.flags = v elif 'seq' == k: if self.flags != '[P.]': self.seq = v elif 'length' == k: self.length = int(v) elif 'ack' == k: self.ack = v def __str__(self): return self.timestamp + self.protocol_type + self.from_addr + '==>' + self.to_addr + self.flags + str( self.seq) + str(self.ack) + str(self.length) ``` **ConnectionTimeoutAnalyze.py** > 分析dmp包內容 ```python from tcpdump.Packet import Packet client_addr = '192.168.1.100' server_addr = '192.168.1.200.39045' packet_times = {} # 連線ID:時間 first_packets = [] #三次握手第一次的包 ''' 第一步:syn=1,seq=xxx 第二步:syn=1,seq=yyy,ack=xxx+1 第三步:syn=0,seq=xxx+1,ack=yyy+1 ''' with open('C:\\Users\\xxx\\Desktop\\39045.dmp') as dmp: for line in dmp.readlines(): line = str(line.strip()) packet = Packet(line) if packet.from_addr.startswith(client_addr) and packet.flags == '[S]': first_packets.append(packet) id = packet.from_addr + packet.to_addr + packet.flags + 'ack=' + packet.ack if packet.flags != '[S.]': id = id + 'seq=' + packet.seq packet_times[id] = packet.timestamp print('請求ID(客戶端IP.埠\\請求序號)\t第一步時間\t\t第二步時間\t\t第三步時間') for fpack in first_packets: sync_time = fpack.timestamp # 第一步的時間 id = fpack.to_addr + fpack.from_addr + '[S.]' + 'ack=' + str(int(fpack.seq) + 1) # 第二步:ack=第一步的seq+1 ack_time = packet_times.get(id) conn_time = None if ack_time is not None: conn_time = packet_times.get(fpack.from_addr + fpack.to_addr + '[.]ack=1seq=0') # 第三步:ack=1,seq無值 print( '[' + fpack.from_addr + '\\' + fpack.seq + ']\t' + sync_time + '\t\t' + str(ack_time) + '\t\t' + str(conn_time)) ``` 通過程式碼分析，發現存在部分建立連線時第二步的時間為None的，因此可以得出結論為發出去的SYN請求包沒有得到服務端的回執，可以光明正大的摔鍋給網路/第三