Q&A
Segmentation faultはStatementのclose漏れ対応後も発生するのですか？
初めて質問させていただきます。
yum updateでphp7.0.2にアップデートしました。
サーバー上のアプリケーションは、見た目上は特に不具合なく動いているのですが、ApacheのエラーログにはSegmentation faultが非常に多く記録されるようになってしまいました。
（例）
[notice] child pid 2566 exit signal Segmentation fault (11)
coreファイルを取得し、gdbを見てみたのですが、下記のような結果になりました。
(gdb)where の結果
#0 0x00007f177b70a2ff in zend_hash_str_find () from /etc/httpd/modules/libphp7.so #1 0x00007f177b60745e in php_session_start () from /etc/httpd/modules/libphp7.so #2 0x00007f177b60793d in ?? () from /etc/httpd/modules/libphp7.so #3 0x00007f177b6eeaa9 in dtrace_execute_internal () from /etc/httpd/modules/libphp7.so #4 0x00007f177b773d12 in ?? () from /etc/httpd/modules/libphp7.so #5 0x00007f177b73bf10 in execute_ex () from /etc/httpd/modules/libphp7.so #6 0x00007f177b6eebee in dtrace_execute_ex () from /etc/httpd/modules/libphp7.so #7 0x00007f177b78efcb in zend_execute () from /etc/httpd/modules/libphp7.so #8 0x00007f177b6fd553 in zend_execute_scripts () from /etc/httpd/modules/libphp7.so #9 0x00007f177b69ef90 in php_execute_script () from /etc/httpd/modules/libphp7.so #10 0x00007f177b792e6d in ?? () from /etc/httpd/modules/libphp7.so #11 0x00007f1785fe7490 in ap_run_handler () #12 0x00007f1785fead1e in ap_invoke_handler () #13 0x00007f1785ff64c0 in ap_process_request () #14 0x00007f1785ff32a8 in ?? () #15 0x00007f1785feefa8 in ap_run_process_connection () #16 0x00007f1785ffb4f7 in ?? () #17 0x00007f1785ffb81a in ?? () #18 0x00007f1785ffbb4b in ap_mpm_run () #19 0x00007f1785fd2d55 in main ()
いくつか出てきたcoreファイルは、すべてこのエラーでした。
libphp7.soに問題があるように思えますが、同様なハマり方をした方、どのように解決されましたでしょうか。
エラーログの出方ですが、HTTPアクセスの量に応じてログも増えているような傾向があるのですが、いっぺんに3プロセスほどまとまって落ちたり、完全にHTTPアクセスと同期したエラーではなさそうに思えます。
[Wed Feb 03 11:45:07 2016] [notice] child pid 11648 exit signal Segmentation fault (11)
[Wed Feb 03 11:45:07 2016] [notice] child pid 11651 exit signal Segmentation fault (11)
[Wed Feb 03 11:45:07 2016] [notice] child pid 11662 exit signal Segmentation fault (11)
プロセスはhttpdで間違い無さそうなのですが、やはり普通にサイトは動作しているようで、
このエラーが発生した時にユーザーに障害が発生しているということでもなさそうです。
キャッシュ関連の動作（Opchaceなど？）が関連しているのかもと思いましたが、正体がわかりません…。
他、関連するかはわからないですが起きている事象としては、MySQLのAborted clientsが似たようなペースで増えています。
これも、PHPアップデート前は発生していませんでした。
どなたか、ご助言いただけますと幸いです。
よろしくお願いいたします。
###【201602031909追記】
エラーログとプロセスを確認したところ、少し事象が見えてきたきがしたので追記です。
ある時間（2016-02-03-1825）のtopのスクリーンショットを取り、その後のエラーログを確認したところ、殆どのhttpdプロセスはこのエラーを吐いているということがわかりました。
これに映っているhttpdのPIDを全て調べたところ、2/3くらいはエラーログが存在しました。
apache
1# 201602031902頃のエラーログを検索 2[Wed Feb 03 18:26:52 2016] [notice] child pid 21489 exit signal Segmentation fault (11) 3[Wed Feb 03 18:27:41 2016] [notice] child pid 21493 exit signal Segmentation fault (11) 4[Wed Feb 03 18:28:25 2016] [notice] child pid 21440 exit signal Segmentation fault (11) 5[Wed Feb 03 18:27:43 2016] [notice] child pid 21366 exit signal Segmentation fault (11) 6[Wed Feb 03 18:28:19 2016] [notice] child pid 21522 exit signal Segmentation fault (11) 7[Wed Feb 03 18:28:22 2016] [notice] child pid 21520 exit signal Segmentation fault (11) 8[Wed Feb 03 18:28:25 2016] [notice] child pid 21494 exit signal Segmentation fault (11) 9[Wed Feb 03 18:28:27 2016] [notice] child pid 21257 exit signal Segmentation fault (11) 10[Wed Feb 03 18:28:47 2016] [notice] child pid 21519 exit signal Segmentation fault (11) 11[Wed Feb 03 18:30:15 2016] [notice] child pid 21455 exit signal Segmentation fault (11) 12[Wed Feb 03 18:31:15 2016] [notice] child pid 21376 exit signal Segmentation fault (11) 13 14 15↓無かったPID 1621521 1721444 1821403 1921453 2021525 21
また、topコマンドで今生きているPIDをエラーログから探しても見つかりませんでした。（これは当たり前ですかね…）
サイトのアプリケーション動作自体は普通に動いている、サイトアクセスの増加にともなってエラーログも増える、ということを踏まえると、このエラーはhttpdプロセスが終了する時に発生しているのでは、という気がしてきました。
###【20160205追記】
更に色々と調査しました。
最初の書き込み時に下記の現象について書きました。
MySQLのAborted clientsが似たようなペースで増えています。
これも、PHPアップデート前は発生していませんでした。
これの原因が判明しました。
オブログ — Statement の解放漏れには気をつけよう
スクリプトを調べたところ、いくつかMySQLのStatementをcloseしていない箇所が見つかり、それをcloseするように直したところ、Aborted cliantの増加は止まりました。
正常に動作する場合は、新しい PreparedStatement が上書きされた後に GC が上手く動作して古い PreparedStatement が解放されるのですが、GC が上手く動作しない場合は古い PreparedStatement が解放されず、データベースとの接続を保った状態のまま残ってしまいます。
この問題が発生する前ではStatementをcloseしなくてもAborted cliantが増えてなかったのが、問題発生後に顕在化したということは、上記引用にある通り、GCが上手く動作しない状態にあるのではと推察します。
- PHPをupdate後、GCに問題が発生し、Segmentation faultが大量発生
- GCが上手く動かないため、これまではよしなにされていたPHPスクリプトのStatement解放漏れが顕在化
というのが現状なのかと思います。
2に関してはもともとスクリプト側の問題ということで、それはそれで修正出来て良かったのですが、1に関しては未だに原因不明です。
思いあたる節としては、諸事情でPHPのインストールユーザーとApacheの実行ユーザーに違いがあるため、sesston_save_pathの所有者がそのままだとセッションの書き込みが出来ないために、そのディレクトリの所有者をchownしている点です。
他に所有者変更が必要なディレクトリがあるのかもしれませんが、調べても見つかりませんでした。
どなたか、ご意見いただけますと幸いです。
###【20160209追記】
PHP7.0.3がリリースされていたので、アップデートしてみては、との助言をいただきました。
ssh
1yum --enablerepo=remi-php70 update php php-devel php-opcache 2
PHP 7.0.3 (cli) (built: Feb 3 2016 11:40:05) ( NTS ) Copyright (c) 1997-2016 The PHP Group Zend Engine v3.0.0, Copyright (c) 1998-2016 Zend Technologies with Zend OPcache v7.0.6-dev, Copyright (c) 1999-2016, by Zend Technologies
アップデートは問題なく終了したのですが、サーバー再起動後、やはり継続してSegment faultは発生し続けています。
PHP本体の問題ではなかったのですかね…。
Zend OPcache がv7.0.6-devなのが少し気になりますが、もしかしてこれのverを下げたほうがいいのでしょうか。
ご意見いただけますと幸いです。
###【20160209追記2】
PHPのバグフォーラムを調べたところ、PHP7.0.2で似たような状況の報告を見つけました。
「見かけは動いているけど、Segmentation faultエラーが大量に出る」という点で一致しています。
gdbの結果の内容は違うみたいですが、原因は同じなのでしょうか。
また、httpdのプロセスidを観察してみたところ、やはり終了時にSegmentation faultが発生しているので間違い無さそうでした。
topコマンドで今ある適当なpidを選び、
/proc ディレクトリにあるプロセスディレクトリを監視、
それが消去された時点でApacheエラーログを見たところ、同じpidのSegmentation faultログが出力されていることを確認しました。
他、使用しているPHPライブラリに問題がないか確かめましたが、これも無関係のようでした。
引き続き調査しようと思います。
###【20160212追記】
コメントにて、php-debuginfoを入れて再度gdbをとのご意見をいただきましたので、結果を記載します。
ssh
1yum --enablerepo=remi-php70 install php-debuginfo 2
php70-php-debuginfo-7.0.3-1.el6.remi.x86_64がインストールされました。
coreファイルをgdbで実行し、where,listをしてみた結果が以下です。
(gdb) where #0 0x00007f177b70a2ff in zend_hash_index_find_bucket (ht=0x0, h=13841567621774083997) at /usr/src/debug/php-7.0.3/Zend/zend_hash.c:544 #1 zend_hash_index_exists (ht=0x0, h=13841567621774083997) at /usr/src/debug/php-7.0.3/Zend/zend_hash.c:2021 #2 0x00007f177b60745e in ?? () at /usr/src/debug/php-7.0.3/ext/session/session.c:1676 from /etc/httpd/modules/libphp7.so #3 0x00007f17790174a0 in ?? () #4 0x00007f177bacb368 in labels.92387 () from /etc/httpd/modules/libphp7.so #5 0x00007f17882f0410 in ?? () #6 0x00007f1779017030 in ?? () #7 0x00007f177bacb366 in labels.92387 () from /etc/httpd/modules/libphp7.so #8 0x00007f177b60793d in zend_string_release () at /usr/src/debug/php-7.0.3/Zend/zend_string.h:271 #9 php_session_start () at /usr/src/debug/php-7.0.3/ext/session/session.c:1644 #10 0x0000000000000000 in ?? () (gdb) list 539 nIndex = h | ht->nTableMask; 540 idx = HT_HASH_EX(arData, nIndex); 541 while (idx != HT_INVALID_IDX) { 542 ZEND_ASSERT(idx < HT_IDX_TO_HASH(ht->nTableSize)); 543 p = HT_HASH_TO_BUCKET_EX(arData, idx); 544 if (p->h == h && !p->key) { 545 return p; 546 } 547 idx = Z_NEXT(p->val); 548 }
zend_hash_index_find_bucketの問題なのかと思い検索してみましたが、過去この部分にバグフィックスがあったらしい（もう直ってる）ことくらいしかわかりませんでした。
ご意見いただけますと幸いです。
###【20160212追記2】
文字数の制限に達してしまったので、gdb listを1個1個のframeに対して実行した結果を作成しました。
ここからもし原因がわかれば、ご助言いただけますと幸いです。
###【20160215追記】
環境の問題かも、と思い、yum updateで諸々のモジュールを最新にしたり、カーネルアップデートをしたりしてみました。
カーネルバージョン cat /proc/version Linux version 2.6.32-358.23.2.el6.x86_64 (mockbuild@c6b9.bsys.dev.centos.org) (g cc version 4.4.7 20120313 (Red Hat 4.4.7-3) (GCC) ) #1 SMP Wed Oct 16 18:37:12 U TC 2013 ※20160213 kernel update Linux version 2.6.32-573.18.1.el6.x86_64 (mockbuild@c6b8.bsys.dev.centos.org) (gcc version 4.4.7 20120313 (Red Hat 4.4.7-16) (GCC) ) #1 SMP Tue Feb 9 22:46:17 UTC 2016
が、これでも改善はされませんでした。
あと残るはCentOSが6.4なのを最新にしてみるか、くらいなのですが、関係あるのかどうかは今のところわかりません…。
6.4だとPHP7で問題あるのかどうかの情報はないようです。
# cat /etc/redhat-release CentOS release 6.4 (Final)
今これをアップデートすると、下記が入るようです。
centos-release.x86_64 6-7.e16.centos12.3
ご意見いただけますと幸いです。
はい、StatementのClose漏れがSegmentation faultを引き起こしていたのではなく、Segmentation faultが起きている原因のためにAborted cliantが発生していたようです。
Segmentation faultの原因は別にあるみたいなので、引き続きエラーは発生しています。
これで発生しなくなっても原因究明にはならなそうですが、2016/2/4に7.0.3が出ていて、Segmentation faultが出る問題も治っているようなので、可能であれば、試してみてはいかがでしょうか。今回の質問の現象の原因とは関係あるかはわかりませんが。
ありがとうございます。
アップデートはタイミングを見て試してみようと思います。
.
debuginfo をインストール後、core を gdbで開けて、where とlist コマンドを実行してもらえますか？
php70-php-debuginfo-7.0.3-1.el6.remi.x86_64
コメントありがとうございます。試してみた結果を、記事に追記しますのでご確認ください。
回答2件
0
以下のzend_string_release の延長線で落ちています。
この zend_string_release は成功すべきだと思いますので、本当の原因はわかりませんが、
session id のストリングに、<>'"\ などの許されないキャラクターが入っている場合にしか、
このコードは実行されません。パケットキャプチャして、へんなsession id が入っていないか確認してみてはどうでしょうか？
C
1 /* Finally check session id for dangerous characters 2 * Security note: session id may be embedded in HTML pages.*/ 3 if (PS(id) && strpbrk(ZSTR_VAL(PS(id)), "\r\n\t <>'\"\\")) { 4 zend_string_release(PS(id)); 5 PS(id) = NULL; 6 }
投稿2016/02/12 02:26
総合スコア479
ご回答ありがとうございます。
生成されているセッションIDをざっと確認してみました。
しかし、英数字以外の文字列が含まれたものはありませんでした。
更にこのzend_string_release の中に問題の発生箇所があるのでしょうか。
引き続き調べてみますが、他に何かご助言があれば、コメントいただけますと幸いです。
0
自己解決
長らくこちらは放っておいてしまいましたが、
結局のところ原因不明であったため、環境のリフレッシュと、そもそものPHPスクリプトの見直しのため、Web環境を引っ越しました。
結果的に、Segmentation Faultについては旧環境のように無尽蔵に出続けることは無くなりました。
色々と環境自体が変わっているので、それはそれでまた別の問題が見受けられたりしてはいますが、一旦この内容については、原因についてはわからないものの、Closeといたします。
ご協力いただいた皆様、ありがとうございました。
投稿2016/03/14 02:23
総合スコア39
あなたの回答
tips
プレビュー
