PHP-FPMでSIGSEGVエラーが出る際にcore dumpを確認する
502 Bad GatewayとSIGSEGV
こんにちは、ナカエです。とても久しぶりのブログ記事です。
先日、PHPを利用したWebアプリケーションで、nginxがステータスコード502 Bad Gatewayのレスポンスを返してくる不具合がありました。そのデバッグ作業で利用したcore dumpの確認方法を覚書を兼ねて残しておきます。
環境
- Centos6
- nginx1.13
- PHP-FPM (PHP5.6/Remiリポジトリからインストール)
エラーログを確認すると、それぞれ下記の通り。
PHPやフレームワークのログ
特にエラー出力なし
nginx (/var/log/nginx/error.log)
2017/05/10 12:52:37 [error] 1042#1042: *360 recv() failed (104: Connection reset by peer) while reading response header from upstream, (以下略)
PHP-FPM (/var/log/php-fpm/error.log)
[10-May-2017 12:52:37] WARNING: [pool www] child 17248 exited on signal 11 (SIGSEGV) after 5523.752586 seconds from start
oh...SIGSEGV...! セグメンテーション違反(セグフォ)ですね。ネットで検索してみても同様のエラーログは見つかりますが、セグフォの原因は様々ですので、片っ端から試していても日が暮れます。
正攻法でプロセスのcore dumpを確認するほうが手早く解決できることが多いです。
core dump とは
コアダンプ(英語:core dump)は、ある時点の使用中のメモリの内容をそのまま記録したものであり、一般に異常終了したプログラムのデバッグに使われる。最近では、特定のプロセスのメモリイメージ(あるいはその一部)とレジスタの内容などの情報を格納したファイルを指すのが一般的である。
1. coreファイルの出力先を設定する
$ cat /proc/sys/kernel/core_pattern
core
デフォルトでは"core"という設定になっており、それぞれのプロセスの作業ディレクトリに出力されています。個人的には変更したほうが見つけやすいので設定を変更しました。
$ echo '/tmp/core-%e.%p' > /proc/sys/kernel/core_pattern
%eと%pはパラメータ
- %e: 実行ファイル名(パスのプリフィックスはなし)
- %p: PID
※再度"core"に書き換えるか、システム再起動で元に戻ります。
2. PHP-FPMの設定を変更
PHP-FPMのWeb用設定ファイルを開き、
$ vim /etc/php-fpm.d/www.conf
rlimit_coreの設定をunlimitedに変更します。※作業後に設定を戻すので元の設定は控えておきましょう
rlimit_core = unlimited
PHP-FPMを再起動します
$ service php-fpm restart
3. セグメンテーションフォルトを起こす操作を実行
セグフォを再現します。コアファイルが正常に吐かれている場合、エラーログのメッセージが若干変換します。
child 17248 exited on signal 11 (SIGSEGV - core dumped)
コアファイルは/tmp/core-php-fpm.1234などとして出力されます。
4. gdbでcore dumpの中身を確認する
gdbが入っていなければインストールしておきます。
$ yum install gdb
PHP-FPMのパスを調べ
$ which php-fpm
/usr/sbin/php-fpm
gdbを実行します
$ gdb {php-fpm のパス} {coreファイルのパス}
例)
gdb /usr/sbin/php-fpm /tmp/core-php-fpm.1234
core dumpファイルの情報が表示され、gdbのシェルが開きます
スタック全体のバックトレースを表示します
(gdb) bt
#0 0x00000000005986ac in php_stream_context_get_option ()
#1 0x00007f6c0cec69e6 in php_stream_zip_opener () from /usr/lib64/php/modules/zip.so
#2 0x000000000059a343 in _php_stream_open_wrapper_ex ()
#3 0x000000000053ee03 in ?? ()
#4 0x00000000005d4029 in dtrace_execute_internal ()
#5 0x0000000000663585 in ?? ()
#6 0x0000000000653058 in execute_ex ()
#7 0x00000000005d415e in dtrace_execute_ex ()
#8 0x0000000000663bf4 in ?? ()
#9 0x0000000000653058 in execute_ex ()
#10 0x00000000005d415e in dtrace_execute_ex ()
#11 0x0000000000663bf4 in ?? ()
#12 0x0000000000653058 in execute_ex ()
#13 0x00000000005d415e in dtrace_execute_ex ()
#14 0x0000000000663bf4 in ?? ()
#15 0x0000000000653058 in execute_ex ()
#16 0x00000000005d415e in dtrace_execute_ex ()
#17 0x00000000005d6bd0 in zend_call_function ()
#18 0x0000000000524c27 in ?? ()
#19 0x00000000005d4029 in dtrace_execute_internal ()
#20 0x0000000000663585 in ?? ()
#21 0x0000000000653058 in execute_ex ()
#22 0x00000000005d415e in dtrace_execute_ex ()
#23 0x0000000000663bf4 in ?? ()
#24 0x0000000000653058 in execute_ex ()
今回のケースはzip拡張でクラッシュしていたことがわかりました。zip拡張の更新内容を確認すると、システムのlibzipのバージョンがzip拡張の要求バージョンを満たしていなかったようです。
今回はCの関数レベルでのバックトレースだけで十分でしたが、PHPのソースレベルで確認したい場合はPHPソースに付属する.gdbinitを使利用すると良いでしょう。
--commandオプションで.gdbinitファイルのパスを指定してgdbを起動すると、zbacktraceなどPHP用のカスタムコマンドが利用できます。
後片付け
coreファイルの確認が終わったら、変更した内容を元に戻しておきます。
- /etc/php-fpm.d/www.conf のrlimit_coreの設定を戻す
- /proc/sys/kernel/core_pattern の中身を"core"に戻す(システムを再起動でも元に戻るはず)