前提・実現したいこと

運用中のWebアプリケーションで以前まで問題ありませんでしたが、
2021年4月6日11時頃からApacheのリクエストが返ってくるまでに30秒かかってしまいます。
この事象はすべてのリクエストで発生するわけではありません。
一旦事象は解消していますが、根本的な部分がわかりません。
再発することを懸念し現在も調査しています。

わかっていること

検証用に２サーバーと本番サーバーを稼働させています。
同事象が発生するのは本番サーバーと検証サーバー１台です。
3台ともサーバースペックを除き、構成やミドルウェアはほぼ同じです。
1画面でのリクエストは80件ほどです。

サーバー内の時間がかかっている部分を調査したところ
ApacheからLaravelのミドルウェアに到達するまでに30秒近くかかっていることがわかりました。
サーバーサイドのプログラム内の問題ではないことがわかっています。

追記

下記について調査内容、結果を追記しました。

Apacheのリクエストが返ってくるまでに30秒かかってしまいます。
サーバーサイドのプログラム内の問題ではないことがわかっています。

はじめにCloudWatchのログを確認し、WebサーバーからRDSへの到達に30秒かかっていることがわかりました。
この結果からALB、WAFには問題がないとわかりました。
次にDBのクエリのレスポンスを調査しましたが、
RDSのスロークエリには時間がかかっているログは確認できませんでした。
Webサーバーか、プログラムかの切り分けのため、Laravelのミドルウェアにログを入れて確認したところ、
Laravelのミドルウェアまでの到達の時間に30秒かかっていることがわかりました。

Webサーバーか、プログラムかの切り分けのため、Laravelのミドルウェアにログを入れて確認したところ、
Laravelのミドルウェアまでの到達の時間に30秒かかっていることがわかりました。

こちらの情報を補足すると
CloudWatchのログには、Apacheのアクセスログが記録されています。
Laravelのミドルウェアには下記のように処理前後にログを仕込みました。

        $path = $request->path();
        $ip = $request->ip();
        $start = Carbon::now();
        $requestId = uniqid("UNIQ_");

        \Log::info('start::uniq::'.$requestId.'::'.$ip.'::'.$path.'::'.$start);

        
        $request = $next($request);


        $end  = Carbon::now();
        $diff = $start->diffInSeconds($end);
        \Log::info('end::uniq::'.$requestId.'::'.$ip.'::'.$path.'::'.$end.'-diff::'.$diff);

するとApacheのアクセスログのインからLaravelの処理前に到達する時点で30秒かかっていることがわかり、
処理前から処理後の差分を出していますが、

\Log::info('end::uniq::'.$requestId.'::'.$ip.'::'.$path.'::'.$end.'-diff::'.$diff);

この差分には1秒もかからずに処理が返ってきていることから
DBやプログラムが重いことはないと判断しています。

わからないこと

MaxClientsとServerLimitの上限値を1000近くに変更したところ解消しましたが、

普段はアクセスの無い検証用サーバーでなぜ発生するか
Apacheのリクエストが返ってくるまでに決まって30秒かかるのはなぜか
別の検証環境で事象が発生しないのはなぜか

についてがわからず、モヤモヤしています。
何か意見をいただけると幸いです。

試したこと

Apacheにあたりをつけて検証しましたが解決しませんでした。

Keep-Alive offにしてみる
MinSpareServers MaxSpareServersを変更してみる

補足情報（FW/ツールのバージョンなど）

ECS (Fargate)

コンテナのメモリ 4GB
CPU 2GHz

RDS(AuroraServerless)
Laravel 6.18.31
PHP 7.4.16
Apache 2.4.38

Apacheの今の設定

MaxConnectionsPerChild 0（デフォルト）
KeepAlive On（デフォルト）
MaxKeepAliveRequests 100（デフォルト）
Timeout 300 （デフォルト）
KeepAliveTimeout 5（デフォルト）
MaxClients 256（prefork版のデフォルト）
ServerLimit 256（prefork版のデフォルト）
StartServers 5（prefork版のデフォルト）
MaxSpareServers 10（デフォルト）
MinSpareServers 5（デフォルト）

2021/04/09追記

皆様ご意見くださりありがとうございます。
現在の進捗ですが、依然究明には至っていない次第でございます。
引き続きご意見いただけますと幸いでございます。

また、ここに来てAuroraServerlessの線も再浮上しました。
理由としては最初にログを仕込んだミドルウェアの前に処理されるミドルウェアにて
データベースへの接続をしている箇所がありました。
Amazonへ直接問い合わせてみるなど原因調査の方法を検討中です。

tanat

2021/04/08 06:39

> サーバー内の時間がかかっている部分を調査したところ > ApacheからLaravelのミドルウェアに到達するまでに30秒近くかかっていることがわかりました。 > サーバーサイドのプログラム内の問題ではないことがわかっています。このあたりについて、どのように調査し、どういった結果が得られたのかを記載されると適切な回答を得られやすいかと思いますよ。

yambejp

2021/04/08 06:42

tcpdumpなどでパケットの調査をしてみては？

yu_1985

2021/04/08 06:52

すでに書かれてますが、 > サーバー内の時間がかかっている部分を調査したところ > ApacheからLaravelのミドルウェアに到達するまでに30秒近くかかっていることがわかりました。 > サーバーサイドのプログラム内の問題ではないことがわかっています。ここについてもっと具体的に、客観的にそれが間違いないと判断できる情報を書いてください。往々にしてあるのが問題の切り分けが間違っているケースです。

neverever823

2021/04/08 07:11

> tanetさま yu_1985さまご指摘ありがとうございます。調査内容と結果を追記いたしました。

neverever823

2021/04/08 07:15 編集

> yambejpさまありがとうございます。 FargateのコンテナにSSHで接続が難しいですが、検討して確認してみます。

yu_1985

2021/04/08 07:22

> Webサーバーか、プログラムかの切り分けのため、Laravelのミドルウェアにログを入れて確認したところ、 Laravelのミドルウェアまでの到達の時間に30秒かかっていることがわかりました。ここがよくわかりません。何を見てどう判断しましたか？書かれている情報を見るとAuroraServerlessがアイドル状態になってるときに遅くなっているのではと思うんですが…。

neverever823

2021/04/08 10:02 編集

> yu_1985さまありがとうございます。「追記」に補足を記述しました。また、しばらくアクセスがないという状態ではないので AuroraServerlessのアイドル状態は考えにくいと思います。

yu_1985

2021/04/08 10:59

> MaxClientsとServerLimitの上限値を1000近くに変更したところ解消しましたうーん、何かがApacheのWorkerを食い尽くしていませんか？ mod_statusとかで事象が発生したときにWorkerの状況を確認してみてください。 https://blog.apar.jp/zabbix/9559/ preforkにしてるならpreforkをやめるか、nginxを使うとかすれば解消したりしそうな気もします。

neverever823

2021/04/08 13:58

> yu_1985さまありがとうございます。やはりサーバー内覗けるようにしたほうがよさそうですね。 nginxにすることも検討したいと思います。ご意見くださりありがとうございます。

yu_1985

2021/04/08 14:44

コマンドを打って確認する他、監視サービスを使うとApacheのWorker数を取ったりしてくれるので検討してもいいとは思います。

tanat

2021/04/08 14:52

https://www.ambionics.io/blog/laravel-debug-rce https://qiita.com/reopa_sharkun/items/f3819b2e8727728da82a の脆弱性を突かれてマルウェアが動いているとか。問題発生時のプロセス/スレッドの状況を確認できないことには原因特定は難しいかと思います。

neverever823

2021/04/09 10:20

> tanatさま CPUやメモリの負荷に変化ないため、攻撃はないかなと考えています。仰るようにプロセス/スレッドの状況を確認を急務にすすめております。