03 30,2016

使用GDB调试PHP core dump

最近线上服务器出现了访问不上的情况,查看php-fpm发现大量的WARNING: [pool www] child 11274 exited on signal 31 (SIGSYS) after 0.089068 seconds from start错误,然后php-fpm进程在不断的重启。

查看PHP的错误日记并没有太多可用信息,既然如此那就尝试抓取core dump使用gdb调试看下吧。

关于core dump

我们经常听到大家说到程序core掉了,需要定位解决,这里说的大部分是指对应程序由于各种异常或者bug导致在运行过程中异常退出或者中止,并且在满足一定条件下(这里为什么说需要满足一定的条件呢?下面会分析)会产生一个叫做core的文件。

通常情况下,core文件会包含了程序运行时的内存,寄存器状态,堆栈指针,内存管理信息还有各种函数调用堆栈信息等,我们可以理解为是程序工作当前状态存储生成第一个文件,许多的程序出错的时候都会产生一个core文件,通过工具分析这个文件,我们可以定位到程序异常退出的时候对应的堆栈调用等信息,找出问题所在并进行及时解决。

core dump默认是不生成的文件,所以首先我们要开启下。

设置core dump路径

# echo "/tmp/core.%p" > /proc/sys/kernel/core_pattern

修改ulimit允许生成core dump文件

# ulimit -c unlimited

重启php-fpm。 过一会进入/tmp,就会发现生成很多core.xxx的文件。这个时候设置关闭core dump并重启php-fpm。

# ulimit -c 0

这个时候就可以使用gdb进行调试core dump,注意因为生成core dump的是php-fpm,所以这里需要使用php-fpm进行调试。如果在cli模式使用php生成的core dump才是使用php程序进行调试。

gdb /usr/local/php/sbin/php-fpm -c /tmp/core.10375

...

#0  zend_hash_index_find (ht=0x0, arKey=0x0, nKeyLength=0, h=0, pData=0x7fff81cef780) at /usr/local/src/autosetup/tmp/php-5.4.16/Zend/zend_hash.c:1021
1021        p = ht->arBuckets[nIndex];
Missing separate debuginfos, use: debuginfo-install ImageMagick-6.5.4.7-7.el6_5.x86_64 bzip2-libs-1.0.5-7.el6_0.x86_64 cyrus-sasl-lib-2.1.23-13.el6_3.1.x86_64 expat-2.0.1-11.el6_2.x86_64 fontconfig-2.8.0-5.el6.x86_64 freetype-2.3.11-15.el6_6.1.x86_64 glibc-2.12-1.149.el6_6.7.x86_64 keyutils-libs-1.4-5.el6.x86_64 krb5-libs-1.10.3-37.el6_6.x86_64 lcms-libs-1.19-1.el6.x86_64 libICE-1.0.6-1.el6.x86_64 libSM-1.2.1-2.el6.x86_64 libX11-1.6.0-2.2.el6.x86_64 libXau-1.0.6-4.el6.x86_64 libXext-1.3.2-2.1.el6.x86_64 libXt-1.1.4-6.1.el6.x86_64 libcom_err-1.41.12-21.el6.x86_64 libcurl-7.19.7-40.el6_6.4.x86_64 libgcc-4.4.7-11.el6.x86_64 libgomp-4.4.7-11.el6.x86_64 libidn-1.18-2.el6.x86_64 libselinux-2.0.94-5.8.el6.x86_64 libssh2-1.4.2-1.el6.x86_64 libstdc++-4.4.7-11.el6.x86_64 libtiff-3.9.4-10.el6_5.x86_64 libtool-ltdl-2.2.6-15.5.el6.x86_64 libuuid-2.17.2-12.14.el6.x86_64 libxcb-1.9.1-2.el6.x86_64 libxml2-2.7.6-17.el6_6.1.x86_64 net-snmp-libs-5.5-50.el6_6.1.x86_64 nspr-4.10.0-1.el6.x86_64 nss-3.15.1-15.el6.x86_64 nss-softokn-freebl-3.14.3-9.el6.x86_64 nss-util-3.15.1-3.el6.x86_64 openldap-2.4.23-32.el6_4.1.x86_64 openssl-1.0.1e-30.el6.8.x86_64 zlib-1.2.3-29.el6.x86_64

// 查看调用栈
(gdb) bt
#0  zend_hash_index_find (ht=0x0, arKey=0x0, nKeyLength=0, h=0, pData=0x7fff81cef780) at /usr/local/src/autosetup/tmp/php-5.4.16/Zend/zend_hash.c:1021
#1  zend_hash_quick_find (ht=0x0, arKey=0x0, nKeyLength=0, h=0, pData=0x7fff81cef780) at /usr/local/src/autosetup/tmp/php-5.4.16/Zend/zend_hash.c:943
#2  0x00007ff5d6433da3 in zim_RedisArray_mget (ht=<value optimized out>, return_value=0x7ff5e2ee3338, return_value_ptr=<value optimized out>, this_ptr=<value optimized out>, 
return_value_used=<value optimized out>) at /usr/local/src/autosetup/tmp/phpredis/redis_array.c:866
#3  0x00007ff5d266d240 in pt_execute_core (internal=1, execute_data=0x7ff5e2ead060, op_array=0x0, rvu=0) at /data/tgz/trace-0.3.0/extension/trace.c:933
#4  0x0000000000776623 in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/local/src/autosetup/tmp/php-5.4.16/Zend/zend_vm_execute.h:645
#5  0x000000000076a8c0 in execute (op_array=0x7ff5e2ee0778) at /usr/local/src/autosetup/tmp/php-5.4.16/Zend/zend_vm_execute.h:410
#6  0x00007ff5d266d0bd in pt_execute_core (internal=0, execute_data=0x0, op_array=0x7ff5e2ee0778, rvu=0) at /data/tgz/trace-0.3.0/extension/trace.c:936
#7  0x0000000000704d0e in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /usr/local/src/autosetup/tmp/php-5.4.16/Zend/zend.c:1315
#8  0x00000000006aacae in php_execute_script (primary_file=0x7fff81cf3410) at /usr/local/src/autosetup/tmp/php-5.4.16/main/main.c:2494
#9  0x00000000007aacf3 in do_cli (argc=2, argv=0x7fff81cf3818) at /usr/local/src/autosetup/tmp/php-5.4.16/sapi/cli/php_cli.c:988
#10 0x00000000007ab3f4 in main (argc=2, argv=0x7fff81cf3818) at /usr/local/src/autosetup/tmp/php-5.4.16/sapi/cli/php_cli.c:1364

可以看到调用在#2 zim_RedisArray_mget这个函数调用的时候发生了异常退出。

从PHP来看这个调用栈还不够清晰,PHP也提供了一个.gdbinit(gdb命令编写脚本)帮我们查看PHP函数层的调用栈。

(gdb) source /usr/local/tgz/php5.4.16/.gdbinit
(gdb) zbacktrace
[0x7ff5e2ead060] RedisArray->mget(array(1)[0x7ff5e2ee1ac0]) /xxxx

至此,错误很明显了,是由于调用redis的mget发生的core dump。在phpredis的github上有发现这个Issues,是2.2.3的一个bug。由于使用RedisArray链接失败的时候并没有报错,在执行命令时才进行判断connection是否可用,导致调用mget的时候connection closed触发了这个core dump。

至于为什么connection closed,翻看了下phpredis代码,发现有两种情况,一种是链接失败,一种是被关闭,由于phpredis中没有主动调用disconnect,所以需要PHP脚本完成后,由zend进行注销处理。因此,这里只可能是第一种情况,就是链接失败。