^PROFILE を使用したルーチン・パフォーマンスの監視
^PROFILE ユーティリティは、プログラマがアプリケーションのルーチンおよびクラスのパフォーマンスを分析する際に利用できます。このタスクは、以下のように 2 フェーズ構成で実行されます。
-
データを収集し、ルーチン・レベルで並べ替え、最も “機能” しているルーチンを特定できます。
-
行レベルの詳細でデータ (サブルーチン、プロシージャ、および個別の行) の収集および表示が必要なルーチンを選択して、パフォーマンス上の問題が疑われる個別のルーチンへの “ドリル・ダウン” を可能にします。
既定では、^PROFILE は、最大で 5000 のルーチンのメトリックを取得します。最大数のルーチンに使用できる十分な共有メモリがない場合、このユーティリティは、このコレクションを監視するのに必要なメモリのページ数と使用可能なページ数に関するメッセージを表示します。その後、可能な限り多くのルーチンのメトリックを取得します。
^PROFILE の使用法
%SYS ネームスペースから (^PROFILE) ユーティリティを起動します。
%SYS>do ^PROFILE
データ収集の開始を求められたら、Enter を押します。
Note:
応答 (Yes および No 以外) を求められた場合は、「?」を入力してヘルプを表示できます。
既定では、プロファイルによってルーチンおよび以下のメトリックの番号付きリストが表示されます。初期設定の場合、このリストは RtnLine メトリックを基準にして並べ替えられます。
| 列タイトル (メトリック) |
説明 |
| RtnLine |
実行されたコードのルーチン行数。既定では、実行された全行数に対するパーセント値で表示されます。 |
| Time |
ルーチンの実行に要した時間。既定では、すべてのルーチンの実行の合計所要時間に対するパーセント値で表示されます。 |
| CPU |
ルーチンの実行に要した CPU 時間。既定では、すべてのルーチンの実行の合計 CPU 時間に対するパーセント値でエントリが表示されます。 |
| RtnLoad |
ルーチンがロードされた回数。既定では、すべてのルーチンのロードに対するパーセント値でエントリが表示されます。 |
| GloRef |
ルーチンのグローバル参照数。既定では、すべてのルーチンのグローバル参照数に対するパーセント値でエントリが表示されます。 |
| GloSet |
ルーチンのグローバル SET 数。既定では、すべてのルーチンのグローバル SET 数に対するパーセント値でエントリが表示されます。 |
ルーチン名 (INT または MVI ファイル)、および実行されるネームスペースは、エントリの 2 行目に表示されます。
ターミナルに表示された指示に従います。
-
プロファイル・レベルでルーチンのリストが表示される場合は、以下のいずれかを指定できます。
| オプション |
説明 |
| # |
詳細なプロファイル・レベルのデータ収集が指定された行 (複数可) を示すフラグを指定します。
Note:
表示されるページのそれぞれに、個別の行数 (#)、コンマで区切られたリスト (#,#,#)、範囲 (#-#)、または組み合わせ (#-#,#,#-#,#) を入力できます。
いずれかのページでルーチンを選択した後は、前後のページに移動して別のルーチンを選択できます。分析対象にするすべてのルーチンを選択したら、Q を入力して、詳細レベルのプロファイル収集を開始します。 |
| B |
リストの前のページを表示します。 |
| E |
表示されたメトリックのコレクションをエクスポートします。 |
| N |
リストの次のページを表示します。 |
| O |
別のメトリックを基準にしてページを並べ替えます (選択したメトリックが最初の列に表示されます)。 |
| Q |
^PROFILE ユーティリティを終了します。
Note:
分析対象のルーチンを示すフラグを指定した場合は、このオプションを指定することでサブルーチン・レベルおよび行レベルのメトリックを収集するか、終了するかを選択できます。
|
| R |
最新のメトリックでリストを更新します。 |
| X |
選択したルーチンのすべて (別のページで選択したルーチンも含む) のフラグをクリアし、メトリックの収集を更新します。 |
-
詳細プロファイリング・レベルでルーチンのリストが表示される場合は、以下のいずれかを指定できます。
| オプション |
説明 |
| # |
詳細に分析する必要があるルーチンの行番号。Enter を押すと、選択したルーチンのサブルーチン・ラベルが表示されます。 |
| B |
リストの前のページを表示します。 |
| N |
リストの次のページを表示します。 |
| O |
別のメトリックを基準にしてページを並べ替えます (選択したメトリックが最初の列に表示されます)。 |
| Q |
^PROFILE ユーティリティを終了します。 |
| R |
最新のメトリックでリストを更新します。 |
-
サブルーチン・ラベル (および各ラベルのメトリック) のリストが表示される場合は、以下のいずれかを指定できます。
| オプション |
説明 |
| # |
詳細に分析する必要があるサブルーチン・ラベルの行番号 (コード内)。Enter を押すと、指定したラベルのコードが表示されます。 |
| B |
リストの前のページを表示します。 |
| L |
サブルーチンの行レベル表示に切り替えます。 |
| N |
リストの次のページを表示します。 |
| Q |
リストを終了し、前のレベルに戻ります。 |
| R |
最新のメトリックでリストを更新します。
Note:
リストに *Unknown* が表示された場合は、R を入力します。
|
-
コードの行が表示されると、次の操作を指定するように求められます。使用できるオプションは以下のとおりです。
| オプション |
説明 |
| # |
詳細に分析する必要があるコード内の行番号。Enter を押すと、指定したラベルのコードが表示されます。 |
| B |
リストの前のページを表示します。 |
| C |
コードの表示をソース・コードと中間 (INT/MVI) コード間で切り替えます。 |
| M |
ページのマージンまたは長さを変更します。 |
| N |
リストの次のページを表示します。 |
| O |
別のメトリックを基準にしてページを並べ替えます。 |
| Q |
リストを終了し、前のレベルに戻ります。 |
| R |
最新のメトリックでリストを更新します。 |
| S |
ルーチンのサブルーチン・レベルの表示に切り替えます。 |
^PROFILE の例
以下は、ターミナルで ^PROFILE ユーティリティを (%SYS ネームスペースから) インタラクティブに実行する例です。
-
以下のコマンドを入力します｡
do ^PROFILE
-
以下のメッセージが表示されます。
WARNING: This routine will start a system-wide collection of
data on routine activity and then display the results. There
may be some overhead associated with the initial collection,
and it could significantly affect a busy system.
The second phase of collecting line level detail activity
has high overhead and should ONLY BE RUN ON A TEST SYSTEM!
Are you ready to start the collection? Yes =>
-
メトリックの収集を開始するには Enter を押します。以下のようなメトリックが表示されます。
Waiting for initial data collection ...
RtnLine Time CPU RtnLoad GloRef GloSet
1. 41.48% 12.19% 0.00% 28.97% 10.65% 0.00%
%Library.ResultSet.1.INT (IRISLIB)
2. 35.09% 56.16% 65.22% 9.35% 36.77% 42.55%
SYS.Database.1.INT (IRISSYS)
3. 10.75% 6.62% 0.00% 43.30% 22.68% 46.81%
Config.Databases.1.INT (IRISSYS)
4. 7.13% 3.22% 0.00% 6.23% 0.00% 0.00%
%Library.Persistent.1.INT (IRISLIB)
5. 1.26% 0.71% 0.00% 4.36% 4.12% 4.26%
PROFILE.INT (IRISSYS)
6. 1.20% 0.00% 0.00% 0.00% 5.15% 6.38%
%SYS.WorkQueueMgr.INT (IRISSYS)
7. 0.76% 15.08% 34.78% 0.00% 0.00% 0.00%
%SYS.API.INT (IRISSYS)
8. 0.64% 1.05% 0.00% 0.00% 17.18% 0.00%
%Library.JournalState.1.INT (IRISLIB)
9. 0.61% 0.31% 0.00% 3.74% 0.00% 0.00%
%Library.IResultSet.1.INT (IRISLIB)
10. 0.28% 0.93% 0.00% 0.00% 1.72% 0.00%
%Library.Device.1.INT (IRISLIB)
11. 0.24% 0.71% 0.00% 0.62% 0.00% 0.00%
Config.CPF.1.INT (IRISSYS)
Select routine(s) or '?' for more options N =>
-
詳細に分析するルーチンに関連付けられた番号を入力します。例えば、2-3,5,7,10 と入力してから N または B を入力すると、別のページを表示して、さらにルーチンの選択を追加できます。
-
分析対象にするすべてのルーチンを選択して、Q を入力すると、以下のようなメッセージが表示されます。
There are 2 routines selected for detailed profiling. You may now
end the routine level collection and start a detailed profiler collection.
WARNING !!
This will have each process on the system gather subroutine level and line
level activity on these routines. Note that this part of the collection may
have a significant effect on performance and should only be run in a test
or development instance.
Are you ready to start the detailed collection? Yes =>
-
Enter を押すと、以下のようなページが表示されます。
Stopping the routine level Profile collection ...
Loading ^%Library.Persistent.1 in ^^c:\intersystems\iris\mgr\irislib\
Detail level Profile collection started.
RtnLine Routine Name (Database)
1. 96.72% %Library.Persistent.1.INT (IRISLIB)
2. 3.28% Config.CPF.1.INT (IRISSYS)
Select routine to see details or '?' for more options R =>
-
コードを分析するルーチンを選択すると、コードに関する情報を含むページが表示されます。
