core dump と gdb コマンドがあればバイナリ再ビルドしなくてもデバッグできます（PHPコマンドでSegmentation faultになった原因調査）

発生した問題

ある Laravel Artisan のコマンドを実行しようとしたら、即座に他に出力もなく Segmentation fault が出て終了しました。
1回目は実行できるのだけど、2回目は実行できない（結論からいうとキャッシュ周りの問題なので、キャッシュがあると死んでました）。

$ php artisan command:hogehoge
Segmentation fault

バージョン情報

$ php -v
PHP 7.2.22 (cli) (built: Sep 11 2019 01:44:09) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.2.0, Copyright (c) 1998-2018 Zend Technologies
    with Zend OPcache v7.2.22, Copyright (c) 1999-2018, by Zend Technologies

$ gdb -v
GNU gdb (GDB) Amazon Linux (7.6.1-64.33.amzn1)

$ uname -r
4.14.146-93.123.amzn1.x86_64

問題解決に使えるツール

• gdb
  • 昔からデバッグに使われている有名なツールです
  • https://www.gnu.org/software/gdb/
• core dump
  • プロセスが死んだ時のメモリの状態を吐き出しておくためのファイルは core dump file と呼ばれます
  • https://man7.org/linux/man-pages/man5/core.5.html

どうやって問題を追っていくか？

1. core dump ファイルを吐き出させる
2. Segmentation fault を吐いたコマンドのパスを確認する
3. gdb に両方セットで食わせます gdb <実行コマンドのパス> -c <core dump file>
   • 一般的にはPHPコマンド自体を再ビルドしてgdbコマンド経由で実行することでデバッグする方法をよく見ますが、手間がかかりハードルが高いです
   • バイナリを再ビルドしなくてもcore dumpさえあれば簡易的なデバッグができるというところで表題の通りです
4. gdb コンソールで where コマンドを実行するとスタックトレースが表示されます
5. スタックトレースをとっかかりにググるなり調査します

詳細

1. core dump ファイルを吐き出させる

Segmentation fault が起こった時には core dump を吐き出すことができます

現状の設定を確認。0 になっているので吐き出されません。

$ ulimit -a | grep core
core file size          (blocks, -c) 0 

設定を変更します。これを入れると性能劣化すると思うので、出来るだけ本番環境は避けた方が無難です。私の環境では開発環境で問題を再現していたので開発環境にいれました。
※以下のコマンドで反映するのは、sshで接続している1セッションだけです。このセッションでコマンド実行する場合には永続化は不要ですが、他のバックグラウンドプロセスに実行させたり、ApacheによるPHP実行のcore dumpを吐き出させる時には他の記事を参照してください。

$ ulimit -c unlimited
$ ulimit -a | grep core
core file size          (blocks, -c) unlimited

以下のように改めて問題が起こるコマンドを実行すると(core dumped)が追加されているのが確認できます。

$ php artisan command:hogehoge
Segmentation fault (core dumped)

core dump file の出力先は以下のファイルに書かれています。参考: https://www.suse.com/ja-jp/support/jp/kb/tids/00100037/
下記の出力は、コマンド実行したカレントディレクトリを示しています。

$ cat /proc/sys/kernel/core_pattern
core

以下のようなファイル出力がされているはずです。

$ ls core.6888
core.6888

2. Segmentation fault を吐いたコマンドのパスを確認する

$ which php
/usr/bin/php

3. gdb に両方セットで食わせます

gdb <実行コマンドのパス> -c <core dump file>

最終的に_emalloc ()で落ちているのはわかりましたが、情報がまだ足りません。

[root@ip-172-31-6-236 html]# gdb /usr/bin/php -c core.6888
GNU gdb (GDB) Amazon Linux (7.6.1-64.33.amzn1)
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-amazon-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/bin/php-7.2...(no debugging symbols found)...done.
warning: core file may not match specified executable file.
[New LWP 6888]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `php artisan command:hogehoge'.
Program terminated with signal 11, Segmentation fault.
#0  0x00000000005a0c11 in _emalloc ()
Missing separate debuginfos, use: debuginfo-install php72-cli-7.2.13-1.7.amzn1.x86_64
(gdb)

4. gdb コンソールで where コマンドを実行するとスタックトレースが表示されます

上記の状態でgdbの対話状態になっていると思うので、以下のように whereコマンドを発行します。
今回のケースだと、memcachedのクライアントに問題があり、igbinary という module を使って unserialize する時に問題が発生することがわかりました。

(gdb) where
#0  0x00000000005a0c11 in _emalloc ()
#1  0x00007fdbe5286735 in ?? () from /usr/lib64/php/7.2/modules/igbinary.so
#2  0x00007fdbe528ce46 in igbinary_unserialize () from /usr/lib64/php/7.2/modules/igbinary.so
#3  0x00007fdbe260f829 in ?? () from /usr/lib64/php/7.2/modules/memcached.so
#4  0x00007fdbe261247c in ?? () from /usr/lib64/php/7.2/modules/memcached.so
#5  0x00007fdbe2613a68 in ?? () from /usr/lib64/php/7.2/modules/memcached.so
#6  0x000000000066bd55 in execute_ex ()
#7  0x00000000005b719b in zend_call_function ()
#8  0x00000000004fd263 in ?? ()
#9  0x000000000066b77a in execute_ex ()
#10 0x000000000066c5f3 in zend_execute ()
#11 0x00000000005c6d54 in zend_execute_scripts ()
#12 0x0000000000565af0 in php_execute_script ()
#13 0x000000000066e9b6 in ?? ()
#14 0x000000000042d18e in ?? ()
#15 0x00007fdbf9e14445 in __libc_start_main () from /lib64/libc.so.6
#16 0x000000000042d213 in _start ()

5. スタックトレースをとっかかりにググるなり調査します

今回のケースだと この記事 を参考対応を取りました。igbinary シリアライザを使う必然性がなかったので設定の変更を行って解決しました。この対応についての詳細については本記事のスコープから外れるので詳しくは記述しません。

before

$ php -i | grep memcached.serializer
memcached.serializer => igbinary => igbinary

after

$ php -i | grep memcached.serializer
memcached.serializer => php => php

参考

2010年の記事ですが色褪せないです。ありがとうございました。