質問をすることでしか得られない、回答やアドバイスがある。

15分調べてもわからないことは、質問しよう!

ただいまの
回答率

88.59%

Apacheのスレッドが定期的(約4時間毎)にserver reached MaxRequestWorkersに達してしまう原因の特定がしたい

解決済

回答 3

投稿 編集

  • 評価
  • クリップ 5
  • VIEW 4,004

haptic

score 8

Apacheのスレッドが増加する原因を特定するには何を調査すれば良いでしょうか?

Plesk環境にて某サイトを運営しています。Google Analytics上ではコンスタントに400~500の接続があり、月間PVは約400万のサイトです。
およそ定期的にApacheが落ちてしまいwatch_dogによりApacheの再起動がかかります。
server reached MaxRequestWorkers settingとなってしまうのが直接的な原因かと思いますが、
アクセスが集中していない深夜帯の午前4時頃にも起こっている原因がわかりません。
(稀にアクセスが集中して同様のエラーで落ちることがあります)

また、おおよそではありますが4時間毎に同じエラーで落ちています。
一回のタイミングで複数回落ちることもあります。
0時台、4時台、8時台、12時台・・・が大まかな流れです。以下が実際の時刻です。
(AH00484: server reached MaxRequestWorkers settingが起きた時刻です)
Sun Jul 21 20:22:08.382531 2019
Sun Jul 21 20:37:36.175939 2019
Sun Jul 21 20:53:58.803470 2019
Mon Jul 22 00:22:48.132260 2019
Mon Jul 22 00:56:57.981250 2019
Mon Jul 22 01:16:41.314307 2019
Mon Jul 22 04:41:06.600084 2019
Mon Jul 22 08:21:54.423372 2019
Mon Jul 22 08:39:16.064287 2019
Mon Jul 22 09:00:13.023712 2019

スペックを上げてmpm_event等のApache調整をすれば問題は起きなくなるかもしれませんが、
約4時間毎に何かが悪さをしていると考えていて根本的な解決をしたいと思います。

これらが発生する原因はどこを調べれば良いでしょうか。ご教示お願い致します。

発生している問題・エラーメッセージ

・
・
・
[Tue Jul 23 08:57:31.400193 2019] [mpm_event:error] [pid 1692:tid 140709346474112] AH00485: scoreboard is full, not at MaxRequestWorkers
[Tue Jul 23 08:57:32.403187 2019] [mpm_event:error] [pid 1692:tid 140709346474112] AH00485: scoreboard is full, not at MaxRequestWorkers
[Tue Jul 23 08:57:33.405190 2019] [mpm_event:error] [pid 1692:tid 140709346474112] AH00485: scoreboard is full, not at MaxRequestWorkers
[Tue Jul 23 08:57:35.409495 2019] [mpm_event:error] [pid 1692:tid 140709346474112] AH00484: server reached MaxRequestWorkers setting, consider raising the MaxRequestWorkers setting
[Tue Jul 23 09:00:27.668690 2019] [mpm_event:notice] [pid 1692:tid 140709346474112] AH00492: caught SIGWINCH, shutting down gracefully
[Tue Jul 23 09:00:33.762839 2019] [core:warn] [pid 1692:tid 140709346474112] AH00045: child process 1749 still did not exit, sending a SIGTERM
[Tue Jul 23 09:00:33.762936 2019] [core:warn] [pid 1692:tid 140709346474112] AH00045: child process 1751 still did not exit, sending a SIGTERM
[Tue Jul 23 09:00:33.762946 2019] [core:warn] [pid 1692:tid 140709346474112] AH00045: child process 1753 still did not exit, sending a SIGTERM
・
・
・

試したこと

・error_logの確認をしたが、上記の通りでした
・crontabで4時間毎のcronがあるかどうか確認したが、なかった
・mpm_eventの設定を「MaxRequestWorkers 500」「ServerLimit 20」に変えてみたが同様のエラー
・mpm_eventをmpm_preforkに変えてみたが同様のエラーが起きた

netstat -an | egrep ':80|:443' | grep ESTABLISHED | awk '{print $5}' | grep -o -E "([0-9]{1,3}[\.]){3}[0-9]{1,3}" | sort -n | uniq -c | sort -nr


上記でアクセス回数を調べても30回を超えるIPはいなかった(攻撃されているとは考えにくい?)

更に追加で試したこと(20190724時点)

・mpm_eventの設定を「MaxRequestWorkers 750」「ServerLimit 30」に変えてみたが同様のエラー
mpm_eventの設定は/etc/httpd/conf.modules.d/01-cgi.conf に記述しています。

# This configuration file loads a CGI module appropriate to the MPM
# which has been configured in 00-mpm.conf.  mod_cgid should be used
# with a threaded MPM; mod_cgi with the prefork MPM.

<IfModule mpm_worker_module>
   LoadModule cgid_module modules/mod_cgid.so
</IfModule>
<IfModule mpm_event_module>
   LoadModule cgid_module modules/mod_cgid.so
   MaxRequestWorkers 750
   ServerLimit 30
</IfModule>
<IfModule mpm_prefork_module>
   LoadModule cgi_module modules/mod_cgi.so
</IfModule>


httpd.confにはInclude conf.modules.d/*.confとあります。
mpmのモジュールはLoadModule mpm_event_module modules/mod_mpm_event.soよりmpm_eventです
念の為httpd -Vにて得られた結果に以下が記載されています

Server MPM:     event
  threaded:     yes (fixed thread count)
    forked:     yes (variable process count)


上記の設定は以下のURLを参考にしています。
https://support.plesk.com/hc/en-us/articles/214529205

設定を変更したあとはsystemctl restart httpd.serviceにてApacheの再起動をおこなっています。
・20190723の16:00頃にサーバの再起動も試してみました。がダメでした。

何れにせよ4時間毎にApacheのスレッドが増えてしまう原因を潰さなければ根本的な解決にはならないと考えています・・・

更に追加で試したこと(20190724 16:35時点)

・mpm_eventの設定を「MaxRequestWorkers 1000」「ServerLimit 40」に変えてみたが同様のエラー
落ちる直前にps aux | grep httpd にて立ち上がっていた個数は44くらいありましたが、
直前になって急激に増えました。平常時は13~17程度の間になります。
Apacheのスレッドが立ちまくってメモリ使用率が80%くらいまでなったので、
その後設定を「MaxRequestWorkers 750」「ServerLimit 30」にもどしました。

約4時間毎に急激にApacheのスレッドが増える原因は何でしょうか。。。
些細なヒントでもいいので皆様のご意見をお待ちしております。

更に追加で試したこと(20190725 11:00時点)

参考URL
・mpm_preforkに変更
/etc/logrotate.d/httpdにあるApacheの読み込み方法をreloadからrestartに変更

   KeepAlive Off
   StartServers 10
   MinSpareServers 20
   MaxSpareServers 60
   ServerLimit 200
   MaxClients 200
   MaxRequestsPerChild 1000


・mpm_preforkの設定を上記にする。
(KeepAliveをOFFにしています)

設定を一気に変えて様子を見るのは悪手だとわかっていますが、実害がでてしまっているので藁にもすがる思いです。

更に追加で試したこと(20190725 14:00時点)

・上記の11時時点で試したことを行っても約4時間毎のエラーでおちてしましました。
エラーメッセージは以下です。
スコアボードの記述はなくいきなりserver reached MaxRequestWorkers となっています。

[Thu Jul 25 13:23:02.328449 2019] [jk:warn] [pid 27849] No JkLogFile defined in httpd.conf. Using default /etc/httpd/logs/mod_jk.log
[Thu Jul 25 13:23:02.328633 2019] [jk:warn] [pid 27849] No JkShmFile defined in httpd.conf. Using default /etc/httpd/logs/jk-runtime-status
[ N 2019-07-25 13:23:02.3521 27881/T1 age/Wat/WatchdogMain.cpp:1307 ]: Starting Passenger watchdog...
[ N 2019-07-25 13:23:02.3681 27884/T1 age/Cor/CoreMain.cpp:1311 ]: Starting Passenger core...
[ N 2019-07-25 13:23:02.3682 27884/T1 age/Cor/CoreMain.cpp:256 ]: Passenger core running in multi-application mode.
[ N 2019-07-25 13:23:02.3773 27884/T1 age/Cor/CoreMain.cpp:986 ]: Passenger core online, PID 27884
[Thu Jul 25 13:23:02.387400 2019] [mpm_prefork:notice] [pid 27849] AH00163: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips Apache mod_fcgid/2.3.9 mod_jk/1.2.40 Phusion_Passenger/5.3.5 mod_perl/2.0.9-dev Perl/v5.16.3 configured -- resuming normal operations
[Thu Jul 25 13:23:02.387440 2019] [core:notice] [pid 27849] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'
[ N 2019-07-25 13:23:05.5255 27884/T5 age/Cor/SecurityUpdateChecker.h:517 ]: Security update check: no update found (next check in 24 hours)
[Thu Jul 25 13:34:37.767338 2019] [mpm_prefork:error] [pid 27849] AH00161: server reached MaxRequestWorkers setting, consider raising the MaxRequestWorkers setting
[Thu Jul 25 13:36:33.927238 2019] [mpm_prefork:notice] [pid 27849] AH00170: caught SIGWINCH, shutting down gracefully

[ N 2019-07-25 13:36:37.1196 27884/T8 age/Cor/CoreMain.cpp:641 ]: Signal received. Gracefully shutting down... (send signal 2 more time(s) to force shutdown)
[ N 2019-07-25 13:36:37.1196 27884/T1 age/Cor/CoreMain.cpp:1217 ]: Received command to shutdown gracefully. Waiting until all clients have disconnected...
[ N 2019-07-25 13:36:37.1197 27884/Ta Ser/Server.h:903 ]: [ServerThr.2] Freed 0 spare client objects
[ N 2019-07-25 13:36:37.1197 27884/Ta Ser/Server.h:559 ]: [ServerThr.2] Shutdown finished

mpm_preforkの設定を以下に変更しました。

   KeepAlive Off
   StartServers 10
   MinSpareServers 20
   MaxSpareServers 80
   ServerLimit 200
   MaxRequestWorkers 200
   MaxConnectionsPerChild 0

更に追加で試したこと(20190725 17:45時点)

4時間毎のタイミングでサイトはタイムアウトで表示されません。
しかしエラーログにはなにも残らなくなりました。
watch_dogが反応せず、Apacheの再起動がかかりません。
サイトが表示されないタイミングでのPSコマンドでのHTTPDのスレッド数は200でしたので、マックスな気がします。
ただし、メモリの使用率が95%を超えていました。
Apacheリスタートが自動がかからないのはまずいのでmpm_eventの時代にもどしました。

サーバーの環境

項目 内容
CPU Intel(R) Xeon(R) CPU E5-2640 v4 @ 2.40GHz (4 core(s))
memory 8G
Plesk Plesk Onyx v17.8.11_build1708180301.19 os_CentOS 7
OS CentOS Linux 7.6.1810 (Core)
PHP 5.6.40
httpd 2.4.6-89.el7.centos

補足情報

Apache の CPU 使用率は普段は20%前後、アクセス集中しているときでも40%に到達することは稀です。
Apache のメモリ使用率は普段は7.55 GB 中 1.50 GB程度です、負荷時も2.50 GB程度です。

  • 気になる質問をクリップする

    クリップした質問は、後からいつでもマイページで確認できます。

    またクリップした質問に回答があった際、通知やメールを受け取ることができます。

    クリップを取り消します

  • 良い質問の評価を上げる

    以下のような質問は評価を上げましょう

    • 質問内容が明確
    • 自分も答えを知りたい
    • 質問者以外のユーザにも役立つ

    評価が高い質問は、TOPページの「注目」タブのフィードに表示されやすくなります。

    質問の評価を上げたことを取り消します

  • 評価を下げられる数の上限に達しました

    評価を下げることができません

    • 1日5回まで評価を下げられます
    • 1日に1ユーザに対して2回まで評価を下げられます

    質問の評価を下げる

    teratailでは下記のような質問を「具体的に困っていることがない質問」、「サイトポリシーに違反する質問」と定義し、推奨していません。

    • プログラミングに関係のない質問
    • やってほしいことだけを記載した丸投げの質問
    • 問題・課題が含まれていない質問
    • 意図的に内容が抹消された質問
    • 過去に投稿した質問と同じ内容の質問
    • 広告と受け取られるような投稿

    評価が下がると、TOPページの「アクティブ」「注目」タブのフィードに表示されにくくなります。

    質問の評価を下げたことを取り消します

    この機能は開放されていません

    評価を下げる条件を満たしてません

    評価を下げる理由を選択してください

    詳細な説明はこちら

    上記に当てはまらず、質問内容が明確になっていない質問には「情報の追加・修正依頼」機能からコメントをしてください。

    質問の評価を下げる機能の利用条件

    この機能を利用するためには、以下の事項を行う必要があります。

質問への追記・修正、ベストアンサー選択の依頼

  • Orlofsky

    2019/07/23 18:30

    設定ファイルを編集後、Apacheを再起動していますか?

    キャンセル

  • キャンセル

  • haptic

    2019/07/24 09:56

    Orlofsky様
    Apacheの再起動は任意で設定を変えて、都度restartで行っております。
    一度サーバ自体の再起動もしてみましたが、効果はありませんでした・・・

    tetsunosuke様
    ありがとうございます。リンク先の様にmpm_eventの設定を徐々に引き上げて行けば対処はできる気がしています。4時間毎にApacheのスレッドが増えるという部分の解決ができればなお嬉しいのですが・・・

    キャンセル

回答 3

check解決した方法

+1

その後試行錯誤し、一応対処療法としての施策によりエラーが起こらなくなったので報告します。

行った設定変更は以下です。
PHP-FPMの設定でpm.max_childrenの値を5→50に変えました。

watchdogにてPHP-FPMの監視を始めたところ、エラーが出て起動できないを繰り返していたことから発覚しました。
Plesk管理下ではsystemctl status php-fpm.serviceを叩いてもPHP-FPMが起動したことになっていませんでした。systemctl status plesk-php56-fpm.service(PHPのVersionにより異なる)が起動していました。watchdogではphp-fpm.serviceを監視していました。

そのplesk-php56-fpm.serviceのログを確認するとエラーが起きていました。ちなみにエラーログの場所は以下です。
/var/log/plesk-php56-fpm/error.log
エラー内容は以下です。

WARNING: [pool hoge.jp] server reached max_children setting (5), consider raising it

4時間毎ではなく、必ずApacheがBusyになる前に起きていたわけではありませんので相互関係は不明です。
ただ、このエラーが起きるとおよそ5分程度でApacheがBusyになっていました。

根本的な原因が不明(約4時間毎のApache挙動異常)なため再発する可能性が危惧されますが、上記変更により一応現象が発生しなくなりましたためここにご報告いたします。
ご回答くださった方やご意見をくださった方ありがとうございました。なにかお気づきの点がございましたらコメントください。

投稿

  • 回答の評価を上げる

    以下のような回答は評価を上げましょう

    • 正しい回答
    • わかりやすい回答
    • ためになる回答

    評価が高い回答ほどページの上位に表示されます。

  • 回答の評価を下げる

    下記のような回答は推奨されていません。

    • 間違っている回答
    • 質問の回答になっていない投稿
    • スパムや攻撃的な表現を用いた投稿

    評価を下げる際はその理由を明確に伝え、適切な回答に修正してもらいましょう。

0

最初のメッセージ「AH00485: scoreboard is full, not at MaxRequestWorkers」が気になりました。
(こいつが引き金を引いているのではないか?)
ググると以下のページが見つかりました。
pleskのサポートのページ
「Apache bug with ID #53555.」 と書いてあり、Apache 2.4.7でfixtされたとあります。修正に関してはRed Hatがこれをback portしてくれるのを待つか、CentOS8を待つかでしょう。ただ回避策として「Switch to MPM Prefork」と「Configure logrotate to restart Apache instead of reloading」の2つが挙げられているので、これで回避できるかもしれません。 (上記のページで回避策の詳細を開いてみてください)

もうひとつ
Keepaliveトラブルのページも参考になるかもしれません。

投稿

編集

  • 回答の評価を上げる

    以下のような回答は評価を上げましょう

    • 正しい回答
    • わかりやすい回答
    • ためになる回答

    評価が高い回答ほどページの上位に表示されます。

  • 回答の評価を下げる

    下記のような回答は推奨されていません。

    • 間違っている回答
    • 質問の回答になっていない投稿
    • スパムや攻撃的な表現を用いた投稿

    評価を下げる際はその理由を明確に伝え、適切な回答に修正してもらいましょう。

  • 2019/07/24 18:33

    sage様

    ご回答ありがとうございます。
    質問内容の試したことで誤字っていて恐縮なのですが(mpm_preworkってなんだ…汗)
    mpm_preforkのモジュールに切替えは試していました。結局4時間毎に同じエラーが起きてしまいましたが・・・
    他のものについては参考にさせていただき、いろいろ試してみたいと思います。
    取り急ぎお礼まで

    キャンセル

0

下記 URL のバグに該当するのではないでしょうか。

https://support.plesk.com/hc/en-us/articles/213901685-Websites-periodically-are-not-available-scoreboard-is-full-not-at-MaxRequestWorkers
https://bz.apache.org/bugzilla/show_bug.cgi?id=53555

Bug#53555 Comment 39 で原因についての記述があります。
下記のような状況で graceful で子プロセスがすぐには終了しないため、scoreboard slot を使い切ってしまうとのこと。

  • a) graceful restart の場合 (logrotate も)
  • b) 負荷状況によってプロセスが増→減する場合 (MaxConnectionsPerChild で終了する場合も?)

Comment 55 に Patch があり、Comment 66 で Fixed in 2.4.25 で議論が終了しています。

CentOS 7 は httpd-2.4.6 のバージョンのままパッチを当てていますので、最新リリースで修正されている可能性はあります。
ダメなら、SCL リポジトリ の httpd24 パッケージ(2.4.34)を使うか、ソースからインストールするか。

投稿

  • 回答の評価を上げる

    以下のような回答は評価を上げましょう

    • 正しい回答
    • わかりやすい回答
    • ためになる回答

    評価が高い回答ほどページの上位に表示されます。

  • 回答の評価を下げる

    下記のような回答は推奨されていません。

    • 間違っている回答
    • 質問の回答になっていない投稿
    • スパムや攻撃的な表現を用いた投稿

    評価を下げる際はその理由を明確に伝え、適切な回答に修正してもらいましょう。

  • 2019/07/25 11:03

    TaichiYanagiya様

    ご回答ありがとうございます。
    先に回答いただいたsage様と同様にApacheのバグ53555が関係しているという認識ですね。
    Apacheのversionは確かに2.4.6であります。Plesk管理下ではこのversion変更は行えないので、まずはこのままリンクにもありますようにmpm_preforkへの変更、logrotateの修正を行ってみたいと思います。
    ありがとうございます。

    キャンセル

  • 2019/07/25 11:21

    MaxConnectionsPerChild 0 や MaxSpareServers を大きくするなど、b) の状況をなるべく作らないようにするといいかもしれません。

    キャンセル

  • 2019/07/25 14:31

    MaxConnectionsPerChild 0
    MaxSpareServers 80
    にて様子を見てみます

    キャンセル

15分調べてもわからないことは、teratailで質問しよう!

  • ただいまの回答率 88.59%
  • 質問をまとめることで、思考を整理して素早く解決
  • テンプレート機能で、簡単に質問をまとめられる

関連した質問

同じタグがついた質問を見る

  • トップ
  • PHPに関する質問
  • Apacheのスレッドが定期的(約4時間毎)にserver reached MaxRequestWorkersに達してしまう原因の特定がしたい