プロファイラ


 Devel::DProfモジュールを使ってサブルーチン毎の実行時間を計測することができます。
 perl -d:DProf test.pl と実行するとtest.plのプロファイル情報がtmon.outというファイルに保存されます。dprofppコマンドを実行するとtmon.outを集計して結果を表示します。
 プロファイル情報の取得と集計結果の表示を同時に行いたい場合は、dprofpp -p test.plとすればよいです。
 dprfppのオプションや表示される値についてはperldoc dprofppで説明を読むことができます。

サンプルプログラム(test.pl)

my $LOOP = 1000;

foo();
foo();
my $cnt = 0;
foreach (1..$LOOP) {
	$cnt = bar($cnt);
}

sub foo {
	my $now;
	my %store;
	foreach my $i (1..$LOOP) {
		$now = localtime;
		unless (exists $store{$now}) {
			$store{$now} = 1;
		} else {
			$store{$now}++;
		}
	}
}

sub bar {
	my $cnt = shift;
	for (my $i = 0; $i < 100; $i++) {
		$cnt++;
	}
	return $cnt;
}

集計と結果表示

> dprofpp -p test.pl

Total Elapsed Time = 3.757658 Seconds
  User+System Time = 3.757658 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 88.0   3.307  3.282   1000   0.0033 0.0033  main::bar
 11.9   0.450  0.450      2   0.2250 0.2250  main::foo

 -tまたは-Tオプションで、サブルーチンの呼び出し状況が分かります。

サンプルプログラム(test2.pl)

foo();
bar();
exit;

sub foo {
	bar();
	bar();
}

sub bar {
	foreach (1..2) {
		baz();
	}
}

sub baz {
	;
}

集計と結果表示

> dprofpp -t -p test2.pl

main::foo
   main::bar
      main::baz (2x)
   main::bar
      main::baz (2x)
main::bar
   main::baz (2x)

関連項目

times関数
CGIのプロファイルを取得
ベンチマーク
メトリクスの取得