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.phpのFuga::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:100でFuga::getPiyoが呼ばれたということがわかった。
.gdbinitに定義されている他の便利なコマンドを使う
.gdbinitには他にも便利なコマンドが定義されている。
-
printzv---zvalの内容をみる -
print_ht---HashTableの中身を見る。
zvalというのはPHPの変数を格納している構造体である。printzvを使えば中のデータをすごくわかりやすく表示してくれる。
もうひとつのprint_htはHashTableの中身を見る時に使う。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..)
}
こんなかんじで、ポインタをいっこいっこ追っていかなくてもデバッグできてとても便利だ。