咱們的一個web項目,因爲新上城市增多,致使訪問量增大,DB壓力增大,做爲提供接口的業務方,最近被下游反饋大量請求「502」。php
502,bad gateway,通常都是upstream(這裏就是php)出錯,對於php,形成502的緣由常見的就是腳本執行超過timeout設置時間,或者timeout設置過大,致使php進程長時間不能被釋放,沒有空閒worker進程來接客。html
咱們的項目就是php執行時間設置太短致使的,對於這種狀況,能夠先適當增大php的執行時間,先保證清除502,優化的事情畢竟要花更多的時間。nginx
控制php執行時間的選項有兩個,在php.ini中 max_execution_time 和php-fpm中 request_terminate_timeout,其中 request_terminate_timeout 能夠覆蓋 max_execution_time,因此若是不想改全局的php.ini,那隻改php-fpm的配置就能夠了。web
下邊我就來詳細的分析一下爲何php腳本執行超出設置時間會致使nginx返回502。瀏覽器
先來佈景,讓問題復現:網絡
nginx和php分別只啓動一個worker,方便追蹤。dom
php-fpm的request_terminate_timeout設置爲3S。socket
測試腳本test.phptcp
sleep(20); echo 'ok';
go go go:函數
在瀏覽器訪問www.v.com/test.php,3S後如期出現...404???what???
出師不利啊,趕忙看看nginx的配置文件
這個location配置是當發生5xx錯誤時跳轉到一個好看點的界面,可是我在/usr/share/nginx/html下並無50x.html這個文件。因此搞了個404出來。這不是很影響我判斷問題的準確性?直接註釋掉!再次訪問,等待3S,終於'正常'的界面出來了。
環境好了,下邊就上套路,按照web問題的排查套路走一遍,先看看錯誤日誌吧:
nginx:
報錯都是 recv() failed (104: Connection reset by peer。
recv時失敗了,鏈接被重置了。爲啥鏈接被重置了?難道一言不合。
咱們在看看php-fpm的錯誤日誌:
(注意php-fpm中php_admin_value[error_log]選項指定php的錯誤日誌,會覆蓋php.ini中的。可是這裏不是看php的錯誤,而是看php-fpm的錯誤。php-fpm的錯誤日誌由php-fpm.conf中的error_log選項指定。)
每一次請求都是產生2個WARNING和1個NOTICE:
WARNING:腳本執行超時了,終止了。
WARNING:子進程收到SIGTERM信號退出了。
NOTICE:啓了一個新的子進程(由於我設置的pm.min_spare_servers = 1)
看來若是php的worker進程執行超時,不只終止腳本執行,並且worker進程也會退出。看來nginx的報錯鏈接被重置是由於php的worker進程退出了(在TCP鏈接中一方若是斷掉的話會發送RST給另外一方)
經過日誌已經能夠知道php腳本執行超時,worker子進程退出,致使nginx報錯Connection reset by peer,下邊咱們經過strace來看看php和nginx的狀況:
php:
1.accept一個nginx的鏈接請求(socket,bind,listen都在master中完成 ),能夠看到nginx的端口是47039,從FD0中讀取數據,就是從標準輸入中,這個是fast-cgi協議規定的。accept以後的已鏈接描述符是3。
2.從FD3中讀取nginx傳遞過來的數據,fastcgi協議格式,接收了856字節。爲何read5次呢?
由於fastcgi協議數據包是8字節對齊,由包頭和包體組成。而且都是會先發一個request數據包,包含一些請求ID,版本,typpe等信息(包頭包體各佔8字節),再發一個params數據包,傳遞get參數和環境變量(包頭8字節,包體變長),最後發送一個沒有包體只有包頭的params數據包,表示參數發送結束(包頭8字節)。因此前3個read用來讀出request包的包頭和包體,還有params包的包頭,第四個read是讀取真正的數據,最後一個read是讀取最後一個params包的包頭。因此nginx傳遞的數據應該是8+8+8+856+8=896字節(和下邊nginx的傳輸bytes能對應上)。注意若是是post方式,還會發送stdin數據包。
3.設置休眠20S,就是php程序中的sleep(20),以後因爲進程被終止了,因此後邊就沒啦。strace程序也退出啦。
nginx:
1.accept到瀏覽器的請求,能夠看到瀏覽器端的端口是56434,IP是192.168.1.105,已創建鏈接的FD是3。
2.從FD3中接收數據,HTTP協議。
3.建立一個socket,FD21,用於和php創建鏈接。
4.鏈接到FD21,能夠看到鏈接的是本機的9000端口,這裏nginx和php-fpm使用IP socket鏈接方式,nginx和php-fpm部署在一臺機器上能夠考慮unix domain socket。
5.向FD21寫入數據,fast-cgi協議格式,咱們看到寫入的長度是896,和上邊的php接收的長度是對應的。
6.recvfrom函數從FD21中返回 ECONNRESET (Connection reset by peer)
7.向FD9中寫入錯誤信息,能夠推斷FD9就是nginx錯誤日誌的文件描述符。
8.關閉和FD21的鏈接。
9.向FD3寫入502 Bad Gateway,就是返回給瀏覽器的信息。
10.向FD8寫入一條訪問日誌,能夠推斷FD8就是nginx訪問日誌的文件描述符。
來驗證一下nginx訪問日誌和錯誤日誌的推斷。能夠看到的確是FD8,FD9,並處於寫入模式。
那麼在這個過程當中整個網絡包的傳輸咱們不妨也看一下:
經過tcpdump抓包,用神器看比較方便。
由於只想看nginx和php的通信,在上邊又知道nginx的端口是47039,能夠經過tcp.srcport==47039過濾出對應的包。
能夠看到nginx和php-fpm數據交互的過程:47039->9000創建三次握手,接着向9000發送數據,9000回覆ACK,3S後9000回覆RST。沒毛病。
注意:
SYN,FIN各佔一個序列號
ACK,RST不佔序列號(28,29兩個包的reqnum和acknum都是相同的)
序列號是每一字節加1(29包發送896字節,同時29包seq爲4219146879,30包的ack爲4219147775,正好相差896)
RST不須要回復。