本番のElastic Beanstalk環境にてRailsアプリをデプロイしたところ、Pumaの再起動に時間がかかりダウンタイムが発生しました。
なぜこの事象が発生したのかがわからず、調査を行ったので記録として残しておきます。
解決していないのでhelp wantedです。
前提
環境
- ElasticBeanstalk環境 (Ruby 2.7 running on 64bit Amazon Linux 2/3.4.7)
- EC2インスタンス数:1台 (t3.medium)
- Puma 5.6.4
その他
デプロイ時にWeb、DBサーバーのCPU使用率、メモリ使用率に問題がないことから、インフラ側ではなくアプリ側の問題と推測しています。
発生した事象
デプロイ終了間際のアプリ再起動時に、Pumaが立ち上がるまでに時間がかかり(6分40秒)、その間にダウンタイム502 Bad Gatewayが発生しました。
/var/log/puma/puma.logより
Pumaを落としたログ(17:56:22)
Pumaが再度立ち上がったログ(18:03:02)
デプロイログ(/var/log/eb-engine.log)を見ても、該当時間にてデプロイ処理が進んでいないことが確認できる。
2022/09/09 17:56:22.324227 [INFO] Running command /bin/sh -c systemctl daemon-reload
2022/09/09 17:56:22.458577 [INFO] Running command /bin/sh -c systemctl reset-failed
2022/09/09 17:56:22.462352 [INFO] Removing /var/app/current/ if it exists
2022/09/09 18:03:00.882353 [INFO] Renaming /var/app/staging/ to /var/app/current/ # ここで6分38秒くらい処理が止まっている！！！
2022/09/09 18:03:00.882379 [INFO] Register application processes...
2022/09/09 18:03:00.882383 [INFO] Registering the proc: web
調査内容
1. 手動でPumaを再起動してみる
再現しないかEB環境にSSHして直接Pumaを何度か再起動してみる。
$ sudo su
$ export $(sudo cat /opt/elasticbeanstalk/deployment/env) # 環境変数の読み込み
$ ps aux | grep puma # pumaのpid調査
$ pumactl -p 14271 restart # 上記で取得したpidを元にpumaの再起動
事象再現せず。
2. ログローテーションの処理とPumaの再起動をぶつけてみる
現象再現時にElastic Beanstalkによりpuma.logのログローテーション処理が走っていたので、
手動でログローテションを行なって、その処理とPumaの再起動を同時に行なってみました。
$ /usr/sbin/logrotate -f /etc/logrotate.elasticbeanstalk.hourly/logrotate.elasticbeanstalk.puma.conf #ログローテションの実行
$ pumactl -p 14271 restart
事象再現せず。
3. Elastic Beanstalkのログローテーションの処理とPumaの再起動をぶつけてみる
1時間に1度、Elastic Beanstalkによりシステム全体のログローテーション処理が走っているので、
そのタイミング周りで、手動でPumaの再起動を何度か行なってみました。
$ pumactl -p 14271 restart
事象再現せず。
対応策
サービスグロースも伴ってインスタンスを増やそうとしていたので、
現在1台で動いているEC2インスタンス数を2台に増やし、ローリングでデプロイさせる方式で進めようと思います。
原因を特定できずに力技の対応になってしまいますが。。。
今後原因特定ができれば追記しようと思います。
ん〜悔しい。
追記
Puma Workerが全て落とされてから、再度起動するのはEBデプロイ時のデフォルト動作っぽい。
監視コマンドは下記
$ watch -n 1 'ps -ef | grep puma'
※動画(右側がデプロイによりリスタートが走った時のPumaプロセス監視、6秒あたりでworker数が0になってる)
https://gyazo.com/49908a78db5e7ab7fac5804fc4f2378c
これはデフォルトのリスタート、下記コマンドと同等の動き。
$ pumactl -p <pid> restart
下記のコマンドと同等の動き(片方のPumaWorkerのリスタートが完了した後に、もう1台のPumaWorkerをリスタートさせる)
をEBデプロイ時に実現できればなぁ、。
$ pumactl -p <pid> phased-restart