記錄一次排查PHP腳本執(zhí)行卡住的問題
發(fā)現(xiàn)問題
最近忽然從監(jiān)控中發(fā)現(xiàn),我們一個服務的一臺機器負載比同機房的其他機器要高,而流入流出流量沒有差別,進一步查看發(fā)現(xiàn)每個機房都有一臺機器存在相同的現(xiàn)象,梳理后發(fā)現(xiàn)有問題的這些機器相比正常的機器多跑了一些PHP腳本,于是猜測是執(zhí)行腳本出問題導致。
解決問題
登錄機器后執(zhí)行top命令,果然發(fā)現(xiàn)存在一個CPU占用較高的PHP進程,然后執(zhí)行下列命令,發(fā)現(xiàn)存在一個由crontab啟動的執(zhí)行了很長時間的PHP腳本:
ps aux | grep 'php' | grep -v 'php-fpm'
由于之前也遇到過PHP腳本執(zhí)行卡住的類似情況,當時的懷疑是跨機房的Mysql查詢在網(wǎng)絡抖動時導致Mysql連接卡住了,于是理所當然的將所有卡住的進程都kill掉了,再從負載上看機器馬上就恢復正常了,于是心滿意足的跑去干別的了。
過了一段時間,刷了下監(jiān)控,發(fā)現(xiàn)問題又出現(xiàn)了,注釋掉crontab并kill掉進程后,手動執(zhí)行問題腳本,竟然能穩(wěn)定復現(xiàn)問題!看來是把問題想得太簡單了,嘗試用strace命令看下卡住的進程當前究竟在干什么:
[tabalt@localhost ~] sudo strace -p 13793 Process 13793 attached - interrupt to quit
什么輸出都沒有!再用netstat看下這個進程是否打開了什么端口:
[tabalt@localhost ~] sudo netstat -tunpa | grep 13793 tcp 0 0 192.168.1.100:38019 192.168.1.101:3306 ESTABLISHED 13793/php tcp 0 0 192.168.1.100:47107 192.168.1.102:6379 CLOSE_WAIT 13793/php
可以看到進程打開了兩個端口,分別與Mysql和Redis建立了連接,并且處于連接建立(ESTABLISHED)和對方主動關閉連接(CLOSE_WAIT)的狀態(tài);初看確實像是和數(shù)據(jù)庫的連接卡住了,但是因為吃過虧上過當,咱們使用tcpdump抓包看進程和數(shù)據(jù)庫之間的交互:
tcpdump -i eth0 host 192.168.1.101 and port 3306 -w ~/mysql.cap
抓了好一會,~/mysql.cap 文件中卻也沒有任何輸出,難道進程和Mysql之間已經(jīng)沒有任何交互了?那為什么連接建立沒有關閉呢?看來只能從頭追蹤一下腳本的執(zhí)行情況了:
首先為了能來得及strace到進程,在PHP腳本最開始的時候輸出進程的pid并sleep 10s:
echo getmypid(); sleep(10);
然后啟動tcpdump準備抓包本機和Mysql的交互過程。
最后執(zhí)行PHP腳本,并復制輸出的pid后在新窗口中執(zhí)行strace命令。
這下strace和tcpdump都有內容了!從strace結果看recvfrom之后不再有poll,但并沒有看出來有什么不對:
//... poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=4, revents=POLLIN}]) recvfrom(4, "://xxx.com/\0\0\23jiadia"..., 271, MSG_DONTWAIT, NULL, NULL) = 271 poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=4, revents=POLLIN}]) recvfrom(4, "_b?ie=UTF8&node=658390051\0\0008www."..., 271, MSG_DONTWAIT, NULL, NULL) = 206
再從抓包結果看,執(zhí)行了兩條SQL查詢語句之后,進程沒有再次發(fā)送查詢請求的包,從程序記錄SQL語句日志中,也發(fā)現(xiàn)確實只執(zhí)行了兩條:
select * from sites where type = 1 limit 50; select * from sites where type = 2 limit 50;
但從這些現(xiàn)象中,仍然沒有能看出任何端倪,只好祭出終極大法:輸出調試!大概看了下代碼,并在關鍵地方添加輸出語句,于是代碼看起來如下:
echo("start foreach\n"); foreach($types as $type) { echo("foreach $type\n"); $result[$type] = $this->getSites($type); } echo("end foreach\n");
執(zhí)行后輸出如下,查詢type為2的網(wǎng)址時卡住了:
start foreach foreach 1 foreach 2
開始懷疑調用的getSites()方法有問題,代碼如下:
$sites = array(); // 省略從數(shù)據(jù)庫查詢的代碼 $siteNum = 8; // 省略從配置讀的代碼 $urlKeys = $result = array(); for($i = 0; $i < $siteNum; $i++) { do { $site = array_shift($sites); $urlKey = md5($site['url']); } while(array_key_exists($urlKey, $urlKeys)); $urlKeys[$urlKey] = 1; $result[] = $site; } return $result;
原來這里為了實現(xiàn)拿8個不重復的網(wǎng)址寫了2個循環(huán),如果結果中不重復的網(wǎng)址只有7個就會有一個空,少于7個就會有死循環(huán)!于是查了下type為2的網(wǎng)址個數(shù),果然是只有6個!
總結
該問題從發(fā)現(xiàn)到解決花了大概1天時間,雖然最后證明是低級的代碼BUG導致,但是整個排查過程還是挺有收獲的,最開始的想當然證明是非常膚淺的,過程中tcpdump和strace的結果也已經(jīng)很能說明問題了,對各個工具的應用應該要更加熟練,工具的結果也要深入分析。以上就是這篇文章的全部內容了,希望本文的內容對大家的學習或者工作能帶來一定的幫助,如果有疑問大家可以留言交流。
相關文章
php curl 模擬登錄并獲取數(shù)據(jù)實例詳解
cURL 是一個功能強大的PHP庫,使用PHP的cURL庫可以簡單和有效地抓取網(wǎng)頁并采集內容,設置cookie完成模擬登錄網(wǎng)頁,curl提供了豐富的函數(shù),開發(fā)者可以從PHP手冊中獲取更多關于cURL信息。本文以模擬登錄開源中國(oschina)為例,需要的朋友可以參考下2016-12-12淺析PHP程序防止ddos,dns,集群服務器攻擊的解決辦法
本篇文章是對PHP程序防止ddos,dns,集群服務器攻擊的解決辦法進行了詳細的分析介紹,需要的朋友參考下2013-06-06PHP基于cookie實現(xiàn)統(tǒng)計在線人數(shù)功能示例
這篇文章主要介紹了PHP基于cookie實現(xiàn)統(tǒng)計在線人數(shù)功能,涉及php文件讀寫、cookie訪問、計算等相關操作技巧,需要的朋友可以參考下2019-01-01