雲容器遷移請求丟失問題分析和排查

前言

近些年來，隨着微服務系統大熱，docker雲容器部署已經是不可忽略的話題。筆者負責的產品線應用本來是部署在虛擬機上，公司統一要求產品線應用所有遷移到docker雲容器中。在遷移過程當中，遇到了客戶端請求丟失的問題，在此梳理總結一下供讀者參考，以避免出現一樣的問題。

本文來自於個人博客網站http://51think.net，歡迎來訪。

問題現象

一、POS終端會發起支付請求，業務碼爲SDK040，服務端60秒內沒有給予響應，請求超時。
二、請求超時後，POS終端自動發起查詢請求，業務碼爲SDK041，服務端返回錯誤信息「訂單不存在」。
這個問題只是機率性出現，出現機率約爲千分之一，經過壓測也沒有復現這個問題。

問題規律

咱們經過splunk日誌查詢發現有以下規律：
一、訂單不存在的報錯以前就存在，量比較少，沒有報障。
二、上雲以後，訂單不存在問題激增，客戶投訴。
三、9月26號切5%的量到雲容器，錯誤量上漲三倍左右。
四、10月17號切40%的量到雲容器，錯誤量上漲5至10倍。
五、10月22號下午將量所有遷回虛擬機，錯誤量回歸至以往正常水平。
以下截圖展現了，一個時間段內報有「訂單不存在」錯誤日誌的統計規律，即上雲以前錯誤量少，上雲以後（10月17日-10月22日）錯誤量明顯增多：

問題分析

從上述的問題規律中能夠看出，訂單不存在的錯誤量在上雲以後明顯增長。經過代碼分析得知，後臺報訂單不存在的緣由在於數據表裏沒有落地本次訂單交易。經過訂單號查詢日誌，發現SDK040的支付請求根本就沒有到達服務端應用，更別談插入數據庫。咱們把懷疑點瞄向整個網絡傳輸路徑，多是哪一個傳輸過程當中把請求拒絕了。先看一下網絡路徑：

從圖中能夠看出，POS智能機進行支付時須要通過netscaler設備，而後進入內部代理。nginx是原有的虛機代理，ingress是k8s提供的代理組件，pod是k8s中承載web應用的容器，在本案中和tomcat同級。在進行雲容器遷移時，咱們經過netscaler切量，將虛機的流量逐步引流到pod中。圖中是已經切量了40%到雲容器環境中。因爲「訂單不存在」錯誤在應用層沒有任何日誌記錄，咱們到nginx和ingress日誌上看看可否找到一些蛛絲馬跡，兩者的access日誌都是這個樣式的：

因爲POS機客戶端都是POST請求，到達nginx層和ingress層的access日誌只能看到請求的URI部分，看不到請求參數，只能看到終端的IP信息，沒法根據訂單號來鎖定具體的請求記錄，因此咱們只能根據終端的IP來查詢指定時間範圍內有沒有請求，結果是使人失望的，問題訂單的支付請求到達nginx或者ingress 。

問題排查

請求沒有到達nginx或者ingress，意味着三種可能：
一、客戶端POS機器沒有發出請求。

咱們經過客戶端遠程抓包，發現客戶端的確發了請求包，並且還報了socketException錯誤。問題不可能出如今客戶端，由於netscaler切量行爲是發生在服務器端，一切量錯誤數就增長，客戶端並無作任何升級改造。

二、網絡抖動致使丟包。

在本例中應該與網絡抖動沒有關係，netscaler切量不可能致使外部網絡抖動。

三、netscaler轉發請求是否出了問題。

咱們找了IDC相關同事一塊兒排查，IDC同事通過抓包，告知咱們說支付請求沒有到達netscaler。

那這個支付請求究竟跑哪去了，問題一度陷入僵局。系統組對比過ingress和nginx的配置，說出一個區別就是nginx配置了會話保持sticky session，而ingress沒有配置。這個差別最終被我否決了，由於咱們的服務端提供的接口都是無狀態的，後臺會話信息所有共享在redis，並不依賴會話保持。
咱們再仔細思考一下整個問題過程，還有一個小規律：切量到ingress，錯誤數會增長，回切到nginx，錯誤數不會當即降低，而是緩慢降低，持續兩個小時左右，錯誤數才能恢復到以往正常水平。這一點感受不合理，若是切量出現的問題，那麼切回去應該當即恢復纔對，而不是再等個兩個小時，這裏面確定有必定的聯繫。

問題突破

大膽質疑：會不會是， 切量後讓整個鏈路帶有必定的特性，而後這個特性會攜帶到回切後的鏈路中？而且這個特性持續了兩個小時以後才消失？這兩個鏈路的交集是POS機，咱們又再次分析了POS機的代碼，POS機的收銀臺功能是安卓寫的，http請求使用了httpclient的工具包。
一、http請求的cookie信息
一開始，我覺得是cookie在做怪，由於httpclient默認請求的時候會攜帶上次請求返回的cookie信息，然而，POS端的http調用代碼是忽略cookie的，以下：

如圖中紅框配置項所示，即每次請求都是獨立的，並不會攜帶任何cookie信息，線索中斷。

二、http請求的header信息
cookie疑問已無望，咱們轉眼關注兩者的header信息差別。咱們在內網環境中，直接經過curl -I -X 命令來訪問ingress和nginx，看看兩者返回的頭信息有何差別。
ingress返回的header信息：

nginx返回的header信息：

經過上圖發現了一個明顯差別，nginx比ingress多了一個配置項keep-Alive:timeout=10，這個配置項的意思是讓這個連接保持10秒。而ingress使用的http1.1沒有這個配置項，意味着這個連接會默認保持兩個小時。兩個小時？是否是和以前回切以後錯誤持續時間等同？嗯，就是這個緣由！另外，咱們聯繫了netscaler的廠商，廠商還透露了一個重要信息，netscaler上有個空閒連接時間管理，配置的是180秒，即netscaler會關閉空閒180秒的連接。至此，咱們再還原一下問題場景：
切量到ingress後，POS的請求路徑是netscaler>ingress>pod，因爲ingress沒有配置keep-Alive:timeout=10，pos客戶端使用httpclient默認保持連接兩個小時，而此時netscaler到達了空閒連接閾值180秒，netscaler主動關閉此連接，而POS端的httpclient仍然認爲此連接能夠複用，再次使用此連接發起請求時，netscaler認爲此連接已關閉，會拒絕轉發此請求。即便切回nginx，此問題依然會持續一段時間，不會當即消失。

問題解決

將ingress增長keep-Alive:timeout=10配置項，從新切量，問題解決。在此也要提醒一下你們：一、謹慎使用httpclient。在本例中，POS做爲客戶端徹底沒有必要使用httpclient進行鏈接池管理，能夠採用底層java提供的URLConnection來創建短鏈接，使用完畢後當即關閉，這樣也不會帶來連接管理的相關問題。二、中間件替換時要關注各個配置項的差別性。nginx和ingress的這個配置項keep-Alive:timeout=10差別被公司的系統組同事忽略了，認爲有connection:keep-Alive配置項就行。後期若是遇到相似奇葩問題，必定要全方位對比各個配置項，不能有缺漏。