サーバの負荷が高すぎるのでなんとかしてみる(調査編)の続きです。
Apacheのログを見ることで、とあるURLに対するアクセス数が想定以上に多いことがわかりました。しかし、アクセス数が多くても、処理時間が短ければそれほどの負荷にはならないはずです。そこでサーバー全体として、どの種類のリクエストを処理するために、どれぐらいの処理時間がかかっているかを確認します。そのためには絞込みが必要です。手順としては以下の通り。
- どのリクエストの処理負荷が高いのかを調べる
- そのリクエストの、どの部分の処理負荷が高いのかを調べる
どのリクエストの処理負荷が高いのかを調べる
Twitterで@yudoufuさんに、Apacheのログフォーマットで%Dオプションが存在することを教えてもらいました。これはそのリクエストを処理するためにかかった時間を記録するものだそうです。そういえばこんなのあったなーとか思い出しつつ、早速下記のように設定してみます。%Dを先頭に持ってきたのはソートが楽だからです(笑)
LogFormat "%D %v:%p %h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" combined_vhost CustomLog /var/log/apache2/vhost.log combined_vhost
注意点しなければいけないというか、はまった部分は、combined_vhostの部分。Web上ではこの部分をcombinedとかにしているサンプルが多く見つかりますが、combinedの部分はApacheの設定ファイルの中でユニークでなければならないので、Ubuntuの場合、combinedにすると最初からある他のIDとぶつかります。
このように設定したうえでしばらくしてからログファイルを覗いてみると、やはり想定以上にアクセス数の多い部分で処理時間がかかっていることがわかりました。よって、この部分の処理時間を短くすることでサーバの負荷をある程度下げることが出来るはずです。
そのリクエストの、どの部分の処理負荷が高いのかを調べる
このリクエストを処理するにあたって、コードのどの部分がボトルネックになっているかを調べます。処理時間を調べるためにベンチマーク用のテーブルを新たに作成し、リクエストがあるたびに処理時間を保存することにしました。
PHPで処理時間を計測する方法としては、microtime関数を利用します。 [php] $time_start = microtime(true); // 計測したい処理を書く $time_end = microtime(true); $time = $time_end - $time_start; [/php] 今回は、計測した結果をデータベースに新しく作成したベンチマーク用のテーブルに格納していきます。これによって、コードのどこがボトルネックになっているかを絞り込んでいきます。 これがC++とかだったら、Intel VTune等のプロファイラを利用することで効率的にボトルネックを探すことが出来るのですが、PHPでは若干面倒な作業をせざるを得ません。もしかしたら探せば便利なプロファイラがあるのかも知れませんが・・・。
以上のように絞込みを行ったところ、データベースに対してSELECT文を発行している部分の処理時間がリクエストを処理する時間の大半を占めていることがわかりました。おかしいなと思ってデータベースのほうを確認してみると、インデックスを設定していないことが判明しました。早速、インデックスを適切に設定してやると、処理時間が一気に短縮されました。ただし、インデックスを張ったことによって、挿入にかかる時間は延びているはずなので、このあたりも含めて評価する必要があります。
まとめ
今回、サーバの負荷が異様に高かったので改善を行いました。負荷軽減を行うためには、どの部分の負荷が高いかを調べる必要があります。高い負荷の部分をを特定するためには、負荷のリクエストを調べてから、負荷の高い処理を特定するのが効率が良いです。
クライアントアプリケーションだとあまり無いかも知れませんが、Webアプリケーションの場合は運用を行うに連れて扱うデータが増えてくることがあります。こういった場合、運用当初には見えなかった問題が運用をはじめてから見えてくる場合があります。最初からデータが増えたらどうなるかを想定して、スケーラブルに設計する必要があります。