=encoding euc-jp =head1 名前 Devel::Profile - なぜ自分のプログラムがとても遅いのか教えてくれます。 =head1 概要 perl -d:Profile program.pl less prof.out =head1 説明 Devel::Profileパッケージは、Perl用のコードプロファイラです。 これは、Perlスクリプトおよび、そのスクリプトのサブルーチンの実行時間に関する情報を集めます。 この情報から、どのサブルーチンが最も多くの時間を使っているか、そして、どのサブルーチンが 最も頻繁に呼ばれているか調査するのに使用することができます。 Perlスクリプトのプロファイルを行うには、-d スイッチを使用してperlインタプリタを実行します。 プロファイラは、デバッグ用のフックを使っています。 test.plのプロファイルを行う場合以下のようなコマンドになります。 perl -d:Profile test.pl スクリプトが終了時(または、実行中の一定周期的に ENVIRONMENT章を参照)、 プロファイラはprof.outと言う名前のファイルに、プロファイル情報を出力します。 出力されたファイルはテキストファイルで、そのまま読むことが出来ます。別のツール などを使って読む必要はありません。 備考:統計はサブルーチン単位に行われます。コード単位ではありません。 =head1 環境変数 =over 4 =item C 実行中に何秒ごとにプロファイルを出力するかを指定します。 0を指定すると終了時のみに出力します。 デフォルトは二分毎です。 =item C プロファイルを出力するファイル名を指定します。 デフォルトはカレントディレクトリの prof.out です。 =item C 場合によっては、サブルーチン以外で実行されるコードの時間(例えばmainスコープの裸のコード) を集計したくないかもしれません。 デフォルトでは、この部分は '' という名前で集計されますが この変数に何かの値をセットすると、集計を行いません。 これは、プログラムの実行時間として集計される時間がその分少なくなる為、(訳注:実行時間の比率 などに)影響を与えることに注意してください。 =back =head1 出力形式 出力例: time elapsed (wall): 86.8212 time running program: 65.7657 (75.75%) time profiling (est.): 21.0556 (24.25%) number of calls: 647248 %Time Sec. #calls sec/call F name 31.74 20.8770 2306 0.009053 Configable::init_from_config 20.09 13.2116 144638 0.000091 Configable::init_field_from_config 17.49 11.5043 297997 0.000039 Configable::has_attr 8.22 5.4028 312 0.017317 MonEl::recycle 7.54 4.9570 64239 0.000077 Configable::inherit 5.02 3.3042 101289 0.000033 MonEl::unique [...] 簡単な概要の後につづいて、サブルーチン毎に1行のデータがあります。 =over 4 =item time elapsed (wall) トータル実行時間(プロファイラとプログラム) =item time running program プログラム実行時間とトータルとの比率 =item time profiling プロファイラ実行時間とトータルとの比率 =item number of calls プログラム内でサブルーチンがコールされた総数 =back サブルーチン毎の行データは以下です。 =over 4 =item name サブルーチンの名前 =item %Time サブルーチン実行時間の全体との比率 =item Sec. サブルーチン実行時間の合計 =item #calls サブルーチン呼出回数 =item sec/call サブルーチン一回あたりの実行時間平均 =item F フラグ =over 4 =item C<*> 原文まま pseudo-function to account for otherwise unacounted for time. (訳注:意味理解できなかったのですが、等のサブルーチンでないと 表現しているのでは?と思います。) =item C このサブルーチンを呼び出したあと、returnせず終了しました。 (例えば、die や exit で終了するなど。) (訳注:sec/callの)集計に若干の誤差が出ている場合があります。 =item C このサブルーチンを呼び出したあと例外発生で終了しました。 (訳注:sec/callの)集計に若干の誤差が出ている場合があります。 =back =back =head1 実行時間の長いプログラム このモジュールは長時間実行される(デーモン)プログラムでもプロファイリング 出来るように書かれています。通常はこのようなプログラムは終わることが無く プロファイルの出力が終了時に限られてしまうのは面白くない選択です。 このモジュールは定期的に$PERL_PROFILE_SAVETIMEに基づく間隔でプロファイ ル出力が可能ですし、DB::save()を呼び出して、コードの任意の位置でプロファ イル出力させることも可能です。ですからプログラムを実行していても、プロ ファイルを参照することが出来ます。 上記の様なプログラムで、非常に時間がかかる初期化処理(設定ファイルの 読み込みやデータ構造の初期化など)があるのなら、初期化処理と処理本体を 分けてプロファイリングしたいと思うでしょう。 その場合は、一旦プロファイルを保存した後に、DB::reset()を呼び出して、 それまでの統計をリセットすることが出来ます。リセットを行うと、その時点 からの統計がプロファイルに出力されます。 デフォルトではリセットを行う為のシグナルをSIGUSR2で受け取るようになって います。シグナルが安全に取り扱える、perl5.8.0以降を使用すると、プロファ イル出力の為のシグナルのコントロールが安全に行えるでしょう。 =head1 バグ 既知のバグはありません。 =head1 参考資料 イエローストーン国立公園 =head1 作者 Jeff Weisberg - http://www.tcp4me.com/