PHPで簡易プロファイリング #PHP

PHPで書かれたシステムのパフォーマンスチューニングをすることになったので、久しぶりにプロファイラを使おうとしたのですが、これがなかなかうまくいかない。

数年前にプロファイリングしたときにはxhprofを使ったので今回もこちらでと思ったのですが、最新リリースは2013年9月30日と4年も前。もちろんPHP7.0リリース前ですので、PHP7.0には対応していません。有志が対応してくださっているそうですが。

では他のプロファイラをと思って探したんですが、当たり前ですがどれもモジュールになっているのでインストールの壁が立ちはだかります。今回、少々特殊な環境で動作するシステムなもので、モジュールを勝手にインストールすることが出来ません。

そもそも、そんな精密なプロファイリングは必要なくて、各処理ブロックのおおまかな実行時間がわかればいい程度のことだったので、以下のような簡易プロファイラを作って対応しました。

laptimer.php

<?php
class laptimer{
  private $starttime = 0;
  private $shoots = array();
  private $is_outputed;

  function __construct(){
    $this->reset();
  }

  function __destruct(){
    if(!$this->is_outputed){
      $this->report();
    }
  }

  function reset(){
    $this->starttime = microtime(true);
    $this->shoots = array();
    $this->is_outputed = false;
  }

  function shoot($subject = ''){
    array_push($this->shoots, array(
      'subject'=>$subject,
          'spendtime'=>microtime(true) - $this->starttime)
    );
    $this->is_outputed = false;
  }

  function report(){
    if(php_sapi_name() !== 'cli'){
      print "<!--\n";
    }
    foreach($this->shoots as $shoot){
      printf("%s : %f\n", $shoot['subject'], $shoot['spendtime']);
    }
    if(php_sapi_name() !== 'cli'){
      print "-->\n";
    }
    $this->is_outputed = true;
  }
};

使い方はこんな感じ。泥臭いですが、計測ポイントにコードを直接埋め込んでいきます。

<?php
require('laptimer.php');

$timer = new laptimer;

for($n = 2; $n < 10; $n++){
  print "hanoi {$n}\n";
  hanoi($n, 'A', 'B', 'C');
  $timer->shoot("hanoi {$n} finish");
}

$timer->shoot('all finish');

function hanoi($n, $a, $b, $c){
  if($n > 0){
    hanoi($n-1, $a, $c, $b);
    print "{$n} disk move {$a} to {$b}\n";
    hanoi($n-1, $c, $b, $a);
  }
}

実行結果はこんな感じですね。

hanoi 2
1 disk move A to C
2 disk move A to B
1 disk move C to B
hanoi 3
1 disk move A to B
2 disk move A to C
1 disk move B to C
3 disk move A to B
1 disk move C to A

...

1 disk move A to B
hanoi 2 finish : 0.000062
hanoi 3 finish : 0.000119
hanoi 4 finish : 0.000192
hanoi 5 finish : 0.000333
hanoi 6 finish : 0.000601
hanoi 7 finish : 0.001117
hanoi 8 finish : 0.002158
hanoi 9 finish : 0.004223
all finish : 0.004225

とりあえずこの方法でボトルネックは発見できたので、目的は果たすことが出来ました。