详解php+nginx 服务发生500 502错误排查思路

 更新时间:2019年07月19日 11:39:28   作者:小小的太阳  
这篇文章主要介绍了详解php+nginx 服务发生500 502错误排查思路,文中通过示例代码介绍的非常详细,对大家的学习或者工作具有一定的参考学习价值,需要的朋友们下面随着小编来一起学习学习吧
(福利推荐:【腾讯云】服务器最新限时优惠活动,云服务器1核2G仅99元/年、2核4G仅768元/3年,立即抢购>>>:9i0i.cn/qcloud

(福利推荐:你还在原价购买阿里云服务器?现在阿里云0.8折限时抢购活动来啦!4核8G企业云服务器仅2998元/3年,立即抢购>>>:9i0i.cn/aliyun

概述

当线上的服务中访问中出现500或者502错误时,需要紧急处理,排查问题,该怎么做?可以通过分析一些错误日志或者跟踪php-fpm进程来进行问题定位。

nginx error_log

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的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

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\0", 0x7FFEE1ECFF38, 0x0)   = 0 0
21416/0x3479b6:  1884  9  6 lstat64("/var/www\0", 0x7FFEE1ECFDF8, 0x0)   = 0 0
21416/0x3479b6:  1889  6  3 lstat64("/var\0", 0x7FFEE1ECFCB8, 0x0)   = 0 0
21416/0x3479b6:  1899  12  8 readlink("/var\0", 0x7FFEE1ED0090, 0x400)   = 11 0
21416/0x3479b6:  1905  6  4 lstat64("/private/var\0", 0x7FFEE1ECFB78, 0x0)   = 0 0
21416/0x3479b6:  1917  6  3 lstat64("/private\0", 0x7FFEE1ECFA38, 0x0)   = 0 0
21416/0x3479b6:  2178  18  14 stat64("/var/www/.user.ini\0", 0x7FFEE1ED0240, 0x0)   = -1 Err#2
21416/0x3479b6:  2217  5  1 setitimer(0x2, 0x7FFEE1ED07E0, 0x0)   = 0 0
21416/0x3479b6:  2225  4  0 sigaction(0x1B, 0x7FFEE1ED0788, 0x7FFEE1ED07B0)   = 0 0
21416/0x3479b6:  2237  5  1 sigprocmask(0x2, 0x7FFEE1ED0804, 0x0)   = 0x0 0
21416/0x3479b6:  3643  48  40 open_nocancel(".\0", 0x0, 0x1)   = 5 0
21416/0x3479b6:  3648  7  3 fstat64(0x5, 0x7FFEE1ED0110, 0x0)   = 0 0
21416/0x3479b6:  3653  7  2 fcntl_nocancel(0x5, 0x32, 0x10F252158)   = 0 0
21416/0x3479b6:  3661  12  7 close_nocancel(0x5)   = 0 0
21416/0x3479b6:  3670  10  7 stat64("/usr/local/var\0", 0x7FFEE1ED0080, 0x0)   = 0 0
21416/0x3479b6:  3681  11  8 chdir("/var/www\0", 0x0, 0x0)   = 0 0
21416/0x3479b6:  3698  4  0 setitimer(0x2, 0x7FFEE1ED02D0, 0x0)   = 0 0
21416/0x3479b6:  3710  6  3 fcntl(0x3, 0x8, 0x10F3FD858)   = 0 0
21416/0x3479b6:  3733  9  6 stat64("/private/var/www/index.php\0", 0x7FFEE1ECFF10, 0x0)   = 0 0
74904/0x332630: 723125 1073381  19 kevent(0x9, 0x0, 0x0)   = 0 0
74902/0x332629: 770666 1073387  17 kevent(0x8, 0x0, 0x0)   = 0 0
74904/0x332630: 723165 1061954  20 kevent(0x9, 0x0, 0x0)   = 0 0
74902/0x332629: 770709 1061954  20 kevent(0x8, 0x0, 0x0)   = 0 0
74904/0x332630: 723201 1074786  16 kevent(0x9, 0x0, 0x0)   = 0 0
74902/0x332629: 770747 1074783  16 kevent(0x8, 0x0, 0x0)   = 0 0
74904/0x332630: 723229 1069141  13 kevent(0x9, 0x0, 0x0)   = 0 0
74902/0x332629: 770777 1069145  11 kevent(0x8, 0x0, 0x0)   = 0 0
21416/0x3479b6:  3942 3902233  7 __semwait_signal(0x703, 0x0, 0x1)   = -1 Err#4
74902/0x332629: 770814  103  25 kill(21416, 15)   = 0 0
dtrace: error on enabled probe ID 2172 (ID 161: syscall::write:return): invalid kernel access in action #13 at DIF offset 68
dtrace: error on enabled probe ID 2172 (ID 161: syscall::write:return): invalid kernel access in action #13 at DIF offset 68
74902/0x332629: 771325  7  2 sigreturn(0x7FFEE1ECFC40, 0x1E, 0xC1A4B78E0404663A)   = 0 Err#-2
74902/0x332629: 771336  7  3 kevent(0x8, 0x0, 0x0)   = 1 0
dtrace: error on enabled probe ID 2174 (ID 159: syscall::read:return): invalid kernel access in action #13 at DIF offset 68
74902/0x332629: 771352  11  7 wait4(0xFFFFFFFFFFFFFFFF, 0x7FFEE1ED0748, 0x3)   = 21416 0
dtrace: error on enabled probe ID 2172 (ID 161: syscall::write:return): invalid kernel access in action #13 at DIF offset 68
74902/0x332629: 773511 1957 1899 fork()   = 28060 0
28060/0x3754c5:  125:  0:  0 fork()   = 0 0
28060/0x3754c5:  128  9  2 bsdthread_register(0x7FFF6774C418, 0x7FFF6774C408, 0x2000)   = -1 Err#22
dtrace: error on enabled probe ID 2172 (ID 161: syscall::write:return): invalid kernel access in action #13 at DIF offset 68
74902/0x332629: 773737  4  1 wait4(0xFFFFFFFFFFFFFFFF, 0x7FFEE1ED0748, 0x3)   = 0 0
74902/0x332629: 773742  6  3 read(0x5, "\0", 0x1)   = -1 Err#35
28060/0x3754c5:  320  4  0 getpid(0x0, 0x0, 0x0)   = 28060 0
28060/0x3754c5:  328  7  2 __mac_syscall(0x7FFF67758A17, 0x4, 0x7FFEE1ED0208)   = -1 Err#45
28060/0x3754c5:  332  5  2 csops(0x6D9C, 0xB, 0x7FFEE1ED0248)   = -1 Err#22
28060/0x3754c5:  755  14  11 dup2(0x1, 0x2, 0x0)   = 2 0
28060/0x3754c5:  797  89  22 close(0x4)   = 0 0
28060/0x3754c5:  806  11  6 dup2(0x7, 0x0, 0x0)   = 0 0
28060/0x3754c5:  817  4  0 geteuid(0x0, 0x0, 0x0)   = 501 0
28060/0x3754c5:  820  3  0 close(0x5)   = 0 0
28060/0x3754c5:  821  3  0 close(0x6)   = 0 0
28060/0x3754c5:  824  5  1 sigaction(0xF, 0x7FFEE1ED0688, 0x0)   = 0 0
28060/0x3754c5:  825  3  0 sigaction(0x2, 0x7FFEE1ED0688, 0x0)   = 0 0
28060/0x3754c5:  827  3  0 sigaction(0x1E, 0x7FFEE1ED0688, 0x0)   = 0 0
28060/0x3754c5:  828  3  0 sigaction(0x1F, 0x7FFEE1ED0688, 0x0)   = 0 0
28060/0x3754c5:  829  3  0 sigaction(0x14, 0x7FFEE1ED0688, 0x0)   = 0 0
28060/0x3754c5:  830  3  0 sigaction(0x3, 0x7FFEE1ED0688, 0x0)   = 0 0
28060/0x3754c5:  1043  3  0 close(0x7)   = 0 0

可以看到系统底层执行的函数,如lstat64获取文件内容信息,kill(21416, 15)kill掉php-fpm进程,fork()出新的php-fpm进程,有兴趣可以深入研究每个指令的作用

参考

/article/165773.htm

以上就是本文的全部内容,希望对大家的学习有所帮助,也希望大家多多支持程序员之家。

相关文章

  • Nginx stream 配置代理(Nginx TCP/UDP 负载均衡)

    Nginx stream 配置代理(Nginx TCP/UDP 负载均衡)

    本文主要介绍了Nginx stream 配置代理(Nginx TCP/UDP 负载均衡),文中通过示例代码介绍的非常详细,具有一定的参考价值,感兴趣的小伙伴们可以参考一下
    2021-11-11
  • nginx-ingress-controller部署配置详解

    nginx-ingress-controller部署配置详解

    这篇文章主要为大家介绍了nginx ingress controller的部署配置,有需要的朋友可以借鉴参考下,希望能够有所帮助,祝大家多多进步,早日升职加薪
    2023-11-11
  • nginx rewrite 实现URL跳转的方法

    nginx rewrite 实现URL跳转的方法

    今天小编就为大家分享一篇nginx rewrite 实现URL跳转的方法,具有很好的参考价值,希望对大家有所帮助。一起跟随小编过来看看吧
    2019-08-08
  • NGINX下配置404错误页面的方法分享

    NGINX下配置404错误页面的方法分享

    NGINX下配置自定义的404页面是可行的,而且很简单,只需如下几步,需要的朋友可以参考下
    2012-11-11
  • Nginx反向代理的主被动健康检查方式

    Nginx反向代理的主被动健康检查方式

    这篇文章主要介绍了Nginx反向代理的主被动健康检查方式,具有很好的参考价值,希望对大家有所帮助,如有错误或未考虑完全的地方,望不吝赐教
    2024-01-01
  • Nginx轻松解决跨域问题的过程详解

    Nginx轻松解决跨域问题的过程详解

    当你遇到跨域问题,不要立刻就选择复制去尝试,请详细看完这篇文章再处理 ,本文给大家详细介绍了Nginx如何轻松搞定跨域问题,文中通过代码示例额和图文介绍的非常详细,需要的朋友可以参考下
    2024-02-02
  • nginx?ingress代理websocket流量的配置方法

    nginx?ingress代理websocket流量的配置方法

    ingress?nginx默认支持websocket协议,使用长连接协议时需要注意连接超时的设置,文中有提到读取和发送超时的注解参数,通过本文阅读可以快速掌握,对nginx?ingress代理websocket相关知识感兴趣的朋友一起看看吧
    2022-03-03
  • Nginx同时支持Http和Https的配置详解

    Nginx同时支持Http和Https的配置详解

    这篇文章主要介绍了Nginx同时支持Http和Https的配置详解,文中通过示例代码介绍的非常详细,对大家的学习或者工作具有一定的参考学习价值,需要的朋友们下面随着小编来一起学习学习吧
    2020-08-08
  • mac 下 安装nginx的方法小结

    mac 下 安装nginx的方法小结

    这里简单记录一下在mac系统下安装nginx的方法,推荐给大家,有需要的小伙伴可以参考下。
    2015-03-03
  • 安装配置php-fpm来搭建Nginx+PHP的生产环境

    安装配置php-fpm来搭建Nginx+PHP的生产环境

    这篇文章主要介绍了安装配置php-fpm来搭建Nginx+PHP的生产环境的方法,php-fpm的作用是将FastCGI进程管理整合进PHP包,需要的朋友可以参考下
    2016-01-01

最新评论

?


http://www.vxiaotou.com