發現問題
最近忽然從監控中發現，我們一個服務的一台機器負載比同機房的其他機器要高，而流入流出流量沒有差別，進一步查看發現每個機房都有一台機器存在相同的現象，梳理後發現有問題的這些機器相比正常的機器多跑了一些PHP腳本，於是猜測是執行腳本出問題導致。
解決問題
登錄機器後執行top命令，果然發現存在一個CPU占用較高的PHP進程，然後執行下列命令，發現存在一個由crontab啟動的執行了很長時間的PHP腳本：
ps aux | grep 'php' | grep -v 'php-fpm'
由於之前也遇到過PHP腳本執行卡住的類似情況，當時的懷疑是跨機房的Mysql查詢在網絡抖動時導致Mysql連接卡住了，於是理所當然的將所有卡住的進程都kill掉了，再從負載上看機器馬上就恢復正常了，於是心滿意足的跑去干別的了。
過了一段時間，刷了下監控，發現問題又出現了，注釋掉crontab並kill掉進程後，手動執行問題腳本，竟然能穩定復現問題！看來是把問題想得太簡單了，嘗試用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）的狀態；初看確實像是和數據庫的連接卡住了，但是因為吃過虧上過當，咱們使用tcpdump抓包看進程和數據庫之間的交互：
tcpdump -i eth0 host 192.168.1.101 and port 3306 -w ~/mysql.cap
抓了好一會，~/mysql.cap 文件中卻也沒有任何輸出，難道進程和Mysql之間已經沒有任何交互了？那為什麼連接建立沒有關閉呢？看來只能從頭追蹤一下腳本的執行情況了：
首先為了能來得及strace到進程，在PHP腳本最開始的時候輸出進程的pid並sleep 10s:
echo getmypid(); sleep(10);
然後啟動tcpdump准備抓包本機和Mysql的交互過程。
最後執行PHP腳本，並復制輸出的pid後在新窗口中執行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
再從抓包結果看，執行了兩條SQL查詢語句之後，進程沒有再次發送查詢請求的包，從程序記錄SQL語句日志中，也發現確實只執行了兩條：
select * from sites where type = 1 limit 50; select * from sites where type = 2 limit 50;
但從這些現象中，仍然沒有能看出任何端倪，只好祭出終極大法：輸出調試！大概看了下代碼，並在關鍵地方添加輸出語句，於是代碼看起來如下：
echo("start foreach\n");
foreach($types as $type)
{
echo("foreach $type\n");
$result[$type] = $this->getSites($type);
}
echo("end foreach\n");
執行後輸出如下，查詢type為2的網址時卡住了：
start foreach foreach 1 foreach 2
開始懷疑調用的getSites()方法有問題，代碼如下:
$sites = array(); // 省略從數據庫查詢的代碼
$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;
原來這裡為了實現拿8個不重復的網址寫了2個循環，如果結果中不重復的網址只有7個就會有一個空，少於7個就會有死循環！於是查了下type為2的網址個數，果然是只有6個！
總結
該問題從發現到解決花了大概1天時間，雖然最後證明是低級的代碼BUG導致，但是整個排查過程還是挺有收獲的，最開始的想當然證明是非常膚淺的，過程中tcpdump和strace的結果也已經很能說明問題了，對各個工具的應用應該要更加熟練，工具的結果也要深入分析。以上就是這篇文章的全部內容了，希望本文的內容對大家的學習或者工作能帶來一定的幫助，如果有疑問大家可以留言交流。
