2019年9月16日(月) 04:58 JST

Geeklogの性能測定

  • 投稿者:
  • 表示回数 3,857
Geeklog

Geeklog-1.5.0からは$_CONF変数がデータベースに格納されるようになったが、その実装方法があまりきれいではないので、速度低下を招くのではないかと思い、ひろろんさんdengenさんと共にごく簡単なキャッシュを実装していた。大ざっぱに言うと10%程度のスピードアップになりそう。

そのとき話題になったのがlib-common.phpのダイエット。このファイルはGeeklogの基本機能を実装し、必要なライブラリをインクルードしているが、1.5.1で200KBほどある。このlib-common.phpの中でも比較的使用されていないコードやインクルードファイルがあれば、使用時にインクルードすることで、サイズを減らせる。

きちんと性能測定したいなあと思ってXdebug関連を探していたら、[PHPプロファイリング: Xdebug(Xdebug2) + WinCacheGrind]というページを見つけた。早速このページの情報を元に、

  1. XdebugのMS Windows用最新モジュール(php_xdebug-2.0.3-5.2.5.dll)をダウンロードしてPHPのエクステンション用ディレクトリにコピー。
  2. WinCacheGrindをダウンロードして、インストール。
  3. php.iniの書き換え。
    [Zend]
    zend_extension_ts = "C:\PHP\ext\php_xdebug-2.0.3-5.2.5.dll"
    xdebug.profiler_enable = 1
    xdebug.profiler_output_name = cachegrind.out.profile
    xdebug.profiler_output_dir = "C:/temp/xdebug"
    xdebug.auto_trace = On
    

Geeklog-1.5.1のトップページにアクセスすると、lib-common.php処理にかかる時間は以下のようになった。

キャッシュなし キャッシュあり
実行時間(ms)比率(%)項目実行時間(ms)比率(%)
26.452.2%lib-common.php読み込み20.661.7%
11.923.6%config->initConfig()0.41.2%
3.16.2%config->loadBaseConfig()3.610.7%
1.83.6%SEC_getUserGroups()1.85.5%
1.02.0%lib-syndication.php読み込み0.82.4%
0.61.3%lib-session.php読み込み1.13.4%
0.40.8%SEC_getUserPermissions()0.41.2%
0.40.8%lib-plugins.php読み込み0.61.9%
0.10.2%japanese_utf-8.php読み込み0.10.3%
0.20.4%setlocale()0.41.2%
50.6 合計33.4 

テスト環境は、Pentium M 1.1GHz、メモリ1.25GB、Windows XP+SP3、PHP-5.2.5、Apache-2.0.63、MySQL-4.0.18ntで、5回アクセスの平均値。

キャッシュなしの方では、lib-common.phpの処理に合計で50.6ミリ秒かかり、そのうちlib-common.phpの読み込み自体に26.4ミリ秒かかっている。キャッシュありの方では、lib-common.phpの処理に合計で33.4ミリ秒かかり、そのうちlib-common.phpの読み込み自体に20.6ミリ秒かかっている。

キャッシュありの方は、config->initConfig()の実行時間が大幅に短くなっている。config->loadBaseConfig()の時間は依然として長いが、これは内部でlib-database.phpをインクルードし、データベースに接続しているためで、短縮は難しそう。SEC_getUserGroups()に時間がかかるのはソースコードに注釈がある通り(lib-security.phpの88-90行目)だが、何らかのキャッシュ機能を実装できる可能性がある。となるとやはり、全体の50%から60%の時間を占めているlib-common.php自体の読み込みがボトルネックになる。もう少し、詳しく調べてみるつもり。