見えないものを見ようとしたら、自分が見えた
うちのアクセスログは PHP のモジュールが MongoDB に書いています。ただしこの方式には穴があって、 .htaccess で遮断した 403 や、存在しないパスへの 404 が一切残りません。 PHP に到達する前に終わっているからです。
そこで Apache のログを時間帯ごとに集計し、「PHPまで届いた分」と「Apacheで止まった分」を並べて見る 氷山ビューを作りました。水面上が今まで見えていた部分、水面下が見えていなかった部分、という発想です。
ところが動かしてみると、水面下から出てきたのは攻撃ではありませんでした。
5xx が、全体の15%
ステータスの全内訳を出した最初の画面が、これでした。
| ステータス | 件数 | 割合 |
|---|---|---|
| 2xx 正常応答 | 7,566 | 31.1% |
| 3xx リダイレクト | 10,985 | 45.2% |
| 403 遮断 | 1,026 | 4.2% |
| 404 探索 | 424 | 1.7% |
| その他 4xx | 853 | 3.5% |
| 5xx サーバエラー | 3,442 | 14.2% |
7件に1件がサーバエラー。403遮断(1,026)と404探索(424)を足した数の、2倍以上です。 攻撃を可視化するために作ったツールが、真っ先に映し出したのは自分の不具合でした。
コードは 500 のみ
5xx をステータスコード別に割ってみました。ここで一気に容疑者が絞れます。
| コード | 件数 | 疑うべきもの |
|---|---|---|
| 500 | 全部 | アプリ層、または Apache の設定 |
| 502 / 504 | 0 | PHP-FPM の枯渇・タイムアウト |
| 503 | 0 | リソース枯渇・MaxRequestWorkers 到達 |
2GB しかない VPS なので、まず pm.max_children の設定ミスによる PHP-FPM の枯渇を疑っていました。
ですが 502も504も503もゼロ。プロセス不足でもタイムアウトでもリソース枯渇でもない。
5xx をひと括りで見ていたら、ここで詰まっていました。500 と 502 では原因も対処もまったく別物です。集計を作るときは、最初から細かく割れる形で持っておくと、こういう場面で助かります。
PHP のエラーは、1行も出ていなかった
500 なのだから、アプリが例外を投げているはずだ——そう思って error.log を見ました。
sudo tail -200 /var/log/apache2/error.log | grep -iE "PHP (Fatal|Parse|Warning)" # → 0行
ゼロ。 PHP は何も悪さをしていません。仮説が外れました。 では何が 500 を出しているのか——同じログを、条件を広げて見直します。
AH00124。 Apache が内部リダイレクトを10回繰り返し、上限に達して 500 を返していました。 アプリではなく Apache の設定の問題です。 そして、以前に扱った AH01071 も再発していました。
「?」ひとつが、無限ループを作っていた
対象サイトの .htaccess にあったのが、WordPress マルチサイト用の定番ルールです。
RewriteRule ^([_0-9a-zA-Z-]+/)?(wp-(content|admin|includes).*) $2 [L] RewriteRule ^([_0-9a-zA-Z-]+/)?(.*\.php)$ $2 [L] ← 犯人
意図は「sub/foo.php のようなサブディレクトリ付きのパスから、先頭のディレクトリを剥がす」こと。
ですが先頭部分 ([_0-9a-zA-Z-]+/) には ?（省略可）が付いています。
すると wxfyf.php のようなディレクトリの無い .php にもマッチしてしまう。
剥がすディレクトリが無いので、書き換え結果 $2 は 入力とまったく同じ。
wxfyf.php → マッチ → wxfyf.php
wxfyf.php → マッチ → wxfyf.php
wxfyf.php → マッチ → wxfyf.php
…（10回）…
→ AH00124 → 500
[L] があるのに、なぜ止まらないのか
ここが引っかかりやすい点です。[L] は「このラウンドの評価を終える」という意味でしかありません。
書き換えが発生すると、Apache はその結果を新しいリクエストとして最初から評価し直します（内部リダイレクト）。
同じルールにまたマッチし、また同じ結果になり、また評価し直す。[L] はループを止めません。
ループを、1ステップずつ追う
パスとルールを選ぶと、内部リダイレクトが1回ずつ進んでいきます。
? と + を切り替えて、どこで止まり、どこで止まらないかを見てください。
wxfyf.php を ? で流すと、1回目からいきなり出力＝入力になり、そのまま10回で 500。
+ にするとそもそもマッチせず、次のルールへ抜けて 404 に落ち着きます。
.js まで500になっていた理由。
デモで「wp- ルール」を選ぶと分かりますが、上の行も同じ構造で自己ループします。
wp-content/… は先頭ディレクトリを剥がそうとしても $2 が自分自身になるためです。
これが、.php ですらない wpp.js が 5xx のリストに並んでいた理由でした。
直すべきは1行ではなく、2行だったわけです。
? を + にする
書き換え前後が同じになる可能性を消します。先頭のディレクトリを必須にするだけです。
RewriteRule ^([_0-9a-zA-Z-]+/)+(wp-(content|admin|includes).*) $2 [L] RewriteRule ^([_0-9a-zA-Z-]+/)+(.*\.php)$ $2 [L] # ↑ ? を + に変えただけ
.htaccess なので再起動は不要。保存した瞬間から効きます。確認はこれだけ。
curl -sI https://example.jp/nonexistent-test-12345.php | head -1 # 500 が返らなくなればループ解消 sudo grep AH00124 /var/log/apache2/error.log | tail -3 # 最終行の時刻が修正前で止まっていれば完全に解決
もうひとつ残っていた:ソフト404
500 は消えましたが、存在しないパスが今度は 301 → 200 を返していました。
末尾スラッシュが付けられ、catch-all の RewriteRule . /index.php [L] が受けて、
WordPress が 200 を返している状態です。これはソフト404と呼ばれ、こちらも実害があります。
| 影響 | 内容 |
|---|---|
| 計測 | 存在しないパスへの探索が 200 として記録され、404 に計上されない |
| SEO | 検索エンジンが実在しないURLを有効ページと認識する |
| 防御 | スキャナに「そのパスは在る」と誤認させ、探索を誘発しうる |
catch-all より前に、実在しない .php をその場で終わらせる一行を置きます。
# catch-all より前に置く RewriteCond %{REQUEST_FILENAME} !-f RewriteRule \.php$ - [R=404,L]
計測が正確になると、数字は「悪化」する
修正後、404 のリストにこれまで見たことのないパスが並ぶようになりました。
ランダムな名前の .php を大量に試す、典型的なバックドア探索です。
以前は 500 や 200 に化けていて、404 として数えられていなかったものです。
ここが今回いちばん腑に落ちた点でした。404 が増えるのは、悪化ではなく計測が正確になった印です。 攻撃の量は変わっていない。変わったのは、こちらが正しく数えられるようになったこと。 壊れた計測は、実態より綺麗な数字を出してしまいます。
この記事のまとめ
- 5xx はコード別に割る。500だけならアプリか設定、502/504ならFPM、503ならリソース。
- 500 なのに
PHP Fatalが0行なら、疑うのはApacheの設定。 AH00124は内部リダイレクトのループ。LimitInternalRecursion を上げても解決しない。^([_0-9a-zA-Z-]+/)?(.*\.php)$ → $2は、ディレクトリが無いと書き換え前後が同一になり自己ループする。?を+へ。[L]はラウンドを終えるだけ。書き換えが起きれば最初から再評価される。- ソフト404（存在しないのに200）は、計測・SEO・防御の三方に効く。catch-all の前で止める。
- 404が増えたら、計測が直った合図。数字の悪化を、改善と読み替える。
攻撃を見るために作った道具が、最初に見せてくれたのは自分の設定ミスでした。 しかもその不具合は、攻撃者のスキャンが引き金で顕在化していた。 可視化とは、相手を見ることであると同時に、自分を見ることでもある——そう実感した一件でした。
