線上Nginx 502 Bad Gateway問題分析

今天一個介面502，不理解一個邏輯很簡單的介面怎麼會失敗。因為我們的的架構是ofe+nginx+php，熟悉這個架構的人都知道，502錯誤碼通常是php-fpm對應的fastcgi程序處理不過來請求導致的。

502狀態碼也叫閘道器錯誤，通常是因為併發請求高超過php-fpm處理能力，導致nginx沒有從upstream收到正確的返回結果。

nginx

從上面的圖中可以看到，upstream_time超過了5s，而正常的請求只需要10ms左右。乍一看像是超時，因為nginx。conf裡面配置的fastcgi_connect_timeout是5s。

upstream上的nginx日誌同樣是502，和ofe上基本一樣。

從nginx error。log可以看出似乎是php fastcgi沒有按時返回結果。

php

問題大機率是出在php層或者業務程式碼。檢視php7-fpm-error。log日誌發現問題時間點fastcgi出現過重啟。

一度懷疑是php出問題了。

php-fpm允許的最大子程序數是128，也就是同時有128個fastcgi可以處理併發請求，如果超過了這個數就會出現雪崩，導致502閘道器錯誤。但是檢視機器負載和當時的請求數，還沒有那麼多。

接著分析pool。d/php7-www。conf中配置的request_terminate_timeout是5s，代表如果如果業務沒有再5s內返回，fastcgi就會終止程序。正好和上面的日誌吻合。

我們重新分析一下php7-fpm-error。log就豁然開朗了。

15：31：20是收到請求並且執行了2s後，打出了executing too slow的trace日誌。這是因為php7-www。conf中配置的request_slowlog_timeout=2s，表示2s如果請求還沒結束就打日誌。

接下來在15：31：24的時候請求達到5s，就觸發了request_terminate_timeout限制，child26113被終止，重新啟動了10022子程序。

因為child26113是被主程序終止的，所以業務日誌並沒有體現，所以導致了我一度以為沒有調到我的業務程式碼。

慢請求

經過上面的分析可以看出是因為程式碼執行超時導致502。此時還有另一個日誌可以排上用場。那就是php7。php7-www。slow。log，記錄了慢請求的一些細節。

找到對應的時間點，分析發現是因為用curl呼叫其他服務超時。查詢下游的服務並沒有找到對應的日誌，進一步推測可能是網路問題。

網路問題

初步分析如果是下游服務執行慢導致超時，那麼至少下游會有日誌。下游服務沒有日誌說明是curl請求丟失或者網路連線失敗，也有可能是dns解析問題。

進一步檢視配置發現，呼叫下游服務用的是外網域名，所以失敗的可能性會更高。根據推斷把外網域名換成內網域名後問題就沒有再出現了。

總結

平時業務開發中最常見的就是502和504錯誤，每次遇到這兩種錯誤都覺得可能是因為併發過大導致php，mysql，redis中的某一個超時或者抖動。

由於目前微服務架構比較普及，所以服務間的呼叫也會帶來問題追查的複雜度，並且服務呼叫穩定性問題也越來越普遍。但是每個問題細心追查起來都可能是因為一個引數或者配置用的不合理，或者格式一行程式碼引起的。一旦透過一次事故排查解決了問題，那麼對架構的理解就會更上一層。