问题
18-Feb-2014 15:48:45] WARNING: [pool www] child 11274 exited on signal 11 (SIGSEGV) after 0.089068 seconds from start
显然11274进程运行过程中遇到了段错误导致进程异常退出了。继续追查发现是php的hsf扩展在启动初始化的时候遇到内存问题导致段错误。
沧老师这个段错误进程你怎么定位到是hsf扩展的问题?
分析过程
发现段错误:
日志中的信息表明,进程号为11274的进程由于收到SIGSEGV信号而退出了。收到这个信号的时候,程序是可以生成core文件的。不过通过日志我们可以知道进程11274退出时没有生成core文件。因为在php-fpm的日志中,如果退出时生成了core文件,日志中会有“SIGSEGV - core dumped”字样。如:
[20-Feb-2014 08:37:59] WARNING: [pool www] child 15845 exited on signal 11 (SIGSEGV - core dumped) after 1.051001 seconds from start
生成core文件:
为啥没生成core文件?是因为我们的系统做了限制。执行如下命令可以查看限制情况:
$ulimit -c unlimited
通过命令,我们就把系统对于core文件的大小限制去除了。
<img src="http://www.bo56.com/wp-content/uploads/2014/03/ulimit1.jpg" alt="ulimit1" width="400" height="215" class="alignnone size-full wp-image-339" /></a><br /> 设置完后,重启了php-fpm 进程。剩下的事情,就是坐等core文件生成了。
第二天,查看php-fpm日志,发现了如下记录:
[20-Feb-2014 08:37:59] WARNING: [pool www] child 15845 exited on signal 11 (SIGSEGV - core dumped) after 1.051001 seconds from start
[20-Feb-2014 08:39:04] WARNING: [pool www] child 17803 exited on signal 11 (SIGSEGV - core dumped) after 0.927973 seconds from start
[20-Feb-2014 08:42:18] WARNING: [pool www] child 23491 exited on signal 11 (SIGSEGV - core dumped) after 0.798308 seconds from start
说明,core文件已经生成。
gdb分析core文件:
既然core文件生成了,现在该gdb上场了。通过如下命令查看程序退出时的栈信息。
$gdb -e /home/php/sbin/php-fpm -c core.15845
..............此处省略n多无关紧要的字
$info threads
3 process 15850 0x0000003cf92d3f9a in epoll_ctl () from /lib64/libc.so.6
2 process 15845 0x0000003cf92c4f65 in _xstat () from /lib64/libc.so.6
* 1 process 15851 0x00007fa94e230310 in ez_run (loop=0x2434c60, flags=0) at ez.c:2363
$thread 2
[Switching to thread 2 (process 15845)]#0 0x0000003cf92c4f65 in _xstat () from /lib64/libc.so.6
$bt
#0 0x0000003cf92c4f65 in _xstat () from /lib64/libc.so.6
#1 0x00007fa94df8fd8b in hsf::hsf_mkdir (path=0x7fa930001628 "/home/logs/hsfcpp") at /usr/include/sys/stat.h:436
#2 0x00007fa94df8feae in hsf::hsf_mkdirp (pathname=<value optimized out>) at utils/fileutils.cc:50
#3 0x00007fa94dfad7cc in hsf::hsf_stat_log_init (path=@0x7fa94e21f080, name=@0x7fffb607a620) at hsf/hsf_stat_file.cc:37
#4 0x00007fa94dfabb36 in hsf::hsf_stat_monitor::init (this=<value optimized out>) at hsf/hsf_stat_monitor.cc:231
#5 0x00007fa94dfa899a in hsf_core_bootstrap () at hsf/hsf.cc:104
#6 0x00007fa94dfa8cea in hsf::hsf_core::init () at hsf/hsf.cc:129
#7 0x00007fa94e448b52 in zm_activate_hsf (type=<value optimized out>, module_number=<value optimized out>) at /home/lingzhan/hsf_php_0.9/php_hsf.cpp:188
#8 0x000000000061d94c in ?? ()
#9 0x000000000226ee20 in ?? ()
#10 0x0000000000624c35 in ?? ()
#11 0x00000000024bc840 in ?? ()
#12 0x00000000024bc840 in ?? ()
#13 0x00000000024bc840 in ?? ()
#14 0x0000000000000000 in ?? ()
再继续分析其他的两个core文件,发现也都有这个栈信息。基本可以肯定是hsf的问题了。
另外,在/var/log/message 中也发现了如下记录:
Mar 13 14:40:07 s006132.cm6 kernel: : [5332900.567547] php-fpm[31017]: segfault at 30 ip 00007fdc74df3310 sp 00000000435b8040 error 4 in libeasy.so.0[7fdc74de3000+23000]
libeasy.so 正是hsf中调用的。进一步确认是执行hsf程序时出现问题的。