計測の話。
PHP7.1にて、 xhprofを使おうと思ったらどうも使えないので、 tideways_xhprofを使った。
インストール
phpenv を使っている環境にインストールをした。ドキュメントそのままで、ソースコードを落としてきて、下記のコマンドを実行。
git clone https://github.com/tideways/php-profiler-extension.git
cd php-profiler-extension
phpize
./configure
make
make test
make install
echo 'extension=tideways_xhprof.so' >> ~/.phpenv/versions/7.1.13/etc/conf.d/tideways.ini;
echo 'tideways.auto_prepend_library=0' >> ~/.phpenv/versions/7.1.13/etc/conf.d/tideways.ini
使い方
xhprof とほぼ使い方は同じで、実行関数名が少し違う程度だった。
使い方の確認を兼ねて、10万文字のテキストにそれぞれの文字の頭に1文字余計に追加するプログラムを作る。
処理方法は よくやる間違い ありがちなmb_substr でやる方法と、preg_split で分解してから処理する方法の２つを比べてみる。
mbstr.php
mb_substr で一文字ずつ取り出してみていく。
<?php
$a = makeRandom();
$length = mb_strlen($a);
$result = '';
for($i=0; $i < $length; $i++){
$b = mb_substr($a, $i, 1);
$result .= '-'.$b;
}
mbarray.php
preg_split で文字単位で分割し配列化してから、 foreach でループで回して処理をする。
<?php
$a = makeRandom();
$buff = preg_split('//u', $a);
$result = '';
foreach($buff as $b){
$result .= '-'.$b;
}
run.php
上記２つのうち、指定した方を実行して、プロファイル結果を保存する。
<?php
tideways_xhprof_enable();
function makeRandom (){
$length = 100000;
$start = ord('あ');
$end = ord('ん');
$result = '';
for($i = 0; $i < $length;$i++){
$result .= chr(random_int($start,$end));
}
return $result;
}
require $argv[1];
file_put_contents(
'./' .$argv[1].'.xhprof',
json_encode(tideways_xhprof_disable())
);
実行結果
$ /usr/bin/time php run.php mbstr.php
2.12user 0.04system 0:02.17elapsed 99%CPU (0avgtext+0avgdata 11860maxresident)k
0inputs+8outputs (0major+14834minor)pagefaults 0swaps
$ /usr/bin/time php run.php mbarray.php
0.16user 0.03system 0:00.19elapsed 97%CPU (0avgtext+0avgdata 12200maxresident)k
0inputs+8outputs (0major+14913minor)pagefaults 0swaps
解析
実行後、mbarray.php.xhprof および mbstr.php.xhprof ができてるので、プロファイル結果を表で表示してみる。
これをするには tideways/toolkit が必要なので、インストールをする。
$ go get github.com/tideways/toolkit
$ ls -l ~/go/bin
drwxr-xr-x 3 yasui staff 96B 10 23 20:06 ./
drwxr-xr-x 4 yasui staff 128B 10 23 20:06 ../
-rwxr-xr-x 1 yasui staff 4.6M 10 23 20:06 toolkit*
toolkit がインストールできたなら、実行パスを通して、実行をしてみる。
$ PATH='~/go/bin':$PATH
ついでに一覧表以外にも、graphvizをインストールしているなら、グラフ化もしてみる。graphvizは HomeBrew で予めインストールしています。
mbstr のプロファイル結果
$ toolkit analyze-xhprof -m 0 mbstr.php.xhprof git:master ? :S6
Showing XHProf data by Exclusive Wall-Time
+-------------------------+--------+------------+------------------------------+
| FUNCTION | COUNT | WALL-TIME | EXCL WALL-TIME (>= 0.00 MS) |
+-------------------------+--------+------------+------------------------------+
| mb_substr | 33334 | 1926.22 ms | 1926.22 ms |
| makeRandom | 1 | 146.50 ms | 133.92 ms |
| main() | 1 | 2101.69 ms | 28.86 ms |
| random_int | 100000 | 7.96 ms | 7.96 ms |
| chr | 100000 | 4.62 ms | 4.62 ms |
| mb_strlen | 1 | 0.12 ms | 0.12 ms |
| tideways_xhprof_disable | 1 | 0.00 ms | 0.00 ms |
+-------------------------+--------+------------+------------------------------+
Looking for a Web UI and SQL Profiling Support? Try our SaaS: https://tideways.io
$ toolkit generate-xhprof-graphviz -o mbstr.php.xhprof.dot mbstr.php.xhprof
$ dot -Tsvg -o mbstr.php.xhprof.svg mbstr.php.xhprof.dot
$ open -a 'Google Chrome' mbstr.php.xhprof.svg
mbarray のプロファイル結果
$ toolkit analyze-xhprof -m 0 mbarray.php.xhprof git:master ? :S6
Showing XHProf data by Exclusive Wall-Time
+-------------------------+--------+-----------+------------------------------+
| FUNCTION | COUNT | WALL-TIME | EXCL WALL-TIME (>= 0.00 MS) |
+-------------------------+--------+-----------+------------------------------+
| makeRandom | 1 | 131.23 ms | 117.61 ms |
| random_int | 100000 | 8.73 ms | 8.73 ms |
| chr | 100000 | 4.89 ms | 4.89 ms |
| main() | 1 | 132.59 ms | 0.97 ms |
| preg_split | 1 | 0.39 ms | 0.39 ms |
| tideways_xhprof_disable | 1 | 0.00 ms | 0.00 ms |
+-------------------------+--------+-----------+------------------------------+
Looking for a Web UI and SQL Profiling Support? Try our SaaS: https://tideways.io
$ toolkit generate-xhprof-graphviz -o mbarray.php.xhprof.dot mbarray.php.xhprof
$ dot -Tsvg -o mbarray.php.xhprof.svg mbarray.php.xhprof.dot
$ open -a 'Google Chrome' mbarray.php.xhprof.svg
結果
-
mb_substrは呼び出し回数が多く、そして全体の実行速度も遅いです。これはmb_substrの使い方を少し間違えているのが原因かと。 -
mbarray.phpの方はmakeRandomがボトルネックになっておりそれがパフォーマンスに影響しているような図になっていますが、そもそもmakeRandomの実行速度はmbstr.phpも実行しているので問題はない。
という感じ。メソッド単位で見たい時は表を表示したらいいけど、大きなくくりだと呼び出しメソッドが多くなって見にくくなるので、適度に細目化するか、グラフ化したらちょっとわかるよという感じ。
toolkitには他にもオプションがあるけど、使い方わからん。