注册 登录
  • 欢迎访问开心洋葱网站,在线教程,推荐使用最新版火狐浏览器和Chrome浏览器访问本网站,欢迎加入开心洋葱 QQ群
  • 为方便开心用户,开心洋葱官网已经开启复制功能!
  • 欢迎访问开心洋葱网站,手机也能访问哦~欢迎加入开心洋葱多维思维学习平台 QQ群
  • 如果您觉得本站非常有看点,那么赶紧使用Ctrl+D 收藏开心洋葱吧~~~~~~~~~~~~~!

脚本PHP执行卡住的问题排查记录

Linux 开心洋葱 2981次浏览 已收录 0个评论 手机上查看

最近从监控上发现,我们一个服务的一台机器负载比同机房的其他机器要高,而流入流出流量没有差别,进一步查看发现每个机房都有一台机器存在相同的现象,梳理后发现有问题的这些机器相比正常的机器多跑了一些PHP脚本,于是猜测是执行脚本出问题导致。

登录机器后执行 top 命令,果然发现存在一个CPU占用较高的PHP进程,然后执行下列命令,发现存在一个由crontab启动的执行了很长时间的PHP脚本:

<code class="language-php hljs">ps aux | grep <span class="hljs-string">'php'</span> | grep -v <span class="hljs-string">'php-fpm'</span></code>

由于之前也遇到过PHP脚本执行卡住的类似情况,当时的怀疑是跨机房的Mysql查询在网络抖动时导致Mysql连接卡住了,于是理所当然的将所有卡住的进程都kill掉了,再从负载上看机器马上就恢复正常了,于是心满意足的跑去干别的了。

过了一段时间,刷了下监控,发现问题又出现了,注释掉crontab并kill掉进程后,手动执行问题脚本,竟然能稳定复现问题!看来是把问题想得太简单了,尝试用strace命令看下卡住的进程当前究竟在干什么:

<code class="language-php hljs">[[email protected] ~] sudo strace -p <span class="hljs-number">13793</span>
Process <span class="hljs-number">13793</span> attached - interrupt to quit</code>

什么输出都没有!再用netstat看下这个进程是否打开了什么端口:

<code class="language-php hljs">[[email protected] ~] sudo netstat -tunpa | grep <span class="hljs-number">13793</span>
tcp        <span class="hljs-number">0</span>      <span class="hljs-number">0</span> <span class="hljs-number">192.168</span><span class="hljs-number">.1</span><span class="hljs-number">.100</span>:<span class="hljs-number">38019</span>        <span class="hljs-number">192.168</span><span class="hljs-number">.1</span><span class="hljs-number">.101</span>:<span class="hljs-number">3306</span>        ESTABLISHED <span class="hljs-number">13793</span>/php
tcp        <span class="hljs-number">0</span>      <span class="hljs-number">0</span> <span class="hljs-number">192.168</span><span class="hljs-number">.1</span><span class="hljs-number">.100</span>:<span class="hljs-number">47107</span>        <span class="hljs-number">192.168</span><span class="hljs-number">.1</span><span class="hljs-number">.102</span>:<span class="hljs-number">6379</span>        CLOSE_WAIT  <span class="hljs-number">13793</span>/php</code>

可以看到进程打开了两个端口,分别与Mysql和Redis建立了连接,并且处于连接建立(ESTABLISHED)和对方主动关闭连接(CLOSE_WAIT)的状态;初看确实像是和数据库的连接卡住了,但是因为吃过亏上过当,咱们使用 tcpdump 抓包看进程和数据库之间的交互:

<code class="language-php hljs">tcpdump -i eth0 host <span class="hljs-number">192.168</span><span class="hljs-number">.1</span><span class="hljs-number">.101</span> <span class="hljs-keyword">and</span> port <span class="hljs-number">3306</span> -w ~/mysql.cap</code>

抓了好一会, ~/mysql.cap 文件中却也没有任何输出,难道进程和Mysql之间已经没有任何交互了?那为什么连接建立没有关闭呢?看来只能从头追踪一下脚本的执行情况了:

  • 首先为了能来得及strace到进程,在PHP脚本最开始的时候输出进程的pid并sleep 10s,代码如下: echo getmypid(); sleep(10);
  • 然后启动tcpdump准备抓包本机和Mysql的交互过程。
  • 最后执行PHP脚本。

这下strace和tcpdump都有内容了!从strace结果看recvfrom之后不再有poll,但并没有看出来有什么不对:

<code class="language-php hljs"><span class="hljs-comment">//...</span>
poll([{fd=<span class="hljs-number">4</span>, events=POLLIN|POLLERR|POLLHUP}], <span class="hljs-number">1</span>, <span class="hljs-number">1471228928</span>) = <span class="hljs-number">1</span> ([{fd=<span class="hljs-number">4</span>, revents=POLLIN}])
recvfrom(<span class="hljs-number">4</span>, <span class="hljs-string">"://xxx.com/\0\0\23jiadia"</span>..., <span class="hljs-number">271</span>, MSG_DONTWAIT, <span class="hljs-keyword">NULL</span>, <span class="hljs-keyword">NULL</span>) = <span class="hljs-number">271</span>
poll([{fd=<span class="hljs-number">4</span>, events=POLLIN|POLLERR|POLLHUP}], <span class="hljs-number">1</span>, <span class="hljs-number">1471228928</span>) = <span class="hljs-number">1</span> ([{fd=<span class="hljs-number">4</span>, revents=POLLIN}])
recvfrom(<span class="hljs-number">4</span>, <span class="hljs-string">"_b?ie=UTF8&node=658390051\0\0008www."</span>..., <span class="hljs-number">271</span>, MSG_DONTWAIT, <span class="hljs-keyword">NULL</span>, <span class="hljs-keyword">NULL</span>) = <span class="hljs-number">206</span></code>

再从抓包结果看,执行了两条SQL查询语句之后,进程没有再次发送查询请求的包,从程序记录SQL语句日志中,也发现确实只执行了两条:

<code class="language-php hljs">select * from sites where type = <span class="hljs-number">1</span> order by weight desc limit <span class="hljs-number">50</span>;
select * from sites where type = <span class="hljs-number">2</span> order by weight desc limit <span class="hljs-number">50</span>;</code>

但从这些现象中,仍然没有能看出任何端倪,只好祭出终极大法:输出调试!大概看了下代码,并在关键地方添加输出语句,于是代码看起来如下:

<code class="language-php hljs"><span class="hljs-keyword">echo</span>(<span class="hljs-string">"start foreach\n"</span>);
<span class="hljs-keyword">foreach</span>($types <span class="hljs-keyword">as</span> $type)
{
    <span class="hljs-keyword">echo</span>(<span class="hljs-string">"foreach $type\n"</span>);
    $result[$type] = $this->getSites($type);
}
<span class="hljs-keyword">echo</span>(<span class="hljs-string">"end foreach\n"</span>);</code>

执行后输出如下,查询type为2的网址时卡住了:

<code class="language-php hljs">start <span class="hljs-keyword">foreach</span>
<span class="hljs-keyword">foreach</span> <span class="hljs-number">1</span>
<span class="hljs-keyword">foreach</span> <span class="hljs-number">2</span></code>

开始怀疑调用的getSites()方法有问题,代码如下:

<code class="language-php hljs">$sites = <span class="hljs-keyword">array</span>();   <span class="hljs-comment">// 省略从数据库查询的代码</span>
$siteNum = <span class="hljs-number">8</span>;       <span class="hljs-comment">// 省略从配置读的代码</span>
$urlKeys = <span class="hljs-keyword">array</span>();
<span class="hljs-keyword">for</span>($i = <span class="hljs-number">0</span>; $i < $siteNum; $i++)
{
    <span class="hljs-keyword">do</span> {
        $site = array_shift($sitesData);
        $urlKey = md5($site[<span class="hljs-string">'url'</span>]);
    } <span class="hljs-keyword">while</span>(array_key_exists($urlKey, $url_keys));

    $urlKeys[$urlKey] = <span class="hljs-number">1</span>;
    $result[] = $site;
}
<span class="hljs-keyword">return</span> $result;</code>

原来这里为了实现拿8个不重复的网址写了2个循环,如果结果中不重复的网址只有7个就会有一个空,少于7个就会有死循环!于是查了下type为2的网址个数,果然是只有6个!

总结一下,该问题从发现到解决花了大概1天时间,虽然最后证明是低级的代码BUG导致,但是整个排查过程还是挺有收获的,最开始的想当然证明是非常肤浅的,过程中tcpdump和strace的结果也已经很能说明问题了,对各个工具的应用应该要更加熟练,工具的结果也要深入分析。


开心洋葱 , 版权所有丨如未注明 , 均为原创丨未经授权请勿修改 , 转载请注明脚本PHP执行卡住的问题排查记录
喜欢 (0)
[开心洋葱]
分享 (0)
关于作者:
开心洋葱,开心洋葱头,水墨

您必须 登录 才能发表评论!

……