最近線上伺服器出現了通路不上的情況,檢視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=, return_value=0x7ff5e2ee3338, return_value_ptr=, this_ptr=,
return_value_used=) 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=) 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進行登出處理。是以,這裡隻可能是第一種情況,就是連結失敗。