原文鏈接：http://tabalt.net/blog/php-sc...

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

登錄機(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"

由于之前也遇到過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ù)正常了，于是心滿意足的跑去干別的了。

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

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

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

[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)程打開了兩個(gè)端口，分別與Mysql和Redis建立了連接，并且處于連接建立（ESTABLISHED）和對(duì)方主動(dòng)關(guān)閉連接（CLOSE_WAIT）的狀態(tài)；初看確實(shí)像是和數(shù)據(jù)庫(kù)的連接卡住了，但是因?yàn)槌赃^虧上過當(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 文件中卻也沒有任何輸出，難道進(jìn)程和Mysql之間已經(jīng)沒有任何交互了？那為什么連接建立沒有關(guān)閉呢？看來只能從頭追蹤一下腳本的執(zhí)行情況了：

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

echo getmypid();
sleep(10);

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

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

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

//...
poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=4, revents=POLLIN}])
recvfrom(4, "://xxx.com/