本文實例講述了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/bash
LOAD=$(awk '{print $1}' /proc/loadavg)
if [ $(echo "$LOAD > 100" | bc) = 1 ]; then
/etc/init.d/php-fpm restart
fi
可惜這只是一個權宜之計，要想徹底解決就必須找出故障的真正原因是什么。
閑言碎語不要講，輪到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>
說明：在Strace中和操作花費時間相關的選項有兩個，分別是「-r」和「-T」，它們的差別是「-r」表示相對時間，而「-T」表示絕對時間。 簡單統計可以用「-r」，但是需要注意的是在多任務背景下，CPU隨時可能會被切換出去做別的事情，所以相對時間不一定準確，此時最好使用「-T」，在行 尾可以看到操作時間，可以發現確實很慢。
在繼續定位故障原因前，我們先通過「man brk」來查詢一下它的含義：
brk() sets the end of the data segment to the value specified by end_data_segment, when that value is reasonable, the system does have enough memory and the process does not exceed its max data size (see setrlimit(2)).
簡單點說就是內存不夠用時通過它來申請新內存（data segment），可是為什么呢？
shell> strace -T -p $(pgrep -n php-cgi) 2>1 | grep -B 10 brk
stat("/path/to/script.php", {...}) = 0 0.000064>
brk(0x1d9a000) = 0x1d9a000 0.000067>
brk(0x1dda000) = 0x1dda000 0.001134>
brk(0x1e1a000) = 0x1e1a000 0.000065>
brk(0x1e5a000) = 0x1e5a000 0.012396>
brk(0x1e9a000) = 0x1e9a000 0.000092>
通過「grep」我們很方便就能獲取相關的上下文，反復運行幾次，發現每當請求某些PHP腳本時，就會出現若干條耗時的「brk」，而且這些PHP 腳本有一個共同的特點，就是非常大，甚至有幾百K，為何會出現這么大的PHP腳本？實際上是程序員為了避免數據庫操作，把非常龐大的數組變量通過「var_export」持久化到PHP文件中，然后在程序中通過「include」來獲取相應的變量，因為變量太大，所以PHP不得不頻繁執行「brk」，不幸的是在本例的環境中，此操作比較慢，從而導致處理請求的時間過長，加之PHP進程數有限，于是乎在Nginx上造成請求擁堵，最終導致高負載故障。
下面需要驗證一下推斷似乎否正確，首先查詢一下有哪些地方涉及問題腳本：
shell> find /path -name "*.php" | xargs grep "script.php"
直接把它們都禁用了，看看服務器是否能緩過來，或許大家覺得這太魯蒙了，但是特殊情況必須做出特殊的決定，不能像個娘們兒似的優柔寡斷，沒過多久，服務器負載恢復正常，接著再統計一下系統調用的耗時：
shell> strace -c -p $(pgrep -n php-cgi)
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
24.50 0.001521 11 138 2 recvfrom
16.11 0.001000 33 30 accept
7.86 0.000488 8 59 sendto
7.35 0.000456 1 360 rt_sigaction
6.73 0.000418 2 198 poll
5.72 0.000355 1 285 stat
4.54 0.000282 0 573 gettimeofday
4.41 0.000274 7 42 shutdown
4.40 0.000273 2 137 open
3.72 0.000231 1 197 fstat
2.93 0.000182 1 187 close
2.56 0.000159 2 90 setitimer
2.13 0.000132 1 244 read
1.71 0.000106 4 30 munmap
1.16 0.000072 1 60 chdir
1.13 0.000070 4 18 setsockopt
1.05 0.000065 1 100 write
1.05 0.000065 1 64 lseek
0.95 0.000059 1 75 uname
0.00 0.000000 0 30 mmap
0.00 0.000000 0 60 rt_sigprocmask
0.00 0.000000 0 3 2 access
0.00 0.000000 0 9 select
0.00 0.000000 0 20 socket
0.00 0.000000 0 20 20 connect
0.00 0.000000 0 18 getsockopt
0.00 0.000000 0 54 fcntl
0.00 0.000000 0 9 mlock
0.00 0.000000 0 9 munlock
------ ----------- ----------- --------- --------- ----------------
100.00 0.006208 3119 24 total
顯而易見，「brk」已經不見了，取而代之的是「recvfrom」和「accept」，不過這些操作本來就是很耗時的，所以可以定位「brk」就是故障的原因。
…
擁抱故障，每一次故障都是歷練。正所謂：天將降大任于斯人也，必先苦其心志，勞其筋骨，餓其體膚，空乏其身，行拂亂其所為，所以動心忍性，增益其所不能。
更多關于PHP相關內容感興趣的讀者可查看本站專題：《PHP錯誤與異常處理方法總結》、《php字符串(string)用法總結》、《PHP數組(Array)操作技巧大全》、《PHP運算與運算符用法總結》、《PHP網絡編程技巧總結》、《PHP基本語法入門教程》及《php面向對象程序設計入門教程》
希望本文所述對大家PHP程序設計有所幫助。
您可能感興趣的文章:- php+redis在實際項目中HTTP 500: Internal Server Error故障排除
- IIS下PHP運行環境搭建與網頁服務器故障排查方法
- IIS PHP環境Temp文件夾的權限問題引起的網站故障
- 基于PHP7錯誤處理與異常處理方法(詳解)
- phpStudy配置多站點多域名方法及遇到的403錯誤解決方法
- PHP中常見的錯誤與異常處理總結大全
- php實現的錯誤處理封裝類實例
- 淺談PHP錯誤類型及屏蔽方法
- php中的異常和錯誤淺析
- PHP中Notice錯誤常見解決方法
