首页 ›存档› 技术 › 查看内容

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

2018-3-30 13:00 |来自: 互联网 325 0

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

最近从监控上发现，我们一个服务的一台机器负载比同机房的其他机器要高，而流入流出流量没有差别，进一步查看发现每个机房都有一台机器存在相同的现象，梳理后发现有问题的这些机器相比正常的机器多跑了一些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 13793Process 13793 attached - interrupt to quit

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

[tabalt@localhost ~] sudo netstat -tunpa | grep 13793tcp    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, "://**.com/\0\0\23jiadia"..., 271, MSG_DONTWAIT, NULL, NULL) = 271poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 1471228928) = 1 ([{fd=4, revents=POLLIN}])
recvfrom(4, "_b?ie=UTF8

声明：文章版权归原作者所有部分文章转自互联网如有侵权请联系 [邮箱地址] 删除

路过

雷人

握手

鲜花

鸡蛋

收藏分享邀请

上一篇：2016微信数据报告发布下一篇：MySQL数据库innodb_rollback_on_timeout默认值的危害

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

相关分类