実行時間や周期時間の確認
DT+Traceの実行時間レポート・周期時間レポートを使用することで関数ごとの実行時間・周期時間が解析できるのはもちろん、関数が実行された1回1回の時間を詳細に解析し、意図していない時間となっていないかの確認、さらにはそのときの処理を確認できます。ボトルネックの特定や定周期処理の確認だけでなく、タイミング系の不具合の解析もこれらのレポートが有用です。ここではそれらの操作方法を説明します。
3. レポートの使い方
解析する関数の絞り込む
レポートには、実行時間の合計、最小、最大、平均、そして通過回数があります。リストのヘッダの各項目をクリックすることで、昇順・降順で並び替えができます。これらをキーにして、例えば最大時間が平均時間に比べて明らかに大きい関数であったり、合計時間や通過回数が大きい関数は意図しない呼び出しがあるのではないか、といった観点で、解析する関数を絞り込みます。
関数の実行時間を詳細リストから確認する
解析したい関数をダブルクリックすると、「実行時間詳細リスト」が表示されます。これはその関数の1回ごとの実行時間をリストアップしたものです。ここから例えば時間値が大きくなっている箇所を検出します。リストの項目が多いなど目視での確認が厳しい場合は、右クリックして「最大値」を選択すると、詳細リストのフォーカスを時間値が最大になっている行に自動でフォーカスを移動します。
その実行時間のときの処理を確認する
このようにして、意図しない時間値を検出した際に気になるのはどういった処理が実行されていたのか、という点です。詳細リストをダブルクリックすることで、DT+Traceは自動で表示をテストレポートに切り替え、該当する処理のレポート行にフォーカスを移動します。また、該当処理のテストレポートの「No.」欄を緑色で表示します。これにより、膨大な量のログの中から見たい箇所を絞り込むことができました。
あとは、その部分から意図しない処理(関数呼び出しなど)を行っていないかを確認します。例えば、テストレポートの「差分(=ひとつ前のレポート行との差分時間)」を確認することで、その間にある処理に時間がかかっていた、といった具合でボトルネックなどの原因の特定が可能です。