PHPプログラムのパフォーマンス可視化

計測の話。

PHP7.1にて、 [xhprof](http://php.net/manual/ja/book.xhprof.php)を使おうと思ったらどうも使えないので、 [tideways_xhprof](https://github.com/tideways/php-xhprof-extension)を使った。

## インストール

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
<?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
<?php

$a = makeRandom();

$buff = preg_split('//u', $a);
$result = '';
foreach($buff as $b){
	$result .= '-'.$b;
}
```

### run.php

上記２つのうち、指定した方を実行して、プロファイル結果を保存する。

```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](https://github.com/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](https://www.graphviz.org)をインストールしているなら、グラフ化もしてみる。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
```

<img width="847" alt="スクリーンショット 2018-10-24 16.09.54.png" src="https://qiita-image-store.s3.amazonaws.com/0/1054/9ff26db0-f82d-369d-f055-671f1e598352.png">


### 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
```

<img width="544" alt="スクリーンショット 2018-10-24 16.12.46.png" src="https://qiita-image-store.s3.amazonaws.com/0/1054/e92edd49-2e6b-1442-2082-e6456e6de48b.png">

## 結果

1. `mb_substr` は呼び出し回数が多く、そして全体の実行速度も遅いです。これは `mb_substr` の使い方を少し間違えているのが原因かと。
2. `mbarray.php` の方は `makeRandom` がボトルネックになっておりそれがパフォーマンスに影響しているような図になっていますが、そもそも `makeRandom` の実行速度は `mbstr.php` も実行しているので問題はない。

という感じ。メソッド単位で見たい時は表を表示したらいいけど、大きなくくりだと呼び出しメソッドが多くなって見にくくなるので、適度に細目化するか、グラフ化したらちょっとわかるよという感じ。

`toolkit`には他にもオプションがあるけど、使い方わからん。

## 参考

1. [Profiling Tools For PHP7](https://qiita.com/takahashi-yugo/items/8f141e6ca0259a2bd2c8)
2. https://github.com/tideways/php-xhprof-extension
3. https://github.com/tideways/toolkit
4. https://www.graphviz.org