PHP實(shí)現(xiàn)通過strace定位故障原因的方法
本文實(shí)例講述了PHP實(shí)現(xiàn)通過strace定位故障原因的方法。分享給大家供大家參考,具體如下:
俗話說:不怕賊偷,就怕賊惦記著。在面對故障的時候,我也有類似的感覺:不怕出故障,就怕你不知道故障的原因,故障卻隔三差五的找上門來。
十一長假還沒結(jié)束,服務(wù)器卻頻現(xiàn)高負(fù)載,Nginx出現(xiàn)錯誤日志:
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)??上ПO(jiān)控不完善,我搞不清楚到底是哪出了問題,無奈之下只好不斷重啟PHP來緩解故障。
如果每次都手動重啟服務(wù)無疑是個苦差事,幸運(yùn)的是可以通過CRON設(shè)置每分鐘執(zhí)行:
#/bin/bash LOAD=$(awk '{print $1}' /proc/loadavg) if [ $(echo "$LOAD > 100" | bc) = 1 ]; then /etc/init.d/php-fpm restart fi
可惜這只是一個權(quán)宜之計(jì),要想徹底解決就必須找出故障的真正原因是什么。
閑言碎語不要講,輪到Strace出場了,統(tǒng)計(jì)一下各個系統(tǒng)調(diào)用的耗時情況:
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」非??梢桑谷缓馁M(fèi)了三成的時間,保險起見,單獨(dú)確認(rèn)一下:
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中和操作花費(fèi)時間相關(guān)的選項(xiàng)有兩個,分別是「-r」和「-T」,它們的差別是「-r」表示相對時間,而「-T」表示絕對時間。 簡單統(tǒng)計(jì)可以用「-r」,但是需要注意的是在多任務(wù)背景下,CPU隨時可能會被切換出去做別的事情,所以相對時間不一定準(zhǔn)確,此時最好使用「-T」,在行 尾可以看到操作時間,可以發(fā)現(xiàn)確實(shí)很慢。
在繼續(xù)定位故障原因前,我們先通過「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)).
簡單點(diǎn)說就是內(nèi)存不夠用時通過它來申請新內(nèi)存(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」我們很方便就能獲取相關(guān)的上下文,反復(fù)運(yùn)行幾次,發(fā)現(xiàn)每當(dāng)請求某些PHP腳本時,就會出現(xiàn)若干條耗時的「brk」,而且這些PHP 腳本有一個共同的特點(diǎn),就是非常大,甚至有幾百K,為何會出現(xiàn)這么大的PHP腳本?實(shí)際上是程序員為了避免數(shù)據(jù)庫操作,把非常龐大的數(shù)組變量通過「var_export」持久化到PHP文件中,然后在程序中通過「include」來獲取相應(yīng)的變量,因?yàn)樽兞刻?,所以PHP不得不頻繁執(zhí)行「brk」,不幸的是在本例的環(huán)境中,此操作比較慢,從而導(dǎo)致處理請求的時間過長,加之PHP進(jìn)程數(shù)有限,于是乎在Nginx上造成請求擁堵,最終導(dǎo)致高負(fù)載故障。
下面需要驗(yàn)證一下推斷似乎否正確,首先查詢一下有哪些地方涉及問題腳本:
shell> find /path -name "*.php" | xargs grep "script.php"
直接把它們都禁用了,看看服務(wù)器是否能緩過來,或許大家覺得這太魯蒙了,但是特殊情況必須做出特殊的決定,不能像個娘們兒似的優(yōu)柔寡斷,沒過多久,服務(wù)器負(fù)載恢復(fù)正常,接著再統(tǒng)計(jì)一下系統(tǒng)調(diào)用的耗時:
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」已經(jīng)不見了,取而代之的是「recvfrom」和「accept」,不過這些操作本來就是很耗時的,所以可以定位「brk」就是故障的原因。
…
擁抱故障,每一次故障都是歷練。正所謂:天將降大任于斯人也,必先苦其心志,勞其筋骨,餓其體膚,空乏其身,行拂亂其所為,所以動心忍性,增益其所不能。
更多關(guān)于PHP相關(guān)內(nèi)容感興趣的讀者可查看本站專題:《PHP錯誤與異常處理方法總結(jié)》、《php字符串(string)用法總結(jié)》、《PHP數(shù)組(Array)操作技巧大全》、《PHP運(yùn)算與運(yùn)算符用法總結(jié)》、《PHP網(wǎng)絡(luò)編程技巧總結(jié)》、《PHP基本語法入門教程》及《php面向?qū)ο蟪绦蛟O(shè)計(jì)入門教程》
希望本文所述對大家PHP程序設(shè)計(jì)有所幫助。
- php+redis在實(shí)際項(xiàng)目中HTTP 500: Internal Server Error故障排除
- IIS下PHP運(yùn)行環(huán)境搭建與網(wǎng)頁服務(wù)器故障排查方法
- IIS PHP環(huán)境Temp文件夾的權(quán)限問題引起的網(wǎng)站故障
- 基于PHP7錯誤處理與異常處理方法(詳解)
- phpStudy配置多站點(diǎn)多域名方法及遇到的403錯誤解決方法
- PHP中常見的錯誤與異常處理總結(jié)大全
- php實(shí)現(xiàn)的錯誤處理封裝類實(shí)例
- 淺談PHP錯誤類型及屏蔽方法
- php中的異常和錯誤淺析
- PHP中Notice錯誤常見解決方法
相關(guān)文章
PHP move_uploaded_file() 函數(shù)(將上傳的文件移動到新位置)
這篇文章主要介紹了PHP move_uploaded_file() 函數(shù),其實(shí)就是將上傳的文件移動到新位置,需要的朋友可以參考下2018-03-03PHP+AJAX實(shí)現(xiàn)無刷新注冊(帶用戶名實(shí)時檢測)
PHP+AJAX實(shí)現(xiàn)無刷新注冊(帶用戶名實(shí)時檢測)...2007-01-01PHP進(jìn)階學(xué)習(xí)之反射基本概念與用法分析
這篇文章主要介紹了PHP進(jìn)階學(xué)習(xí)之反射基本概念與用法,結(jié)合實(shí)例形式分析了php反射的概念、原理基本用法及相關(guān)操作注意事項(xiàng),需要的朋友可以參考下2019-06-06Look And Say 序列php實(shí)現(xiàn)代碼
Look And Say序列,簡單的說就是根據(jù)你看到的數(shù)字,寫出下一個數(shù)字2011-05-05Php output buffering緩存及程序緩存深入解析
在php中有時為了控制程序的輸出顯示順序,提供了output buffering緩存(php自身緩存機(jī)制)。若Ob緩存開啟,需要輸出的就先存在ob緩存里,再到程序緩存里。若沒有開啟,則直接進(jìn)入程序緩存,程序執(zhí)行完畢,按照順序從程序緩存里輸出2013-07-07