Wireshark|記一次批處理異常報錯的故障排除
本文轉載自微信公眾號「小咩社長」,作者小咩社長。轉載本文請聯系小咩社長公眾號。
寫在前面:
最近一保險客戶火急火燎的找到我說:“濤哥,我們最近這段時間每天晚上在執行批處理的過程中,頻繁的報錯,十萬次的HTTP POST請求中,大概會有六七百次的請求失敗的情況發生,故障現象隨時可以復現,趕緊幫看看“。經過老中醫我一番懸絲診脈,梳理完整個業務訪問流程后,下一良方,輔以悍藥猛攻,基本上藥到病除。
由于此故障場景很有代表性,于是專門整理出這篇文章,希望能給到大家在日常運維排錯中一點啟發。話不多少,上干貨。
網絡邏輯拓撲及業務流:
業務的邏輯拓撲圖,如下圖所示。
批處理業務服務器:Server1 10.160.XX.81:8000、Server2 10.160.XX.82:8000。并且通過前端F5設備提供負載均衡和業務對外發布,VIP地址:10.50.XX.67:8165。
測試終端:通過Curl的方式向 F5 VIP 10.50.XX.67:8165 發送POST請求(批處理流程)
訪問流程:
- 用戶使用腳本通過curl 提交POST請求到F5 VIP 10.50.XX.67:8165
- F5將客戶的POST請求按照負載均衡算法將請求轉發給真實服務器Server1或者server2
- F5和服務器之間有一個國產XX信的NGFW設備(上聯F5設備使用的是防火墻feth11接口,下聯交換機使用是防火墻feth10接口),注意防火墻出入接口,接下來分析數據包的時候會提到。
故障現象:
用戶在使用腳本提交POST請求到F5 VIP 10.50.XX.67:8165的時候,運行一段時間后會卡住(即:POST請求發出后沒有響應),幾秒鐘后收到F5 返回來的RESET包。
抓包大殺器TCPDUMP:
乍一看,很明顯F5發了RESET包,顯然是F5的鍋嘛。其實有時眼見不一定為實,需要透過現象找到問題本質,并不是誰發了RESET包就是誰的鍋。
話不多說,直接掏出大殺器tcpdump,這種疑難雜癥還得猛藥去攻。在客戶執行批處理操作的同時,我們在以下三個位置進行抓包。
一、F5設備上執行tcpdump抓包
#同時抓取客戶端IP、F5 VIP、服務器IP,可以抓全整個訪問環節的數據包,方便定位故障點
- #同時抓取客戶端IP、F5 VIP、服務器IP,可以抓全整個訪問環節的數據包,方便定位故障點
- tcpdump -ni 0.0:nnn -s0 host 10.50.xx.88 or 10.50.xx.67 or 10.160.xx.81 or 10.160.xx.82 -w /var/tmp/test0421-6.pcap.pcap
二、XX信防火墻抓包,抓取流經上聯接口feth11和下聯接口feth10的所有流量。
三、在服務器 Server1 10.160.XX.81、Server2 10.160.XX.82上使用tcpdump抓取流經服務器網卡的所有數據包。
抓包進行時:
測試端使用腳本跑批處理的時候,三個點同時進行抓包,當測試端故障復現,三個點停止抓包。
數據包分析:
不負眾望,故障現象成功復現,下面進行最重要的階段,數據包分(甩)析(鍋):
一、F5上數據包分析:測試客戶端到F5 VIP數據包分析(clientside):
注意故障包的時間:20點57分12秒,以下分析基于該時間點的故障數據包分析,注意數據包前時間!!!
通過wireshark查看F5上tcpdump抓取的數據包,找到故障會話,可以看到
客戶端10.50.X.88:54373訪問 F5 VIP 10.50.XX.67:8165的訪問流量,通過數據包我們可以得到到以下信息:
- 客戶端10.50.X.88:54373訪問 F5 VIP 10.50.XX.67:8165 TCP三次握手建立成功
- 客戶端發起了POST請求,并且F5確認收到該請求 (ack)
- F5沒有響應回http response給客戶端
- F5返回給客戶端一個RST,RST原因為:F5RST(peer) TCP retransmit timeout(重傳超時)。
事實上當F5和客戶端建立完TCP三次握手之后,F5會基于負載算法選擇一臺服務器進行tcp三次握手建鏈,然后將客戶端發來的POST請求轉發給真實的服務器:
通過wireshark上使用F5的擴展插件,該會話流程中還能看到以下信息。
- 在該會話中F5選擇了10.160.XX.82:8000這臺服務器
- F5啟用了源地址轉換功能,將客戶端的真實IP地址10.50.XX.88轉換為10.50.XX.247
- 源端口為43166
二、F5上數據包分析:F5 (10.50.XX.247)到10.160.XX.82:8000流量分析(serverside):
通過wireshark查看F5上tcpdump抓取的數據包,過濾tcp.port ==43166,可以看到
F5端(10.50.XX.247:43166)訪問 server2 10.160.XX.82:8000的訪問流量,通過數據包我們可以得到到以下信息:
- 當F5端(10.50.XX.247:43166)嘗試與 server2 10.160.XX.82:8000建立鏈接
- F5 發送SYN包給server2,但是server2并未無回應 SYN-ACK
- F5觸發重傳機制,三次重傳后未得到服務端的響應(于是F5 觸發RST機制,強制斷開客戶端的鏈接)
三、服務器數據包分析:server2 10.160.XX.82 數據包分析:
通過上述F5上數據包我們分析了clientside和serverside的數據交互,得出初步結論,F5和服務端server2建立鏈接失敗,假設可能的原因有以下幾種:
- 防火墻將F5給服務器server2發送的SYN包轉發給了Server2,Server2沒收到
- 防火墻將F5給服務器server2發送的SYN包轉發給了Server2,Server2收到但是沒有響應
- 防火墻沒有收到F5給服務器server2發送的SYN包
- 防火墻收到F5給服務器server2發送的SYN包,沒有給服務器server2轉發
現在我們首先解決假設2,這個很easy,我們直接查看在server2上抓的數據包即可,如果在時間點20點57分12秒收到了來自防火墻的數據包,那么代表防火墻轉發了數據包,server2有沒有回應zai數據包中一目了然。通過數據包我們可以得到到以下信息:
server2 0.160.XX.82在20點57分03秒后就再也沒有收到來自F5 10.50.XX.247:43166的數據包。
四、撥云見日:XX信防火墻數據包分析:
通過查看server2上的抓包,我們看到server2并未收到來自F5的數據包,接下來就清晰多了,就剩下XX信防火墻了,查看XX信的抓包,我們基本上就可以解決剩下的三個假設,直接定位問題。
接下來就是見證奇跡的時刻:打開XX信防火墻的數據包瞅一瞅:
通過數據包對比查看定位到故障包時間點20點57分13 14 15秒鐘XX信防火墻上聯接口feth11收到了F5發給server2的SYN包,但是并未從feth10接口轉出。。。。
故障定位:
通過以上分析,我們大概能夠還原整個故障原因:
首先客戶端發起批處理操作,在不斷的POST的過程中,中間XX信防火墻轉發數據異常,導致服務端無法接收到F5設備轉發到服務端的數據,于是F5嘗試重傳數據包,當三次重傳都未能成功建立連接后,F5執行RST動作,強制斷開服務端的鏈接。
F5 RST機制
一、由于F5的全代理架構,客戶端到F5(clientside)、F5到服務器(serverside)維護連個TCP/IP協議棧,受益于架構設計,才可以做到客戶端和F5之間跑http2,F5和服務器跑http1.1,前端跑https,后端跑http。所以F5在TCP/HTTP等協議會做RFC合規校驗,再特定的包結構下或者協議安全上會觸發RST動作,保障業務的安全和設備穩定性,以下是部分RST說明,詳情見鏈接:
鏈接:https://support.f5.com/csp/article/K13223
總結
通過層層抓包,一步步接近問題真相,快感還是有,雖然最終不是自己F5設備的問題,但是能幫助客戶第一時間定位問題,這其實也是我們作為服務商的價值,若有坑,召比填,填必滿!最近一直再忙F5 CVE的事,一直沒時間輸出。老鐵們不用擔心,rancher商業版我這已經申請測試了,目前再搭demo環境,rancher聯動F5和k8s集群的的干貨文章在路上了!