Nginx" upstream prematurely closed connection while reading response header from upstream"問題排查


問題背景

  我們這邊是一個基於Nginx的API網關(以下標記為A),最近兩天有調用方反饋,偶爾會出現502錯誤,我們從Nginx的error日志里看,就會發現有" upstream prematurely closed connection while reading response header from upstream"這么一條錯誤日志,翻譯過來其實就是上游服務過早的關閉了連接,意思很清楚,但是為什么會出現這種情況呢。而且是在業務低峰出現這種情況(也只是小概率的出現),在業務高峰的時候沒有出現這種情況,而且上游服務方(以下標記為B)說出問題的請求他們那邊沒有收到,也就是沒有任何記錄,這就比較詭異了。測試環境不知道如何去復現,也就不好排查。

排查過程

  1、在服務器上開啟tcpdump抓包 tcpdump -nps0 -iany -w /tmp/20180617.pcap net [ip] and net [ip],如果不知道tcpdump怎么使用的同學可以百度一下。

  2、在nginx的error.log中觀察到到有兩條" upstream prematurely closed connection while reading response header from upstream"錯誤日志,分別是2018/06/07 20:41:27和2018/06/08 09:10:46兩個時間點,如下圖

  3、然后查看抓包數據,找到了對應時間點的包數據,從這個可以看出,A向B發送了一個1060-2143的包,,而服務端發送了一個Fin斷開連接。為什么服務端會斷開連接了,我們不得而知。

  4、上一步A發送包首字節數是1060,那必然前面肯定發送過包,那我們繼續往上查,發現了如下圖所示的現象。在20:40:22的時候3次握手建立連接並發送了第一個包;而且也查了在20:40:22到20:41:27中間這條長連接沒有發送任何包

  5、和B溝通,他們的Nginx中的keepalive_timeout配置為65秒,keepalive_timeout這個配置的意思是說長連接保持的時間,如果沒有任何數據傳輸的話,超過這個時間,服務端會關閉這個連接。那這就對上了,說明在這65秒沒有任何數據傳輸,也正好在這個點,A向B發送了數據,而B關閉了這個連接,於是就出現了上面的現象。

  6、當然這是我根據抓包分析出來的結果,我也自己模擬了這種情況,寫了一個定時任務,每隔一分鍾向第一台nginx發送請求,轉發到第二台nginx上。第二台nginx的keepalive_timeout配置為60,在發送第七次的時候,出現了同樣的問題,nginx打印同樣的錯誤日志,抓包的結果也和上述情況一致。驗證了我上述的分析過程。

問題總結

  1、如果系統並發量不大,沒有必要開啟長連接,有兩種方式,一、第一台nginx可以去除proxy_http_version 1.1; proxy_set_header Connection "0";這兩個配置;二、第二台nginx的keepalive_timeout可以配置為0(默認是75)。

  2、上述問題我的解決方案是:暫時調大keepalive_timeout的值,先觀察,但很有可能還是會有這個問題。

后記

  1、網絡問題的排查過程是很痛苦了,再一次驗證了基礎知識的重要性。

  2、偶然報出的問題,一定不要忽視,說不定以后就是系統的瓶頸。


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM