前回の記事では、Redmine 6.1への移行後に Passenger の CPU 使用率が異常に高止まりし、production.log と netstat を追い始めたところまでを書きました。

調べていく中で、

  • 削除した Knowledgebase へのアクセス
  • sort= や set_filter= を含むチケット一覧
  • PDF や CSV、Atom のエクスポート要求

といった、一見すると関連性のないリクエストが大量に飛んできていることが分かってきます。そして最後に、

「もしかしてクローラーなのでは？」

という疑問が残りました。今回は、その続きを書いていこうと思います。

アクセス元を確認してみる

まずは production.log とアクセスログを突き合わせながら、アクセス元を確認してみました。

すると、見えてきたのは見慣れた IP アドレスです。

66.249.xx.xx

Googlebot でした。しかも一度や二度ではありません。HTTPS のセッションを何十本も張りながら、次々とリクエストを投げています。

しかもアクセスされていたのは、削除した Knowledgebase だけではありません。チケット一覧についても、

sort=
page=
set_filter=

といったパラメータ違いを延々と巡回しています。さらに、

issues.pdf
issues.csv
issues.atom

まで取得しようとしていました。普段ブラウザで Redmine を使っていると、これらは「便利な機能」という認識です。

ですが、サーバー側から見ると話は変わります。例えば PDF の生成であれば、データベースからチケットを取得し、テンプレートを組み立て、PDF をレンダリングし、レスポンスを返す。

HTML を返すだけとは比較にならないくらい重い処理になります。

つまり Googlebot は、リンクがあるから辿っているだけなのですが、Passenger からすると重い仕事ばかり持ち込まれている状態でした。

404でもPassengerは起きてしまう

Knowledgebase のアクセスについても同じです。

「存在しないページなんだから404で終わりでは？」

最初はそう考えていました。しかし実際には、Rails が起動し、ルーティングを行い、存在しないことを確認し、404 を返します。404 を返すこと自体は正しい動作です。ですが、その404を返すためにも Passenger は仕事をしています。

これでは、存在しないページへのアクセスであっても CPU を使い続けることになります。

ならばRailsまで届かせなければいい

ここで考え方を変えました。Rails が重いのではありません。Rails に仕事を渡してしまっていることが問題です。

であれば、Rails が起きる前にApacheで止めればいい。Apache を使っている以上、一番軽いのは Apache の段階で処理してしまうことです。

そこで mod_rewrite を使うことにしました。バーチャルホストの.confを以下のように変えていきます。

RewriteRule ^/projects/.*/knowledgebase - [G,L]
RewriteRule ^.*/knowledgebase - [G,L]

まずは削除済みの Knowledgebase。続いて、

RewriteCond %{HTTP_USER_AGENT} (Googlebot|GoogleOther|bingbot|Baiduspider) [NC]
RewriteRule ^/(projects/[^/]+/)?issues\.(pdf|csv|atom)$ - [G,L]

PDF、CSV、Atom のエクスポート。さらに、

RewriteCond %{QUERY_STRING} (sort=|set_filter=|per_page=) [NC]
RewriteRule ^/(projects/[^/]+/)?issues - [G,L]

検索エンジンが総当たりしている動的クエリも Apache 側で受け止めることにしました。

404ではなく410を選んだ理由

404でも目的は達成できます。ですが、今回は410 Goneを選びました。

404エラーは、「今は見つからない」という意味です。検索エンジンから見ると、

「また後で来れば復活しているかもしれない」

という扱いになります。一方、410 Gone は、

「もう永久にありません。」

という宣言です。今回削除した Knowledgebase は、将来復活させる予定はありません。だったら、その意思を HTTP ステータスとして返した方が正確です。

robots.txtも追加した

もちろん、Apache の設定だけではありません。今後の巡回そのものを減らすため、robots.txt にも、

Disallow: /projects/*/knowledgebase*
Disallow: /*?*sort=
Disallow: /*?*set_filter=

などを追加しました。ただし、ここは誤解しやすいところです。robots.txt は即効性のある仕組みではありません。

既に巡回予定へ入っているリクエストは、そのまま飛んできます。まず Apache で止める。その上で robots.txt により今後の巡回を減らす。この二段構えにしました。

効果はすぐに現れた

設定を反映し、Passenger(mod_passengerなのでapacheそのもの)を再起動します。

その後、再び CPU 使用率を確認すると、先ほどまで70〜90%を推移していた Passenger が数%程度で落ち着いていました。

production.log からも

  • Knowledgebase の404、
  • IssuesController の大量アクセス、
  • 500.html

の RoutingError は姿を消しています。試しに curl から Googlebot の User-Agent を付けてアクセスしてもApache が Rails を起動することなく、即座に

HTTP/1.1 410 Gone

を返しました。狙い通りです。Passengerに到達すること無くは何も仕事をしていません。

今回学んだこと

今回改めて感じたのは、「プラグインを削除すること」と、「削除したことを検索エンジンへ伝えること」は全く別の話だということでした。

Redmine 側では綺麗にプラグインをアンインストールできていても、Google は昔の URL を覚えています。そして真面目に巡回を続けます。そのリクエストを Rails まで届けてしまえば、存在しないページであっても Passenger は起き、CPU を使います。

だからこそ、410エラーにより「もうありません。」という判断を Apache が先に行う。

今回のケースでは、この水際防衛が一番効果的でした。

Redmine に限らず、長く運用してきた Web アプリケーションでは、大きな整理やプラグインの削除を行った後、一度アクセスログを眺めてみることをおすすめします。

自分ではとっくに忘れていた URL を、検索エンジンは驚くほど律儀に覚えているものです。そして、それが思わぬサーバー負荷につながっていることも、決して珍しくありません。

余談「Apacheは実は柔軟」

これは私の持論なのですが、超大手プラットフォームや大手配信サイトではapacheは重い。nginxこそ主流だ的な記事を見かけますが筆者のように

多数のサーバを立てられない
それでもWebアプリを多数動かしたい
セキュリティも譲れない
場合はApacheの方が驚くほど柔軟なパターンがあります。その辺の話はまた改めて。