実行時間や周期時間の確認

DT+Traceの実行時間レポート・周期時間レポートを使用することで関数ごとの実行時間・周期時間が解析できるのはもちろん、関数が実行された1回1回の時間を詳細に解析し、意図していない時間となっていないかの確認、さらにはそのときの処理を確認できます。ボトルネックの特定や定周期処理の確認だけでなく、タイミング系の不具合の解析もこれらのレポートが有用です。ここではそれらの操作方法を説明します。

1. 実行時間とは

関数の入り口のテストポイント(FuncIn)が実行されてから、出口のテストポイント(FuncOut)が実行されるまでの時間です。関数内で別の関数を呼び出していたり、割り込み処理が入る場合もありますが、それらの時間も含んだものが「In-Out」、それらの時間を含まない純粋なその関数の実行時間を「占有時間」となっています。この2種類ありますが、解析したい内容に合わせてお選びください。

2. 周期時間とは

関数の入り口のテストポイント(FuncIn)が実行されてから、また同じ関数の入り口のテストポイント(FuncIn)が実行されるまでの時間です。このページに記載している操作方法はすべての時間系のレポートで共通ですので、実行時間レポート(In-Out)を使って説明します。

3. レポートの使い方

解析する関数の絞り込む

レポートには、実行時間の合計、最小、最大、平均、そして通過回数があります。リストのヘッダの各項目をクリックすることで、昇順・降順で並び替えができます。これらをキーにして、例えば最大時間が平均時間に比べて明らかに大きい関数であったり、合計時間や通過回数が大きい関数は意図しない呼び出しがあるのではないか、といった観点で、解析する関数を絞り込みます。

関数の実行時間を詳細リストから確認する

解析したい関数をダブルクリックすると、「実行時間詳細リスト」が表示されます。これはその関数の1回ごとの実行時間をリストアップしたものです。ここから例えば時間値が大きくなっている箇所を検出します。リストの項目が多いなど目視での確認が厳しい場合は、右クリックして「最大値」を選択すると、詳細リストのフォーカスを時間値が最大になっている行に自動でフォーカスを移動します。

その実行時間のときの処理を確認する

このようにして、意図しない時間値を検出した際に気になるのはどういった処理が実行されていたのか、という点です。詳細リストをダブルクリックすることで、DT+Traceは自動で表示をテストレポートに切り替え、該当する処理のレポート行にフォーカスを移動します。また、該当処理のテストレポートの「No.」欄を緑色で表示します。これにより、膨大な量のログの中から見たい箇所を絞り込むことができました。

あとは、その部分から意図しない処理(関数呼び出しなど)を行っていないかを確認します。例えば、テストレポートの「差分(＝ひとつ前のレポート行との差分時間)」を確認することで、その間にある処理に時間がかかっていた、といった具合でボトルネックなどの原因の特定が可能です。

4. 処理時間を把握する

DT+Traceでは、時間値のデータをリストだけでなくグラフ表示できます。レポート上で右クリックし、「実行時間グラフ表示」や「実行時間ヒストグラム表示」と選択することで、関数ごとの時間値やその関数の実行時間のばらつきを確認できます。

右クリックして「コピー」を選択すると、クリップボードにコピーできます。

また、レポートの内容もCSVでエクスポートできます。
-> DT+Traceの解析内容を外部にエクスポートする

▲トップページへ戻る