こんにちは、42tokyo Advent Calendar 2023の13日目を担当する42tokyoの在校生です。

私の運用するサービスはApache + php-fpmの構成をとっています。
ある日、Apacheのerrorログを見たら、以下のログが大量に記録されていました。

[/var/log/httpd/error_log]

[Mon Dec 11 04:06:49.210756 2023] [proxy_fcgi:error] [pid 1520632:tid 140122485937920] 
[client XXX.XXX.XXX.XXX:34791] AH01071: Got error 'Primary script unknown'

※ログは見やすさのために改行を入れています。

エラーの意味をChatGPTに聞いてみます。

エラーメッセージ: "Primary script unknown" というメッセージは、通常、FastCGIプロセスがリクエストされたスクリプトを見つけられなかったことを示しています。これは、スクリプトのパスが間違っているか、スクリプト自体が存在しないか、またはサーバーの設定に問題があることを意味する可能性があります。

error_logだけではクライアントがどのスクリプトにアクセスしようとしたのか分かりません。そこでaccessログと突き合わせます。

# cat /var/log/httpd/access_log | grep "04:06:49" | grep "XXX.XXX.XXX.XXX"
XXX.XXX.XXX.XXX - - [11/Dec/2023:04:06:49 +0900] 
"GET /~ap2/ero/toukei_kaiseki/mod_shokushu.php?game=4284 HTTP/1.1" 404 196 "-" 
"Mozilla/5.0 (Linux; Android 6.0.1; Nexus 5X Build/MMB29P) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.6099.62 Mobile Safari/537.36 (compatible; GoogleOther)" 478 426 620

※ログは見やすさのために改行を入れています。

クライアントがmod_shokushu.phpにアクセスしようとして404を返しているので、見つけられなかったスクリプトはmod_shokushu.phpと思われます。

Apacheがmod_shokushu.phpがないと判断して404を返しているのだから、php-fpmがリクエストされたスクリプトを見つけられなかったというログが残るのはおかしいと思っていろいろ調べてました。
調べた結果、自分が間違っていることがわかりました。

Apacheはmod_shokushu.phpの存在確認をせず、phpという拡張子を見てphp-fpmに処理を渡します。php-fpmはmod_shokushu.phpがないので、AH01071: Got error 'Primary script unknown'をログに出力し、Apacheに応答(おそらく404)を返します。Apacheはphp-fpmからの応答を受けてクライアントに404を返します（php-fpmがどんな応答を返すのかを見つけることはできませんでした）。

[自分の思っていた動作]
クライアント → Apache → クライアント

[実際の動作]
クライアント → Apache → php-fpm → Apache → クライアント

存在しないスクリプトにアクセスがあった場合に、AH01071: Got error 'Primary script unknown'が記録されるのはそういうものだとは分かったのですが、記録しない方法はないだろうかと思いました。
また、そもそも存在しないスクリプトにアクセスがあった場合、Apacheで応答を返した方が速いのではないかと思いました、

そこで、そんな方法があるかChatGPTに聞いてみました。

クライアントが存在しないスクリプト（mod_shokushu.php）にアクセスしてきた場合に、AH01071 エラーを出力しないようにするか、あるいはCGIを起動しないようにするためのいくつかの方法があります。これらの方法はサーバーの設定とアプリケーションのロジックに依存します。以下にいくつかのアプローチを示します：

ApacheのRewriteルールを使用
Apacheのmod_rewriteモジュールを使用して、存在しないスクリプトへのリクエストを検出し、これを適切なエラーページや別のURLにリダイレクトするルールを作成します。例えば、.htaccess ファイルに以下のようなルールを追加することができます：

RewriteEngine On
RewriteCond %{REQUEST_URI} ^/~ap2/ero/toukei_kaiseki/mod_shokushu.php
RewriteRule ^.*$ - [R=404,L]

mod_shokushu.phpにリクエストがあった場合、404を返すようにRewriteすればいいようでした。

RewriteRuleとRewriteCondは、よく検討して書かないと想定しなかった動作をして痛い目を見てきた(ぐぐって見つけたRewriteルールを何も考えずコピペするとたいてい思わぬ動作をしてきた)ので、よく調べて、以下のように書きました。

<Directory "/home/*/public_html">
(中略)
    RewriteEngine On
    # 存在しないPHPファイルにアクセスした場合は404エラーを返す
    RewriteCond %{REQUEST_FILENAME} \.php
    RewriteCond %{REQUEST_FILENAME} !-f
    RewriteRule ^ - [R=404]
</Directory>

上記設定を反映することでApacheのerrorログにAH01071: Got error 'Primary script unknown'が記録されなくなりました。
php-fpmに処理を渡すことがなくなったので、少し速くなったと思います。
負荷のかかっていない待機系サーバーでabで調べてみました。

RewriteRule適用前

$ ab -c 1 -n 1000 http://127.0.0.1/~ap2/ero/toukei_kaiseki/mod_shokushu.php
(中略)
Time taken for tests:   0.478 seconds
(以下略)

RewriteRule適用後

$ ab -c 1 -n 1000 http://127.0.0.1/~ap2/ero/toukei_kaiseki/mod_shokushu.php
(中略)
Time taken for tests:   0.317 seconds
(以下略)

ほんの少しだけ速くなりました。本当にほんの少しだけ…

そもそもなぜ存在しないスクリプトに大量のアクセスがあるのかについて。
大量にアクセスしてくるのはGoogleBotです。
mod_shokushu.phpはだいぶ前に使わなくなったスクリプトで、現在のWebサイトからのリンクはないのですが、GoogleBotはそのスクリプトが生きていると思っているみたいです。
mod_shokushu.phpは?key=1000のようにパラメータを渡して使うスクリプトでしたので、パラメータをかえてGoogleBotが大量にアクセスしてくるみたいです。
サーバーの負荷的には問題ないのですがログが大量に残されるのが悲しいです。