記一次生產請求耗時的問題

最近發現lb上記錄的request_time比upstream_response_time大的比較多，例如upstream_response_time記錄是0.062，request_time記錄的就是5.064等等。整個耗時很反常。並且出現這個問題基本上都是一個返回值比較大的接口，基本上返回值是100K左右。領導讓定位一下這個問題。

先說下咱們的架構的背景，是這樣的
阿里雲的SLB-------咱們本身的LB----------WEB機器

定位方向錯誤

跟蹤這個問題以後，一直以爲 LB上記錄的upstream_response_time的時間有問題，我的以爲100K的請求0.0xx秒沒法完成，從這個入口查了一段時間，沒有任何結果。固然也是收穫的，協助WEB的同事發現有些請求的CACHE沒有使用上。後來以爲應該鑽牛角了，第一個Nginx的upstream_response_time確定是沒有問題的；第二個LB到WEB是都是內網訪問，快是必然的。後來抓包也確實證實了LB到WEB特別快，upstream_response_time的時間是正確無誤的。

Nagle 算法的問題？

排除掉upstream_response_time記錄錯誤以後，一直沒有發現。就看了些資料，學習了下課程。看了下極客時間
Linux性能優化實戰 課程，40 | 案例篇：網絡請求延遲變大了，我該怎麼辦？
看完以後，以爲可能真的是Nagle 算法的問題。解釋下Nagle 算法，Nagle 算法，是 TCP 協議中用於減小小包發送數量的一種優化算法，目的是爲了提升實際帶寬的利用率。大概意思就是，合併TCP的小包，提升網絡帶寬的利用率。以爲多是Nagle 算法的問題，就把一臺LB的tcp_nodelay 打開了幾小時，發現問題依然存在。那基本就排除Nagle 算法的問題。
後來仔細琢磨了一下，跟Nagle 算法應該沒有關係，Nagle 算法的延遲是40ms纔對，咱們這個基本上是5秒。

lingering close 的問題

排除掉Nagle 算法的問題以後，又沒有任何方向了。不知道怎麼追查了。後來又抓包查看，沒有發現有價值的線索。可是肯定沒有延遲4秒的，都是延遲5秒的。這是一個特別重要的線索。當時以爲應該有一個默認的配置是5秒。http://nginx.org/en/docs/http/ngx_http_core_module.html#
nginx http_core_module裏面搜索下5s，發現了lingering_timeout 5s; lingering_timeout是個什麼鬼？後來找到一篇跟咱們很相似的問題的文章。文章裏面很詳細的解釋了lingering_timeout。
http://shibing.github.io/2016/11/18/nginx%E7%9A%84%E5%BB%B6%E8%BF%9F%E5%85%B3%E9%97%AD-lingering-close/

下面的這些解釋都來自上面的文章
該問題是由 Nginx 的延遲關閉（lingering close）鏈接致使的。Nginx 爲了可以平滑關閉鏈接，採用了延遲關閉，它的工做方式以下：Nginx 在給客戶端發送完最後一個數據包後會首先關閉 TCP 鏈接的寫端（TCP 是全雙工協議，任何一端都便可讀也可寫），表示服務端不會再向客戶端發送任何數據，可是不會當即關閉 TCP 鏈接的讀端，而是等待一個超時，在超時到達後若是客戶端尚未數據發來，Nginx 纔會關閉TCP的讀端，從而關閉整個鏈接，而後再輸出日誌。另外一方面，Nginx 是在關閉鏈接後才輸出日誌，因此在輸出日誌以前響應早就發送給了用戶，所以對業務幾乎沒有影響。可是這也會致使 requset_time 值變得不許確，使其失去統計意義，開啓 Keep-Alive 能夠部分解決這一問題。

在 Nginx 發送完數據包並進入延遲關閉鏈接流程後，若是客戶端在 lingering_timeout 時間內沒有進行任何操做，那麼就會關閉與客戶端的鏈接而後輸出日誌，這就會致使致使訪問日誌滯後 lingering_timeout 才輸出。咱們線上並無對該參數進行配置，那麼會採用默認值，正好是5秒，與實際狀況吻合。另外若是使用長鏈接，Nignx 在請求結束後不須要關閉鏈接而直接輸出日誌，那麼就不會有這個問題，這也就解釋了爲何開啓 Keep-Alive 後問題消失。

基本上是能夠肯定是lingering_timeout的問題，把生產的一臺的lingering_timeout的參數改成4s，發現5s的消失，4s的出現。知道這個緣由以後，就能肯定，其實真正的耗時有多是2S 3S，只不過延遲關閉了，寫日誌的時間是5S。文章也介紹了只要客戶端設置keep-alive長鏈接，Nginx就不會關閉鏈接，寫日誌時間就會快不少。可是阿里雲的SLB不能開啓長鏈接，由於這個問題，對咱們來講是無解的，咱們能夠將lingering_timeout設置短一點，可是延時關閉的問題是不可避免的。好在是咱們知道了緣由，並非真正的處理慢了，只不過是延時關閉致使日誌時間有誤。

------------------------------------end
一塊兒關注高性能WEB後端技術，關注公衆號