php-fpmでのsegmentation fault
先日、お客様が運用しているWebサイトで、502 Bad Gatewayが頻発して原因がよくわからないので調べられないかとお問い合わせをいただきました。
とりあえず、お客様の環境を確認させていただくと、Amazon Linux上でNginxとphp-fpm(phpのバージョンは7.2)を使ったWebシステムでした。やれるだけはやってみますということで調査を開始しました。
まず、Nginxのエラーログを確認してみます。
...略... recv() failed (104: Connection reset by peer) while reading response header from upstream, ...略...
ということで、upstream。この場合はphp-fpmでエラーがおきているようです。
今度はphp-fpmのエラーログを確認してみます。
[xx-xxx-2019 xx:xx:xx] WARNING: [pool www] child 3693 exited on signal 11 (SIGSEGV) after 215.031886 seconds from start
PHPスクリプトに何か問題があるのかと思っていたら、SIGSEGV(Segmentation fault)が発生しているということで何かやっかいな問題のような気がしてきました。引き続き、調査のためcore dumpを取得してみます。
php-fpmにcore dumpを吐かせるためには、php-fpmの設定を以下のように変更します。
process.dumpable = yes rlimit_core = unlimited
PHP 7.1まではrlimit_coreの設定だけでよかったのですが、7.2からprocess.dumpableの項目が増えているようで、こちらの設定も必要でした。masterプロセスとpoolプロセスのユーザが異る環境でcore dumpを生成するには、yesにしておく必要があるようです。
設定変更後、php-fpmを再起動して再度SIGSEGVを発生させます。設定変更がうまくいっていれば、php-fpmのエラーログに"core dumped"の文字列が追加され、coreが吐かれたことを確認できます。
[xx-xxx-2019 xx:xx:xx] WARNING: [pool www] child 3353 exited on signal 11 (SIGSEGV - core dumped) after 7.249466 seconds from start
core dumpを取得できたので、backtraceを確認してみましょう。
$ gdb /usr/sbin/php-fpm ./coredump-php-fpm-7.2.3353 GNU gdb (GDB) Amazon Linux (7.6.1-64.33.amzn1) Copyright (C) 2013 Free Software Foundation, Inc. ...略... (gdb) bt #0 0x000000000059bda1 in _emalloc_56 () #1 0x00000000005c52b0 in _array_init () #2 0x00007f8f280c8e07 in ?? () from /usr/lib64/php/7.2/modules/igbinary.so #3 0x00007f8f280c97ee in ?? () from /usr/lib64/php/7.2/modules/igbinary.so #4 0x00007f8f280cfe46 in igbinary_unserialize () from /usr/lib64/php/7.2/modules/igbinary.so #5 0x00007f8f27eb5829 in ?? () from /usr/lib64/php/7.2/modules/memcached.so #6 0x00007f8f27eb847c in ?? () from /usr/lib64/php/7.2/modules/memcached.so #7 0x00007f8f27eb9a68 in ?? () from /usr/lib64/php/7.2/modules/memcached.so #8 0x00000000006681f5 in execute_ex () #9 0x00000000005b363b in zend_call_function () #10 0x00000000004f6737 in ?? () #11 0x0000000000667c1a in execute_ex () #12 0x0000000000668a93 in zend_execute () #13 0x00000000005c31f4 in zend_execute_scripts () #14 0x0000000000561f90 in php_execute_script () #15 0x000000000042d5cc in ?? () #16 0x00007f8f3b988445 in __libc_start_main () from /lib64/libc.so.6 #17 0x000000000042e6d5 in _start () (gdb)
memcachedの処理の延長でigbinary内でSegmentation faultになっているようです。フレームワークにLaravelを使っていたので、試しにCache Driverをfileに変更するとBad Gatewayは発生しなくなったので、当たりのようです。
igbinaryはmemcachedでデータをシリアライズするのに使用しているライブラリのようですが、お客様によると、システムは元々問題なく動作していたところ、突然Bad Gatewayが出るようになったとのことで、キャッシュしようとしているデータの内容によって、たまたま、igbinaryのバグにひっかかるようになってしまったのかもしれません。今回は、memcachedのシリアライザーにigbinaryを使わずに、phpを使うように設定を変更する形で回避案を提案させていただきました。
memcached.serializer = "php"
Segmentation faultが発生していることがわかった時は若干焦りましたが、システム側のPHPスクリプトを追うことにならずかえって早く解決できたかもしれません。
=============弊社ではLinuxサーバーに関する保守作業やトラブル対応に関するお問合せもお受けしております。
何かお困りのことがございましたらお問い合わせください。手助けできることがあるかもしれません。
投稿日:2019/02/06 01:15