摘要：概述當線上的服務中訪問中出現或者錯誤時，需要緊急處理，排查問題，該怎么做可以通過分析一些錯誤日志或者跟蹤進程來進行問題定位。

當線上的服務中訪問中出現500或者502錯誤時，需要緊急處理，排查問題，該怎么做？可以通過分析一些錯誤日志或者跟蹤php-fpm進程來進行問題定位。

nginx的error_log在nginx的配置文件中定義的

server {
    listen       80;
    server_name  localhost;
    root         /var/www;

    access_log  /Users/jiao/logs/default.access.log;
    error_log /Users/jiao/logs/default.error.log;
    location / {
        index  index.html index.htm index.php;
        autoindex   on;
    }
    location = /info {
        allow   127.0.0.1;
        deny    all;
        rewrite (.*) /.info.php;
    }
    location ~ .php$ {
        root    /var/www;
        fastcgi_pass 127.0.0.1:9000;
        fastcgi_index index.php;
        fastcgi_param SCRIPT_FILENAME /var/www$fastcgi_script_name;
        include /usr/local/etc/nginx/fastcgi_params;
    }
}

查看error_log

?  tail /Users/jiao/logs/default.error.log
2019/07/17 11:08:18 [error] 77416#0: *76 kevent() reported about an closed connection (54: Connection reset by peer) while reading response header from upstream, client: 127.0.0.1, server: localhost, request: "GET / HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "localhost"

發現出現了Connection reset by peer，連接被重置了，此時可以再查看php-fpm的error_log進一步分析問題

php-fpm的error_log在php-fpm.conf文件中配置中定義的

; Error log file
; If it"s set to "syslog", log is sent to syslogd instead of being written
; in a local file.
; Note: the default prefix is /usr/local/var
; Default Value: log/php-fpm.log
error_log = log/php-fpm.log

error_log里面的內容是這樣的

?  tail /usr/local/var/log/php-fpm.log
[17-Jul-2019 10:49:54] NOTICE: [pool www] child 81948 started
[17-Jul-2019 11:08:18] WARNING: [pool www] child 77537, script "/var/www/index.php" (request: "GET /index.php") execution timed out (3.801267 sec), terminating
[17-Jul-2019 11:08:18] WARNING: [pool www] child 77537 exited on signal 15 (SIGTERM) after 1503.113967 seconds from start
[17-Jul-2019 11:08:18] NOTICE: [pool www] child 94339 started

可以看到是請求/var/www/index.php文件出現了超時

dtruss是動態跟蹤命令，可以根據PID，name跟蹤進程
mac環境下使用dtruss，linux環境可以使用strace，pstack

? dtruss                            
USAGE: dtruss [-acdefholLs] [-t syscall] { -p PID | -n name | command | -W name }

      -p PID          # examine this PID
      -n name         # examine this process name
      -t syscall      # examine this syscall only
      -W name         # wait for a process matching this name
      -a              # print all details
      -c              # print syscall counts
      -d              # print relative times (us)
      -e              # print elapsed times (us)
      -f              # follow children
      -l              # force printing pid/lwpid
      -o              # print on cpu times
      -s              # print stack backtraces
      -L              # don"t print pid/lwpid
      -b bufsize      # dynamic variable buf size

eg,

   dtruss df -h       # run and examine "df -h"
   dtruss -p 1871     # examine PID 1871
   dtruss -n tar      # examine all processes called "tar"
   dtruss -f test.sh  # run test.sh and follow children
   

跟蹤php-fpm：sudo dtruss -a -n php-fpm
此時訪問web頁面，就可以看到跟蹤內容

21416/0x3479b6:      1559      63      3 getrusage(0x0, 0x7FFEE1EC0760, 0x0)         = 0 0
21416/0x3479b6:      1561       4      0 getrusage(0xFFFFFFFFFFFFFFFF, 0x7FFEE1EC0760, 0x0)         = 0 0
21416/0x3479b6:      1627      77     17 poll(0x7FFEE1EC08C0, 0x1, 0x1388)         = 1 0
dtrace: error on enabled probe ID 2174 (ID 159: syscall::read:return): invalid kernel access in action #13 at DIF offset 68
dtrace: error on enabled probe ID 2174 (ID 159: syscall::read:return): invalid kernel access in action #13 at DIF offset 68
dtrace: error on enabled probe ID 2174 (ID 159: syscall::read:return): invalid kernel access in action #13 at DIF offset 68
dtrace: error on enabled probe ID 2174 (ID 159: syscall::read:return): invalid kernel access in action #13 at DIF offset 68
dtrace: error on enabled probe ID 2174 (ID 159: syscall::read:return): invalid kernel access in action #13 at DIF offset 68
21416/0x3479b6:      1872      29     24 lstat64("/var/www/index.php