PHP实现通过strace定位故障原因的方法

本文实例讲述了PHP实现通过strace定位故障原因的方法。分享给大家供大家参考，具体如下：

俗话说：不怕贼偷，就怕贼惦记着。在面对故障的时候，我也有类似的感觉：不怕出故障，就怕你不知道故障的原因，故障却隔三差五的找上门来。

十一长假还没结束，服务器却频现高负载，Nginx出现错误日志：

connect() failed (110: Connection timed out) while connecting to upstream
connect() failed (111: Connection refused) while connecting to upstream

看上去是Upstream出了问题，在本例中Upstream就是PHP（版本：5.2.5）。可惜监控不完善，我搞不清楚到底是哪出了问题，无奈之下只好不断重启PHP来缓解故障。

如果每次都手动重启服务无疑是个苦差事，幸运的是可以通过CRON设置每分钟执行：

#/bin/bashLOAD=$(awk '{print $1}' /proc/loadavg)if [ $(echo "$LOAD > 100" | bc) = 1 ]; then  /etc/init.d/php-fpm restartfi

可惜这只是一个权宜之计，要想彻底解决就必须找出故障的真正原因是什么。

闲言碎语不要讲，轮到Strace出场了，统计一下各个系统调用的耗时情况：

shell> strace -c -p $(pgrep -n php-cgi)% time   seconds usecs/call   calls  errors syscall------ ----------- ----------- --------- --------- ---------------- 30.53  0.023554     132    179      brk 14.71  0.011350     140    81      mlock 12.70  0.009798     15    658    16 recvfrom 8.96  0.006910      7    927      read 6.61  0.005097     43    119      accept 5.57  0.004294      4    977      poll 3.13  0.002415      7    359      write 2.82  0.002177      7    311      sendto 2.64  0.002033      2   1201     1 stat 2.27  0.001750      1   2312      gettimeofday 2.11  0.001626      1   1428      rt_sigaction 1.55  0.001199      2    730      fstat 1.29  0.000998     10    100    100 connect 1.03  0.000792      4    178      shutdown 1.00  0.000773      2    492      open 0.93  0.000720      1    711      close 0.49  0.000381      2    238      chdir 0.35  0.000271      3    87      select 0.29  0.000224      1    357      setitimer 0.21  0.000159      2    81      munlock 0.17  0.000133      2    88      getsockopt 0.14  0.000110      1    149      lseek 0.14  0.000106      1    121      mmap 0.11  0.000086      1    121      munmap 0.09  0.000072      0    238      rt_sigprocmask 0.08  0.000063      4    17      lstat 0.07  0.000054      0    313      uname 0.00  0.000000      0    15     1 access 0.00  0.000000      0    100      socket 0.00  0.000000      0    101      setsockopt 0.00  0.000000      0    277      fcntl------ ----------- ----------- --------- --------- ----------------100.00  0.077145         13066    118 total

看上去「brk」非常可疑，它竟然耗费了三成的时间，保险起见，单独确认一下：

shell> strace -T -e brk -p $(pgrep -n php-cgi)brk(0x1f18000) = 0x1f18000 <0.024025>brk(0x1f58000) = 0x1f58000 <0.015503>brk(0x1f98000) = 0x1f98000 <0.013037>brk(0x1fd8000) = 0x1fd8000 <0.000056>brk(0x2018000) = 0x2018000 <0.012635>