WordPressチューニング: ボトルネックの調査

1カ月ぶりにブログを更新したら、ページ表示の遅さが気になってしまったので、今まで何もしてこなかったWordPressのパフォーマンス・チューニングを行うことにした。

WordPressチューニングの情報はWebにいろいろあるけれど、ほとんどが「この設定をこうしたらこんなに速くなった！」みたいな話ばかりで、パフォーマンス・エンジニアの端くれとしては「なんでそこがボトルネックだと判断したの？」という視点がないが気になった。そこで、この記事では原因分析から評価まできちんと記しておこうと思う。ただ、Webアプリケーション・パフォーマンス・チューニングのプロではないので、その辺はお手柔らかに……。

以下ではHTTPサーバーに Apache HTTP Server 2.2.3 + CentOS 5.7、データーベース・サーバーに MySQL Community Edition 5.1.52 + Scientific Linux 6.1 を使っているが、その他の環境でも応用できるだろう。

まず、どこで時間がかかっているのかの切り分けを行おう。Google Chrome 15 のメニュー「ツール > デベロッパー ツール」を開き、Networkタブを表示したら、Shiftキーを押しながら再読み込みボタンを押してWebブラウザーのキャッシュを使わずに再読み込みする。何度か試してみると4秒弱という結果が最頻値のようなので、以下の結果で分析することにした。

タイムラインを見ると、一番上のindex.php (/blog/) に1.83秒と最も時間がかかっている。特にindex.phpのwaitingが終わらないとそのほかのファイル読み込みも全く始まらないので、これが1.83秒もあるというのは何とかすべきだ。index.phpのwaitingに時間がかかっている理由は大きく分けると「ネットワークのレスポンスが悪い」「HTTPサーバーのレスポンスが悪い」「動的ページ生成が遅い」の3つが考えられるだろう。

とりあえず動的ページ生成が遅いのかどうかの切り分けのために、同じページの静的ページを作成する。Google Chrome のメニュー「名前を付けてページを保存…」でHTMLのみをtest.htmlとして保存し、動的に生成されるindex.phpの静的ページ版を作成する。このtest.htmlをindex.phpと同じ階層に置いて、今度はtest.htmlにWebブラウザーからアクセスしてみる。

index.phpに比べてtest.htmlの読込みが圧倒的に速い。つまり、動的生成に時間がかかっているということになる。動的生成が遅い理由は「PHPが遅い」「MySQLが遅い」の2つが考えられるので、そのどちらであるかを切り分けることにした。index.phpのチューニングにターゲットを絞ったので、Google Chrome のデベロッパーツールではなく、ab (Apache HTTP server benchmark tool) をここからは使うことにする。abはhttpd.rpmに含まれており、同じネットワーク内の別サーバーから実行した。

今のところ同時実行性は気にしないので-c (concurrentcy) は小さめで、1分程度負荷がかかるように-n (requests) を調整してindex.phpに対して実行した。以下がその結果であるが、Requests per second が0.56#/secということで、1秒間に1ページも応答できていないという結果となった。

[root@oscar ~]# ab -c 2 -n 40 http://rewse.jp/blog/
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking rewse.jp (be patient).....done


Server Software:        Apache
Server Hostname:        rewse.jp
Server Port:            80

Document Path:          /blog/
Document Length:        63908 bytes

Concurrency Level:      2
Time taken for tests:   71.022 seconds
Complete requests:      40
Failed requests:        0
Write errors:           0
Total transferred:      2564720 bytes
HTML transferred:       2556320 bytes
Requests per second:    0.56 [#/sec] (mean)
Time per request:       3551.077 [ms] (mean)
Time per request:       1775.538 [ms] (mean, across all concurrent requests)
Transfer rate:          35.27 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        1    1   0.4      1       3
Processing:  2343 3523 794.2   3274    5342
Waiting:     1651 2518 644.6   2348    4603
Total:       2345 3524 794.1   3276    5343

Percentage of the requests served within a certain time (ms)
  50%   3276
  66%   3575
  75%   4090
  80%   4285
  90%   4888
  95%   5069
  98%   5343
  99%   5343
 100%   5343 (longest request)

このときのHTTPサーバー上で実行したdstatとiostatの結果をグラフ化したものが以下だ。CPUが100%使用されている。

[root@xray ~]# dstat --cpu --output cpu.csv 2
[root@xray ~]# iostat -x /dev/xvda 2 > io.dat

同様にデーターベース・サーバー上で実行したdstatとiostatの結果をグラフ化したものが以下だ。このデータベースはWordPress専用ではないにもかかわらず、CPU / ディスクともほとんど負荷はかかっていない。

データベースのワークロードはほぼSELECTなので、ロック待ちなどでDBサーバーのリソースが使えていない可能性は低いし、仮にそうであればHTTPサーバー側も待たされてリソースを使えないはずだろう。これによりボトルネックはMySQLではなく、PHPであると考えられる。ここから「PHPエンジン」「WordPressコード」のどちらが遅いのかを切り分けることもできるが、たとえばWordPressのコードをチューニングするとその後のメンテナンスが面倒なので、この2つは総合的に考えることにした。

合わせてtest.html（静的ページ）にも同様にabを実行しておく。そのままでは計測時間が短すぎたので-nを増やしている。test.htmlの Requests per second が204.13#/secなので、動的ページ生成を最大限までチューニングすればこの値になるということで、逆に言うと動的ページ生成のチューニングだけではこれより良い値にはならないということだ。よって、今回のチューニング目標はこれより1桁小さい20#/sec（現行の35.71倍）とした。

[root@oscar ~]# ab -c 2 -n 4000 http://rewse.jp/blog/test.html
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking rewse.jp (be patient)
Completed 400 requests
Completed 800 requests
Completed 1200 requests
Completed 1600 requests
Completed 2000 requests
Completed 2400 requests
Completed 2800 requests
Completed 3200 requests
Completed 3600 requests
Completed 4000 requests
Finished 4000 requests


Server Software:        Apache
Server Hostname:        rewse.jp
Server Port:            80

Document Path:          /blog/test.html
Document Length:        67699 bytes

Concurrency Level:      2
Time taken for tests:   19.595 seconds
Complete requests:      4000
Failed requests:        0
Write errors:           0
Total transferred:      272001800 bytes
HTML transferred:       270841510 bytes
Requests per second:    204.13 [#/sec] (mean)
Time per request:       9.798 [ms] (mean)
Time per request:       4.899 [ms] (mean, across all concurrent requests)
Transfer rate:          13555.52 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        1    1   0.9      1      28
Processing:     5    8   3.8      8      77
Waiting:        0    3   2.3      3      59
Total:          6   10   4.0      9      79

Percentage of the requests served within a certain time (ms)
  50%      9
  66%      9
  75%     10
  80%     10
  90%     11
  95%     12
  98%     17
  99%     26
 100%     79 (longest request)

このような「ボトルネックの特定」と「ゴールの設定」はパフォーマンス・チューニングにとって非常に重要で、これがチューニングの半分である。次回は実際のチューニングの一環として、APC (Alternative PHP Cache)を導入する。