http://jackxiang.com/index.php zh-cn http://jackxiang.com/post// jack <xdy108@126.com> Mon, 15 Aug 2011 10:36:06 +0000 http://jackxiang.com/post// [root@emulMachine ~]# pidof nginx 3372 3229 3228 3227 3226 3225 3224 3223 3222 3221 3220 3219 3218 [root@emulMachine ~]# pidof php-fpm 28808 27996 26071 22893 22892 22522 22519 22518 22517 22515 22514 21726 20985 20499 19475 17924 17918 16251 15421 14626 14606 14603 9866 8379 7411 5389 4027 3515 3338 3027 2468 1973 878
有兄弟用它调试PHP在Nginx下的fastcgi：
strace -o xiong.log -p pid slow.log
strace -f -p 1000
-f ——跟踪fork之后的子进程
strace -p pid发现 系统调用select/read被疯狂调用。---同事的解决问题邮件摘录，说明这个strace -p还是很有用滴。

主要是说如何实现strace -p 10747来进行跟踪其进程导致CPU到100%的事情。
　有时候，运行 Nginx、PHP-CGI(php-fpm) Web服务的 Linux 服务器，突然系统负载上升，使用 top 命令查看，很多 php-cgi 进程 CPU 使用率接近100%。后来，我通过跟踪发现，这类情况的出现，跟 PHP 的 file_get_contents() 函数有着密切的关系。

　　大、中型网站中，基于 HTTP 协议的 API 接口调用，是家常便饭。PHP 程序员们喜欢使用简单便捷的 file_get_contents("http://example.com/") 函数，来获取一个 URL 的返回内容，但是，如果 http://example.com/ 这个网站响应缓慢，file_get_contents() 就会一直卡在那儿，不会超时。

　　我们知道，在 php.ini 中，有一个参数 max_execution_time 可以设置 PHP 脚本的最大执行时间，但是，在 php-cgi(php-fpm) 中，该参数不会起效。真正能够控制 PHP 脚本最大执行时间的是 php-fpm.conf 配置文件中的以下参数：
view plainprint?

    The timeout (in seconds) for serving a single request after which the worker process will be terminated  
    Should be used when 'max_execution_time' ini option does not stop script execution for some reason  
    '0s' means 'off'  
    <value name="request_terminate_timeout">0s</value>  

　　默认值为 0 秒，也就是说，PHP 脚本会一直执行下去。这样，当所有的 php-cgi 进程都卡在 file_get_contents() 函数时，这台 Nginx+PHP 的 WebServer 已经无法再处理新的 PHP 请求了，Nginx 将给用户返回“502 Bad Gateway”。修改该参数，设置一个 PHP 脚本最大执行时间是必要的，但是，治标不治本。例如改成 <value name="request_terminate_timeout">30s</value>，如果发生 file_get_contents() 获取网页内容较慢的情况，这就意味着 150 个 php-cgi 进程，每秒钟只能处理 5 个请求，WebServer 同样很难避免“502 Bad Gateway”。

　　要做到彻底解决，只能让 PHP 程序员们改掉直接使用 file_get_contents("http://example.com/") 的习惯，而是稍微修改一下，加个超时时间，用以下方式来实现 HTTP GET 请求。要是觉得麻烦，可以自行将以下代码封装成一个函数。
view plainprint?

    <?php  
    $ctx = stream_context_create(array(  
       'http' => array(  
           'timeout' => 1 //设置一个超时时间，单位为秒  
           )  
       )  
    );  
    file_get_contents("http://example.com/", 0, $ctx);  
    ?>  

　　当然，导致 php-cgi 进程 CPU 100% 的原因不只有这一种，那么，怎么确定是 file_get_contents() 函数导致的呢？

　　首先，使用 top 命令查看 CPU 使用率较高的 php-cgi 进程。

top - 10:34:18 up 724 days, 21:01,  3 users,  load average: 17.86, 11.16, 7.69
Tasks: 561 total,  15 running, 546 sleeping,   0 stopped,   0 zombie
Cpu(s):  5.9%us,  4.2%sy,  0.0%ni, 89.4%id,  0.2%wa,  0.0%hi,  0.2%si,  0.0%st
Mem:   8100996k total,  4320108k used,  3780888k free,   772572k buffers
Swap:  8193108k total,    50776k used,  8142332k free,   412088k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                              
10747 www       18   0  360m  22m  12m R 100.6 0.3    0:02.60 php-cgi                                                                                                              
10709 www       16   0  359m  28m  17m R 96.8  0.4    0:11.34 php-cgi                                                                                                              
10745 www       18   0  360m  24m  14m R 94.8  0.3    0:39.51 php-cgi                                                                                                              
10707 www       18   0  360m  25m  14m S 77.4  0.3    0:33.48 php-cgi                                                                                                              
10782 www       20   0  360m  26m  15m R 75.5  0.3    0:10.93 php-cgi                                                                                                              
10708 www       25   0  360m  22m  12m R 69.7  0.3    0:45.16 php-cgi                                                                                                              
10683 www       25   0  362m  28m  15m R 54.2  0.4    0:32.65 php-cgi                                                                                                              
10711 www       25   0  360m  25m  15m R 52.2  0.3    0:44.25 php-cgi                                                                                                              
10688 www       25   0  359m  25m  15m R 38.7  0.3    0:10.44 php-cgi                                                                                                              
10719 www       25   0  360m  26m  16m R  7.7  0.3    0:40.59 php-cgi

　　找其中一个 CPU 100% 的 php-cgi 进程的 PID，用以下命令跟踪一下：
strace -p 10747

　　如果屏幕显示：
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)
select(7, [6], [6], [], {15, 0})        = 1 (out [6], left {15, 0})
poll([{fd=6, events=POLLIN}], 1, 0)     = 0 (Timeout)

　　那么，就可以确定是 file_get_contents() 导致的问题了。

来自：http://blog.s135.com/file_get_contents/


CentOs6.3 出现：
root@192.168.1.105:~# strace -p 2303
-bash: strace: command not found
root@192.168.1.105:~# yum install strace
yum install strace
Total download size: 167 k
Installed size: 457 k
Is this ok [y/N]: y
...
Installed:
  strace.i686 0:4.5.19-1.11.el6_2.1                                                                                                                    

Complete!
比如Nginx：
root@192.168.1.105:~# ps aux|grep nginx|grep -v "grep"|awk '{print $2}' 1389 1390 1391 1393 1394 1395
用如下命令去看多个进程：
strace -p 1390 -p 1389 -p 1391 -p 1393 -p  1394 -p 1395 -p 1395 [/php] 访问时一个1391的进程做了如下操作，这样能在某种程序给我们提供线索，最后能解决实际问题： [pid  1391] setsockopt(33, SOL_TCP, TCP_CORK, [0], 4) = 0 [pid  1391] recv(33, 0x8e61930, 32768, 0) = -1 EAGAIN (Resource temporarily unavailable) [pid  1391] epoll_wait(28, {{EPOLLIN, {u32=3039863392, u64=580689666042274400}}}, 512, 500) = 1 [pid  1391] gettimeofday({1342306122, 682220}, NULL) = 0 [pid  1391] recv(34, "GET /template/zhanhelp_huaxi100/"..., 32768, 0) = 717 [pid  1391] open("/data0/htdocs/naimanqi/template/zhanhelp_huaxi100/zhanhelp_img/titlebg.png", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 36 [pid  1391] fstat64(36, {st_mode=S_IFREG|0777, st_size=315, ...}) = 0 [pid  1391] setsockopt(34, SOL_TCP, TCP_CORK, [1], 4) = 0 [pid  1391] writev(34, [{"HTTP/1.1 200 OK\r\nServer: nginx/1"..., 215}], 1) = 215 [pid  1391] sendfile64(34, 36, [0], 315) = 315 [pid  1391] write(5, "192.168.1.103 - - [15/Jul/2012:0"..., 252) = 252 [pid  1391] write(5, "192.168.1.103 - - [15/Jul/2012:0"..., 252) = 252 [pid  1391] write(6, "192.168.1.103 - - [15/Jul/2012:0"..., 252) = 252 [pid  1391] write(7, "192.168.1.103 - - [15/Jul/2012:0"..., 252) = 252 [pid  1391] write(8, "192.168.1.103 - - [15/Jul/2012:0"..., 252) = 252 [pid  1391] close(36)                   = 0 来自网页： 在linux環境之下，trace任意一執行檔或 function，畫出流程圖，並秀出執行過程中呼叫了哪些system call，標明每一個system call之目的及參數意義。以圖、表方式呈現更佳。 若打 strace 指令時出現 -bash: strace: command not found 表示系統沒有安裝 strace ，打下列指令 rpm -qa | grep strace 會出現安裝 strace 所需要的 rpm 檔名，如 strace-4.5.15- 1.fc6 下載後再打 rpm -ivh rpm 檔名 (這邊是 strace-4.5.15- 1.fc6 ) 即可安裝。 若distribution 是用 debian 系列，則下 apt-get install strace 通过启用php-fpm的slowlog来解决PHP CPU占用过高问题： 前阵子通过top发现PHP-fpm的进程很高，网站打开速度很慢，估计肯定某个PHP脚本执行时间过长，所以开启了php-fpm的slowlog来跟踪哪些php脚本执行过慢。 开启方法如下： 编辑php-fpm.conf文件 找到request_slowlog_timeout = 0这一行，默认值为0，表示不开启slowlog，将其值改为3s，表示跟踪执行时间达到或超过3s的脚本。 找到slowlog，它的值表示慢执行日志的路径。 修改完后需要重启php，slowlog的文件的内容大概是这样的： [31-Dec-2012 09:50:00] [pool www] pid 2874 script_filename = /htdocs/blog/index.php [0x0000000001cf4ff0] mysql_query() /htdocs/blog/class/mysql.php:9 [0x0000000001cf4ec0] query() /htdocs/blog/class/mysql.php:26 [0x0000000001cf4a70] one() /htdocs/blog/class/ware.php:88 [0x0000000001cf46c8] query() /htdocs/blog/function/common.php:132 [0x0000000001cf3a40] +++ dump failed 这样就可以很明显看到什么mysql.php的mysql_query()方法执行的语句超时了。 来自：http://www.linuxde.net/2013/01/11854.html 参考：http://blog.csdn.net/delphiwcdj/article/details/7387325 二、fopen/fwrite写入不进去经strace子进程发现没空间的实践操作： [pid 22114] open("/tmp/out.dat", O_RDWR|O_CREAT|O_APPEND, 0666) = 6 [pid 22114] open("/tmp/out.mp4", O_RDWR|O_CREAT|O_APPEND, 0666) = 7 [pid 22114] fstat(6, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0 [pid 22114] fstat(7, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0 [pid 22114] write(6, "POST /upload?uuid=84b1052c-ebc5-"..., 1024) = -1 ENOSPC (No space left on device) [pid 22114] write(7, "Begin:The fox and the grapes\nHun"..., 902) = -1 ENOSPC (No space left on device) [pid 22114] close(6)   [pid 22114] close(7) 代码如下： [codes=php]                         if (recvlen == msglen)//循环终止条件之一：当前待处理TCP消息恰好为一条完整的应用层消息                         {                             printf("\n\nFinished,运行的包结束了，指向这儿：写入长度recvlen=%d,buf=%s\n!!!!!!!!!!!!!!!!!!!!\n",recvlen,buf);                             FILE *dst,*dst3;                             dst=fopen("/tmp/out.dat","a+");                             dst3=fopen("/tmp/out.mp4","a+");                             if(dst==NULL){                                 printf("cant'to open destination file\n");                                 return 0;                             }                             printf("write to /tmp/out.dat's recvlen's length=%d\n",strlen(buf));                             fwrite(buf,recvlen,1,dst);                             buf2=buf;                             getContentLen(buf2,&httpBodyLen);                             fwrite(buf2+httpHeadersLen,httpBodyLen,1,dst3);                             fclose(dst);                             fclose(dst3);                             rs=0;                             buf = NULL;                             break;                         }else{                             printf("\n********出现根据头部和头部里的长度之和与Receive接收到的实际长度不一致。recvlen %d==?==%d msglen********\n",recvlen,msglen);                         }                         //出现一个包里有两个Content-Length的实际情况                         FILE *dst2,*dst4;                         dst2=fopen("/tmp/out.dat","a+");                         dst4=fopen("/tmp/out.mp4","a+");                         if(dst2==NULL){                             printf("cant'to open destination file\n");                             return 0;                         }                         printf("write to /tmp/out.dat's recvlen's length=%d\n",strlen(buf));                         fwrite(buf,msglen,1,dst2);                         buf2=buf;                         getContentLen(buf2,&httpBodyLen);                         fwrite(buf2+httpHeadersLen,httpBodyLen,1,dst4);                         fclose(dst2);                         fclose(dst4); ]]> http://jackxiang.com/post//#blogcomment <user@domain.com> Thu, 01 Jan 1970 00:00:00 +0000 http://jackxiang.com/post//#blogcomment