Edited at

PHPのcoredumpを読んでなぜSEGVで落ちたかを知りたい

More than 3 years have passed since last update.

PHPのcoredumpを読みたいことは一生に1度くらいあるかもしれない。ないほうがよい。

正確にはmod_phpが組み込まれているApache httpdのcoredumpである。


内容はいいからコマンドが知りたい人向け

$ gdb /usr/sbin/apache2 --core /var/tmp/core/core.15001 --command /usr/local/src/php-5.5.5/.gdbinit

(gdb) set print pretty on
(gdb) zbacktrace
(gdb) print *executor_globals->active_op_array
(gdb) print sapi_globals->request_info

以下本編。


gdbを使って何で落ちたのか知る

まずはともあれgdbである。前述のようにPHPを実行しているのはApacheなのでApacheの実行ファイルを指定して、coreファイルを開く。

$ gdb /usr/sbin/apache2 --core /var/tmp/core/core.15001

だいたい知りたいことといえば、どの関数中に落ちたとかそういうことだと思う。C言語レベルで見るのであれば、普通にbacktraceを見れば良い。

(gdb) backtrace

しかし、PHPは書けてもZendはわからないゆとりなので、PHPレベルで知りたい。そういうときは、下の変数の中身を見れば良い。定義しているヘッダファイル名を書いておいたので、どのようなデータが入っているか詳しく見たい人はそこのソースを読もう。

変数名
定義されている場所
適当な説明

sapi_globals
main/SAPI.h
SAPI関連の情報が入っている。

executor_globals
Zend/zend_globals.h
実行中の状態が入っている

compiler_globals
Zend/zend_globals.h
コンパイラのスタックとかが入ってるみたいだけどよくわからない

core_globals
main/php_globals.h
memory_limitとかinclude_pathとかcoreの情報が入っている

ps_globals
ext/session/php_session.h
セッション関連の情報が入っている

さて、どの関数を実行中に落ちたか知りたい。実行中の関数は*executor_globals->active_op_arrayを見るとわかる。set print pretty onすると見やすいよ、と教えてもらった。

(gdb) set print pretty on 

(gdb) print *executor_globals->active_op_array
$11 = {
type = 2 '\002',
function_name = 0x888888888888 "getPiyo",
scope = 0x888888888888,
fn_flags = 88888888,
prototype = 0x0,
num_args = 4,
required_num_args = 1,
(..snip..)
filename = 0x888888888888 "/home/php/lib/Hoge/Fuga.php",
line_start = 200,
line_end = 300,
doc_comment = 0x888888888888 "/**\n * Fuga::getPiyo\n * これはコメントです\n */",
doc_comment_len = 88,
(..snip..)
}

/hoge/php/lib/Hoge/Fuga.phpFuga::getPiyoを実行中だったことがわかった。

では、どのようなリクエストが来たのだろうか。ApacheとやりとりしているのはSAPIなので、sapi_globals->request_infoを見ればリクエスト情報がわかる。

(gdb) print sapi_globals->request_info

$13 = {
request_method = 0x888888888888 "GET",
query_string = 0x888888888888 "mode=hoge&id=8888&get_piyo=true",
post_data = 0x0,
raw_post_data = 0x0,
cookie_data = 0x888888888888 "__utmc=888888; __utma=888888; __utmz=aaaaaaa; __utmv=8888888"...,
content_length = 0,
post_data_length = 0,
raw_post_data_length = 0,
path_translated = 0x888888888888 "/home/php/htdocs/index.php",
request_uri = 0x888888888888 "/index.php",
content_type = 0x0,
(..snip..)
}

GET /index.php?mode=hoge&id=8888&get_piyo=trueみたいなアクセスが来ていることがわかった。これでリクエストを再現してデバッグすることができるはずだ。


.gdbinit を使ってPHPレベルでのバックトレースを見る

gdbでいっこいっこ見ていくのはとても大変なので、PHPのソースコードには便利な.gdbinitが付属している。これを--commandで指定して起動する。

$ gdb /usr/sbin/apache2 --core /var/tmp/core/core.15000 --command /usr/local/src/php-5.5.5/.gdbinit

zbacktraceというコマンドを使うと簡単にPHPレベルでのバックトレースが見られる。すごい便利。

(gdb) zbacktrace

[0x888888888888] Fuga::getPiyo(array(1)[0x888888888888]) /home/php/lib/Hoge/Fuga.php:100
[0x888888888888] Hoge::getFuga(array(1)[0x888888888888]) /home/php/lib/Hoge/Hoge.php:20
(..snip..)
[0x888888888888] main() /home/php/htdocs/index.php:100

こんな感じで関数名と呼び出し元のコードの場所がわかる。これをみると、htdocs/index.php:100でmain()が呼ばれて、なんやかんやあって、/home/php/lib/Hoge/Fuga.php:100Fuga::getPiyoが呼ばれたということがわかった。


.gdbinitに定義されている他の便利なコマンドを使う

.gdbinitには他にも便利なコマンドが定義されている。



  • printzv --- zvalの内容をみる


  • print_ht --- HashTableの中身を見る。

zvalというのはPHPの変数を格納している構造体である。printzvを使えば中のデータをすごくわかりやすく表示してくれる。

もうひとつのprint_htHashTableの中身を見る時に使う。HashTableはPHPのコードでよく使われているHashテーブルでリスト構造っぽい。print_htで見るときはだいたいHashTable->pListHeadを指定する。

使った時の様子をサンプルとして貼り付けておく。


セッションの中身を見る

(gdb) printzv ps_globals.http_session_vars

[0x7fa922cb4cd0] (refcount=2,is_ref) array(20): {
"user_id\0" => [0x888888888888] (refcount=1) string(4): "8888"
(..snip..)
}


実行中のグローバル変数一覧を見る

(gdb) print_ht executor_globals->symbol_table->pListHead

[0x888888888888] {
"_POST\0" => [0x888888888888] (refcount=2) array(0):
"_COOKIE\0" => [0x888888888888] (refcount=2) array(12):
"_FILES\0" => [0x888888888888] (refcount=2) array(0):
"_SERVER\0" => [0x888888888888] (refcount=2) array(33):
"_ENV\0" => [0x888888888888] (refcount=2) array(16):
(..snip..)
}

こんなかんじで、ポインタをいっこいっこ追っていかなくてもデバッグできてとても便利だ。


参考URL