ElastiCache MemcachedのCPU使用率が急上昇し、DatabaseConnectionエラーが発生した時に対応したこと

2019年5月14日システムAWS

ElastiCache MemcachedのCPU使用率が急上昇し、DatabaseConnectionエラーが発生した時に対応したこと
ElastiCache MemcachedのCPU使用率が急上昇し、DatabaseConnectionエラーが発生した時に対応したこと

とある企業のシステム監視をしていたところ

  • ElastiCache MemcachedのCPU使用率が急上昇
  • Database Connectionの急上昇
  • PHP-fpmがseems busyのWARNINGが発生
  • Database Connectionに失敗

などにより、急激に負荷高まりシステムが激重になる事象が発生しました。その時に調べたことや対応したことを残します。

追記：2019年9月30日

ボトルネックは「CakePHPが保存するキャッシュデータが肥大化していたのが原因」でした！
詳しい原因と解決方法については、最後に追記しています。

環境/構成

まずは、環境構成についてです。
AWSで環境を構築されており、詳細な構成は以下の様になります。

  • Webサーバ(Web Servers)
    • AWSのEC2を利用
  • Webシステム(Web System)
    • Nginxを利用
    • php-fpm5系でCakePHP2系を利用
  • データベース(Database)
    • AWSのRDSでAuroraを利用
  • キャッシュ(Cache)
    • AWSのElastiCacheでMemcachedを利用
    • Nodeは3つ

事象について

RDSのDatabaseConnectionが急上昇

AWSのCloudWatchでグラフを確認すると、
DatabaseConnectionが急上昇
していた。

それで事象に気づいていろいろと調査すると色々とエラーが起こっていた。

ElastiCacheのMemcachedのCPUが急上昇

ElastiCacheのMemcachedのグラフを確認すると
CPU使用率が急上昇
していた。

CakePHP2のエラーログでCache書き込みエラーやDatabaseConnectionエラー

CakePHP2のエラーログを確認すると
Cacheへの書き込みに失敗
していた。

****-**-** **:**:**.*** Warning: (PID=****) (UUID=*********) (()) Warning (***): _cake_core_ cache was unable to write '******' to Memcached cache in […./lib/Cake/Cache/Cache.php, line 328]

他にも
DatabaseConnectionに失敗
が起こっていた。

****-**-** **:**:**.*** Error: (PID=****) (UUID=*********) ) (…./lib/Cake/Error/ErrorHandler.php(118)) [MissingConnectionException] Database connection "Mysql" is missing, or could not be created.

PHP-fpmのエラーログでWARNING

PHP-fpmのエラーログを確認すると
忙しい(seems busy)状態
になり
Process数が足りていない
WARNING発生。

[**-***-**** **:**:**] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning * children, there are * idle, and * total children

事象の原因調査

まず時系列でどのサーバでどの時間に何が発生しているのかを整理しました。

そうすると、
ElastiCacheのCPUが急上昇
↓
RDSのDatabaseConnectionが急上昇
↓
PHP-fpmがseems busyのWARNING発生
という具合になっているようでした。

対応内容

CakePHP2のエラーログにあるDatabaseConnectionエラー

AWSのEC2のインスタンスを複製して、インスタンスを新しく構築しました。

そうすると、
CakePHP2のエラーログに出力される

****-**-** **:**:**.*** Error: (PID=****) (UUID=*********) ) (…./lib/Cake/Error/ErrorHandler.php(118)) [MissingConnectionException] Database connection "Mysql" is missing, or could not be created.

は、解消されました。

ただ、
長い間再起動していない状態だったのがダメだったのか、再起動していないのでカーネルのアップデート(kernel update)されていなかったことが原因だったのかもです。

なので、
こちらの事象に悩まされている方は、サーバ再起動することをおススメします。

ElastiCacheのMemcachedのCPU使用率が急上昇

これには２つ対応を行いました。

ElastiCache Cluster Client for PHP

AWSのElastiCacheでnodeのエンドポイントを指定して接続を行っていたので、クラスター(Cluster)のエンドポイントを指定するよう変更しました。

それに伴い
AWSで用意されている「ElastiCache Cluster Client」を使うようにしました。

使用する理由としては、
ElastiCache Cluster Clientを使用することで、クラスターのエンドポイントを指定すると自動でぶら下がっているnodeを検出して接続するようです。

ElastiCache Cluster Clientをインストール

# ElastiCache Cluster ClientをPECLを使ってインストール
$ sudo pecl install /home/ec2-user/AmazonElastiCacheClusterClient-1.0.0-PHP56-64bit.tgz
install ok: channel://__uri/AmazonElastiCacheClusterClient-1.0.0
configuration option "php_ini" is not set to php.ini location
You should add "extension=amazon-elasticache-cluster-client.so" to php.ini
# PHPの拡張モジュール(Extention)の配置場所を確認
$ php -i | grep extension
extension_dir => /usr/lib64/php/5.6/modules => /usr/lib64/php/5.6/modules
# ちゃんとインストールされたか確認
$ ls -la /usr/lib64/php/5.6/modules | grep amazon
-rw-r–r– 1 root root 1213746 May 8 17:44 amazon-elasticache-cluster-client.so
# インストールしたElastiCache Cluster Clientの拡張モジュールを読み込むようにする
# 既存のmemcached.soは、コメントアウトしておく
$ sudo vi /etc/php.d/50-memcached.ini
; extension=memcached.so
extension=amazon-elasticache-cluster-client.so
# php-fpmを再起動
$ sudo /etc/rc.d/init.d/php-fpm restart

CakePHP2のエラーログにあるCache書き込みエラー

ElastiCacheのMemcachedのバージョンを最新版へアップデートしました。

そして
パラメータグループのmaxconns_fastを1に設定。

maxconns_fast
最大接続制限に達したときに新しい接続リクエストを処理する方法を変更します。
このパラメータを 0（ゼロ）に設定した場合、新しい接続がバックログキューに追加され、他の接続が終了するまで待機します。
パラメータを 1 に設定した場合、ElastiCache はクライアントにエラーを送信し、すぐに接続を終了します。

https://docs.aws.amazon.com/ja_jp/AmazonElastiCache/latest/mem-ug/ParameterGroups.Memcached.html

そうすると、

****-**-** **:**:**.*** Warning: (PID=****) (UUID=*********) (()) Warning (***): _cake_core_ cache was unable to write '******' to Memcached cache in […./lib/Cake/Cache/Cache.php, line 328]

は、解消されました。

PHP-fpmの忙しい(seems busy)状態でProcess数が足りない

上記の対応を行ったことで、
PHP-fpmの忙しい(seems busy)状態は解消され、Process数が足りないエラーログの

[**-***-**** **:**:**] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning * children, there are * idle, and * total children

は、出力されなくなりました。

PHP-fpmの設定見直し

ちなみに
PHP-fpmのpm(Process)関係の設定についていくつか調べていたので、補足程度に乗せておきます。

/etc/php-fpm.d/www.confのプロセス設定

  • pm
    • プロセスマネージャが子プロセスの数を制御する方法
      • static
      • 子プロセスの数は固定される
      • ondemand
      • プロセスを必要に応じて立ち上げる
      • dynamic
      • 関連する設定値の内容によって、立ち上がる子プロセスの数が動的に決まる
  • pm.max_children
    • 同時に処理をする可能性がある子プロセス数
  • pm.start_servers
    • プロセス開始時に生成される子プロセス
    • デフォルト値: min_spare_servers + (max_spare_servers – min_spare_servers) / 2
  • pm.min_spare_servers
    • 待ち状態の子プロセスの最小の数
    • もし待ち状態のプロセスの数がここに設定されている数値より少ない場合、何個かの子プロセスが作成される
  • pm.max_spare_servers
    • 待ち状態の子プロセスの最大の数
    • もし待ち状態のプロセスの数がここに設定されている数値より多い場合、何個かの子プロセスが消される。
    • pm.start_servers + pm.min_spare_servers
  • pm.process_idle_timeout
    • アイドルプロセスが殺されるまでの秒数
    • pmがオンデマンドに設定されている場合にのみ使用されます
  • pm.max_requests
    • 各子プロセスが、再起動するまでに実行するリクエスト数
    • プロセスのメモリが肥大化するときの回避策として使える
    • プロセス再生成に関わるCPU利用率があがります

/etc/php-fpm.d/www.confの設定で参考にしたサイト

おわりに

サーバが障害でトラブって調査するのって疲れますよね(汗)
実は、解消するまでに1週間近く掛かってしまいました。。。

結局分からなかったことが、
ElastiCache Cluster Clientを利用した後でも、ElastiCacheのnodeが3つあるうちの1つのnodeでCPU使用率が急上昇する事象は解消されなかった。

ただ、
ElastiCacheのMemcachedのバージョンを上げることで解消はされたっぽい。
これは最後までなぞのままでした。。。

この記事の内容でおかしな点があればご指摘をお願いしますm(_ _)m

余談

過去のシステム系の記事ですが、
WordPressのテーマを変更したことによってスタイルとかが変わってめちゃ見にくくなっちゃってる。。。

書き換えなくては。。。orz

追記：2019年9月30日

上記の対応を行った後に、同様の事象が発生しました。そこで改めて原因と対策を行うことになりました。

原因

発生の原因は、PHPのフレームワークであるCakePHPのキャッシュに問題があることが分かりました。

もう少し詳しく言うと、アクセスが多い時に"**_ cake_core_method_cache “というキーで保存しているデータが肥大化しキャッシュが悲鳴をあげていました。実際にtelnetでMemcachedへ接続し確認してみると確かに膨大なデータが登録されていました。

対応

対応としては、/App/Config/core.phpに記述している以下のコードをまるっとコメントアウトにすることにしました。

Cache::config('_cake_core_', array(
    'engine' => $engine,
    'prefix' => $prefix . 'cake_core_',
    'path' => CACHE . 'persistent' . DS,
    'serialize' => ($engine === 'File'),
    'duration' => $duration
));

ただコメントアウトにすることでパフォーマンスが低下すると思います。なので、他にもっと良い解決方法があると思います。

私たちはかなり大きなCakePHP（現在2.4.7）SAASアプリを持っています。それはかなり成熟していて、先週までCakePHPs-coreによって提供された機能性に関して本当の問題を決して経験しませんでした。
先週末、私たちは非常に憂慮すべき状況に遭遇しました。そこでは、私たちのアプリは本当に遅くて不完全でした。私たちは、あらゆる種類のサーバー監視を調べたところ、過去数時間でI / O統計が急増したことがわかりました。さらに調査した後、問題をCakeの ‘cake_core_method_cache’ファイルに特定しました。平均して、このファイルのサイズは200 kbです。先週末、それは最大40 MBまで上がりました。
私たちのdeploy-routineの一部はapp / tmp / cacheとapp / tmp / persistentフォルダからすべてのキャッシュファイルを削除することです。頻繁に（1日に数回）配置されるため、キャッシュは頻繁に消去されます。残念なことに、先週の休日は私たちの配備を一時停止していました、そしてこれはコア/キャッシング機能のための問題であるように見えました。

https://codeday.me/jp/qa/20190608/963097.html

＼プログラミングスクール受講メリット／

・メンターにすぐ聞けるので分からないところでつまづかない
・受講生同士で学び合いモチベーション維持しやすい
・就学後に就職支援や進路サポートを受けることが出来る

＼現役エンジニアによるサポート就職支援／
[ TechAcademy ]
の特徴・料金を確認
ユート
ユート

Webプログラマ兼ブロガー | プログラミング基礎知識を発信｜Webプログラマ歴は10年以上｜JavaScript,PHP.HTML | 「人生の時間は有限。悪いことをしている時間はない」
→プロフィール

2019年5月14日システムAWS

Posted by ユート