こんにちは!
昨日確認したときはサイトは正常でしたが、今朝起きたら502 Bad Gatewayエラーでダウンしていました。モニタログはこちらです monitor.txt (9.4 MB)
わあ…Java がこんなに多いなんて!私の Jitsi サーバーもかつては同じように混乱していました。
また、ホストをメールサーバーとして使用しているようですが、私は最終的にそれをアプリから分離しました。そうすれば、将来的に復元しやすくなり、標準的な本番環境のインストールにできるだけ近い状態で整理整頓を保つことができます。フローティング IP を備えた非常に小さなメールインスタンスの方が、評判の監視がしやすく、コストもわずかに抑えられるかもしれません。
OK、見てみましょう…まず「average」でgrepします:
06:24:13 up 3 days, 8:13, 0 users, load average: 0.01, 0.05, 0.08
06:34:33 up 3 days, 8:23, 0 users, load average: 12.89, 11.68, 6.35
つまり、06:34 の少し前に、実行可能なプロセスの数という点で何かが大爆発しました。
もう少し範囲を広げてgrepすると、メモリ使用量は実際にはほとんど変わっていないことがわかります:
06:24:13 up 3 days, 8:13, 0 users, load average: 0.01, 0.05, 0.08
total used free shared buff/cache available
Mem: 8167548 3513172 3241404 371940 1412972 4512016
Swap: 10485756 0 10485756
--
06:34:33 up 3 days, 8:23, 0 users, load average: 12.89, 11.68, 6.35
total used free shared buff/cache available
Mem: 8167548 3110612 1351844 373268 3705092 4812672
Swap: 10485756 0 10485756
むしろ、メモリ使用量は減少しています。何かのプロセスが終了したのかもしれません:
06:13:53 up 3 days, 8:02, 0 users, load average: 0.04, 0.16, 0.15
total used free shared buff/cache available
Mem: 8167548 3505540 3259744 371932 1402264 4519680
06:24:13 up 3 days, 8:13, 0 users, load average: 0.01, 0.05, 0.08
total used free shared buff/cache available
Mem: 8167548 3513172 3241404 371940 1412972 4512016
06:34:33 up 3 days, 8:23, 0 users, load average: 12.89, 11.68, 6.35
total used free shared buff/cache available
Mem: 8167548 3110612 1351844 373268 3705092 4812672
06:44:53 up 3 days, 8:33, 0 users, load average: 13.64, 13.25, 9.89
total used free shared buff/cache available
Mem: 8167548 3093212 3618984 373276 1455352 4840140
06:55:13 up 3 days, 8:44, 0 users, load average: 11.62, 12.70, 11.42
total used free shared buff/cache available
Mem: 8167548 3140580 3366628 373352 1660340 4792440
どうやらユニコーン(Unicorn)が再起動したようです:
Thu Aug 5 06:24:13 CEST 2021
06:24:13 up 3 days, 8:13, 0 users, load average: 0.01, 0.05, 0.08
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 30389 0.0 0.0 2160 1148 ? Ss Aug03 0:00 \\_ runsv unicorn
x 13329 0.0 0.0 15132 3712 ? S Aug04 0:26 \\_ /bin/bash config/unicorn_launcher -E production -c config/unicorn.conf.rb
x 13365 0.0 3.0 542036 251584 ? Sl Aug04 0:23 \\_ unicorn master -E production -c config/unicorn.conf.rb
x 13846 0.6 4.5 9129356 371852 ? SNl Aug04 4:19 | \\_ sidekiq 6.2.1 discourse [0 of 5 busy]
x 13858 0.0 3.9 8971616 323264 ? Sl Aug04 0:18 | \\_ unicorn worker[0] -E production -c config/unicorn.conf.rb
x 13870 0.0 4.0 8975712 330660 ? Sl Aug04 0:20 | \\_ unicorn worker[1] -E production -c config/unicorn.conf.rb
x 13889 0.0 4.1 8979808 337180 ? Sl Aug04 0:20 | \\_ unicorn worker[2] -E production -c config/unicorn.conf.rb
x 29760 0.0 0.0 13708 2220 ? S 06:24 0:00 \\_ sleep 1
Thu Aug 5 06:34:33 CEST 2021
06:34:33 up 3 days, 8:23, 0 users, load average: 12.89, 11.68, 6.35
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 30389 0.0 0.0 2160 1148 ? Ss Aug03 0:00 \\_ runsv unicorn
x 4638 0.4 0.0 15132 3784 ? S 06:32 0:00 \\_ /bin/bash config/unicorn_launcher -E production -c config/unicorn.conf.rb
x 4642 11.1 2.8 439636 233240 ? Sl 06:32 0:11 \\_ unicorn master -E production -c config/unicorn.conf.rb
x 4822 13.1 3.7 8877408 309844 ? Sl 06:33 0:10 | \\_ unicorn worker[1] -E production -c config/unicorn.conf.rb
x 5025 15.6 3.7 8873312 310264 ? Sl 06:33 0:10 | \\_ unicorn worker[0] -E production -c config/unicorn.conf.rb
x 5065 20.6 3.9 8922504 320740 ? SNl 06:33 0:11 | \\_ sidekiq 6.2.1 discourse [0 of 5 busy]
x 5639 0.0 0.0 13708 2264 ? S 06:34 0:00 \\_ sleep 1
また、Apache が起動に苦労しているようにも見えます:
Thu Aug 5 06:24:13 CEST 2021
06:24:13 up 3 days, 8:13, 0 users, load average: 0.01, 0.05, 0.08
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 13730 0.0 0.1 225016 15840 ? Ss Aug02 0:17 /usr/sbin/apache2 -k start
www-data 10232 0.0 0.1 1352372 10972 ? Sl Aug03 0:00 \\_ /usr/sbin/apache2 -k start
www-data 27998 0.0 0.1 228880 9608 ? S Aug04 0:01 \\_ /usr/sbin/apache2 -k start
www-data 28000 0.0 0.3 3036536 27796 ? Sl Aug04 0:53 \\_ /usr/sbin/apache2 -k start
www-data 28002 0.0 0.3 2904772 26524 ? Sl Aug04 0:50 \\_ /usr/sbin/apache2 -k start
www-data 28185 0.0 0.1 762472 10952 ? Sl Aug04 0:00 \\_ /usr/sbin/apache2 -k start
Thu Aug 5 06:34:33 CEST 2021
06:34:33 up 3 days, 8:23, 0 users, load average: 12.89, 11.68, 6.35
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 13730 0.0 0.1 225024 15856 ? Ss Aug02 0:17 /usr/sbin/apache2 -k start
www-data 10232 0.0 0.1 1352372 10972 ? Sl Aug03 0:00 \\_ /usr/sbin/apache2 -k start
www-data 28185 0.0 0.1 762472 10952 ? Sl Aug04 0:00 \\_ /usr/sbin/apache2 -k start
www-data 30794 0.0 0.1 228888 9620 ? S 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 31490 0.0 0.1 344564 10852 ? Sl 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 32095 0.0 0.1 500228 10888 ? Sl 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 32215 83.2 0.1 369152 10876 ? Sl 06:25 7:26 \\_ /usr/sbin/apache2 -k start
www-data 32284 0.0 0.1 229400 9936 ? S 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 32382 187 0.1 410136 10916 ? Sl 06:25 16:31 \\_ /usr/sbin/apache2 -k start
www-data 32410 0.0 0.1 229400 9936 ? S 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 32545 0.0 0.1 229400 9936 ? S 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 2106 0.0 0.1 3032348 11396 ? Sl 06:27 0:00 \\_ /usr/sbin/apache2 -k start
www-data 2240 0.0 0.1 2901012 11416 ? Sl 06:27 0:00 \\_ /usr/sbin/apache2 -k start
www-data 2241 0.0 0.1 2901184 14220 ? Sl 06:27 0:00 \\_ /usr/sbin/apache2 -k start
Thu Aug 5 06:44:53 CEST 2021
06:44:53 up 3 days, 8:33, 0 users, load average: 13.64, 13.25, 9.89
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 13730 0.0 0.1 225024 15856 ? Ss Aug02 0:17 /usr/sbin/apache2 -k start
www-data 10232 0.0 0.1 1352372 10972 ? Sl Aug03 0:00 \\_ /usr/sbin/apache2 -k start
www-data 28185 0.0 0.1 762472 10952 ? Sl Aug04 0:00 \\_ /usr/sbin/apache2 -k start
www-data 30794 0.0 0.1 228888 9620 ? S 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 31490 0.0 0.1 344564 10852 ? Sl 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 32095 0.0 0.1 500228 10888 ? Sl 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 32215 82.1 0.1 369152 10876 ? Sl 06:25 15:50 \\_ /usr/sbin/apache2 -k start
www-data 32284 0.0 0.1 229400 9936 ? S 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 32382 188 0.1 410136 10916 ? Sl 06:25 36:10 \\_ /usr/sbin/apache2 -k start
www-data 32410 0.0 0.1 229400 9936 ? S 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 32545 0.0 0.1 229400 9936 ? S 06:25 0:00 \\_ /usr/sbin/apache2 -k start
www-data 2106 0.0 0.1 3032348 11396 ? Sl 06:27 0:00 \\_ /usr/sbin/apache2 -k start
www-data 2240 0.0 0.1 2901012 11416 ? Sl 06:27 0:00 \\_ /usr/sbin/apache2 -k start
www-data 2241 0.0 0.1 2901184 14432 ? Sl 06:27 0:00 \\_ /usr/sbin/apache2 -k start
多数のフォークされた Apache プロセスがあり、そのうちの一つが 83% の CPU を消費し、もう一つが 188% の CPU を消費している点に注目してください。何かおかしいことが起きています。
しかし、この発見に対して何をすべきか確信が持てません。
最近、カーネルが何かを殺す理由があったか確認してみる価値もあるかもしれません:
dmesg -T | egrep -i kille
そのコマンドを実行しても何も出力されません。
おそらく、友人が MPM prefork から MPM Event に切り替えたことが原因だと思います。それ以来 Apache の使用量が大幅に増えましたが、Discourse 以降はサイトがクラッシュしたり不具合が起きたりすることはありません。私は MPM prefork に戻しました。これで改善するかもしれません。
Java はどうやら Varnish キャッシュだったようです。プロセスのツリーを開いてみると、ベースが Varnish でした。Java よりもこちらの方がずっと納得がいきます ![]()
MPM Event は Apache をマルチスレッドで動作させ、より多くの訪問者を処理できるようにします。これには、現在一般的に PHP-FPM として知られる独立した PHP サービスとの組み合わせが必要です。サーバーが混雑している場合、Prefork は Apache と PHP のパフォーマンスを制限してしまいます。Event が過剰なリソースを消費している場合、その原因は Event に対して不適切に設定された FPM である可能性が最も高いですが、最適化されていない MPM Event 自体が問題となることもあります。
Prefork は、同時アクセスの少ないサーバーでは問題なく動作しますが、Apache の現在の標準は Event/FPM です。
それは良いことだと思います…
ありがとうございます、お手伝いできて嬉しいです ![]()
MPM preforkに戻したところ、Apacheは3日間クラッシュしていません。これで問題が完全に解決することを願っています。皆様のご支援、ありがとうございました ![]()
This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.