如何排查PHP腳本執(zhí)行卡住的問(wèn)題

這篇文章將為大家詳細(xì)講解有關(guān)如何排查PHP腳本執(zhí)行卡住的問(wèn)題，小編覺(jué)得挺實(shí)用的，因此分享給大家做個(gè)參考，希望大家閱讀完這篇文章后可以有所收獲。

發(fā)現(xiàn)問(wèn)題

最近忽然從監(jiān)控中發(fā)現(xiàn)，我們一個(gè)服務(wù)的一臺(tái)機(jī)器負(fù)載比同機(jī)房的其他機(jī)器要高，而流入流出流量沒(méi)有差別，進(jìn)一步查看發(fā)現(xiàn)每個(gè)機(jī)房都有一臺(tái)機(jī)器存在相同的現(xiàn)象，梳理后發(fā)現(xiàn)有問(wèn)題的這些機(jī)器相比正常的機(jī)器多跑了一些PHP腳本，于是猜測(cè)是執(zhí)行腳本出問(wèn)題導(dǎo)致。

解決問(wèn)題

登錄機(jī)器后執(zhí)行top命令，果然發(fā)現(xiàn)存在一個(gè)CPU占用較高的PHP進(jìn)程，然后執(zhí)行下列命令，發(fā)現(xiàn)存在一個(gè)由crontab啟動(dòng)的執(zhí)行了很長(zhǎng)時(shí)間的PHP腳本：

ps aux | grep 'php' | grep -v 'php-fpm'

由于之前也遇到過(guò)PHP腳本執(zhí)行卡住的類似情況，當(dāng)時(shí)的懷疑是跨機(jī)房的Mysql查詢?cè)诰W(wǎng)絡(luò)抖動(dòng)時(shí)導(dǎo)致Mysql連接卡住了，于是理所當(dāng)然的將所有卡住的進(jìn)程都kill掉了，再?gòu)呢?fù)載上看機(jī)器馬上就恢復(fù)正常了，于是心滿意足的跑去干別的了。

過(guò)了一段時(shí)間，刷了下監(jiān)控，發(fā)現(xiàn)問(wèn)題又出現(xiàn)了，注釋掉crontab并kill掉進(jìn)程后，手動(dòng)執(zhí)行問(wèn)題腳本，竟然能穩(wěn)定復(fù)現(xiàn)問(wèn)題！看來(lái)是把問(wèn)題想得太簡(jiǎn)單了，嘗試用strace命令看下卡住的進(jìn)程當(dāng)前究竟在干什么：

[tabalt@localhost ~] sudo strace -p 13793
Process 13793 attached - interrupt to quit

什么輸出都沒(méi)有！再用netstat看下這個(gè)進(jìn)程是否打開(kāi)了什么端口：

[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

可以看到進(jìn)程打開(kāi)了兩個(gè)端口，分別與Mysql和Redis建立了連接，并且處于連接建立（ESTABLISHED）和對(duì)方主動(dòng)關(guān)閉連接（CLOSE_WAIT）的狀態(tài)；初看確實(shí)像是和數(shù)據(jù)庫(kù)的連接卡住了，但是因?yàn)槌赃^(guò)虧上過(guò)當(dāng)，咱們使用tcpdump抓包看進(jìn)程和數(shù)據(jù)庫(kù)之間的交互：

tcpdump -i eth0 host 192.168.1.101 and port 3306 -w ~/mysql.cap

抓了好一會(huì)，~/mysql.cap 文件中卻也沒(méi)有任何輸出，難道進(jìn)程和Mysql之間已經(jīng)沒(méi)有任何交互了？那為什么連接建立沒(méi)有關(guān)閉呢？看來(lái)只能從頭追蹤一下腳本的執(zhí)行情況了：

首先為了能來(lái)得及strace到進(jìn)程，在PHP腳本最開(kāi)始的時(shí)候輸出進(jìn)程的pid并sleep 10s:

 echo getmypid(); sleep(10);

然后啟動(dòng)tcpdump準(zhǔn)備抓包本機(jī)和Mysql的交互過(guò)程。

最后執(zhí)行PHP腳本，并復(fù)制輸出的pid后在新窗口中執(zhí)行strace命令。

這下strace和tcpdump都有內(nèi)容了！從strace結(jié)果看recvfrom之后不再有poll，但并沒(méi)有看出來(lái)有什么不對(duì)：

//...
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

再?gòu)淖グY(jié)果看，執(zhí)行了兩條SQL查詢語(yǔ)句之后，進(jìn)程沒(méi)有再次發(fā)送查詢請(qǐng)求的包，從程序記錄SQL語(yǔ)句日志中，也發(fā)現(xiàn)確實(shí)只執(zhí)行了兩條：

select * from sites where type = 1 limit 50;
select * from sites where type = 2 limit 50;

但從這些現(xiàn)象中，仍然沒(méi)有能看出任何端倪，只好祭出終極大法：輸出調(diào)試！大概看了下代碼，并在關(guān)鍵地方添加輸出語(yǔ)句，于是代碼看起來(lái)如下：

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)址時(shí)卡住了：

start foreach
foreach 1
foreach 2

開(kāi)始懷疑調(diào)用的getSites()方法有問(wèn)題，代碼如下:

$sites = array(); // 省略從數(shù)據(jù)庫(kù)查詢的代碼
$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;

原來(lái)這里為了實(shí)現(xiàn)拿8個(gè)不重復(fù)的網(wǎng)址寫了2個(gè)循環(huán)，如果結(jié)果中不重復(fù)的網(wǎng)址只有7個(gè)就會(huì)有一個(gè)空，少于7個(gè)就會(huì)有死循環(huán)！于是查了下type為2的網(wǎng)址個(gè)數(shù)，果然是只有6個(gè)！

關(guān)于“如何排查PHP腳本執(zhí)行卡住的問(wèn)題”這篇文章就分享到這里了，希望以上內(nèi)容可以對(duì)大家有一定的幫助，使各位可以學(xué)到更多知識(shí)，如果覺(jué)得文章不錯(cuò)，請(qǐng)把它分享出去讓更多的人看到。