Oracle® Solaris Studio 12.4: パフォーマンスアナライザチュートリアル

印刷ビューの終了

更新: 2014 年 12 月
 
 

同期トレースの理解

このセクションでは、同期トレースのデータと、そのデータをクロックプロファイリングデータと関連付ける方法について説明します。

  1. 「関数」ビューに移動し、列見出し「包括的 CPU 合計」をクリックし、包括的 CPU 合計時間に従ってソートします。

  2. リストの先頭にある do_work() 関数を選択します。

    image:do_work 関数が選択された「関数」ビュー
  3. 「関数」ビューの下部にある「呼び出し元/呼び出し回数」パネルを見ると、do_work() は 2 つの場所から呼び出され、10 個の関数を呼び出しています。

    do_work() はほとんどの場合、データを処理するスレッドの作成時に呼び出され、_lwp_start() から呼び出されるものとして示されます。do_work() は場合によっては、locktest() から呼び出されたあと、nothreads() という名前の 1 つのシングルスレッドタスクを呼び出します。

    do_work() が呼び出す 10 個の関数は 10 個の異なるタスクを表し、各タスクはプログラムが実行した異なる同期メソッドを使用します。mttest で作成される一部の実験では、わずかな時間を使用してほかのタスクからワークブロックをフェッチする 11 番目の関数が記録されることがあります。この関数 fetch_work() は、前のスクリーンショットで「呼び出し」パネルに表示されています。

    「呼び出し」パネルの最初の 2 つの呼び出し先を除き、すべての呼び出し先はほぼ同じ時間の「属性 CPU 合計時間」(10.6 秒以下) を示しています。

  4. 「呼び出し元-呼び出し先」ビューに切り替えます。

    image:「呼び出し元-呼び出し先」ビュー

    「呼び出し元-呼び出し先」ビューには「呼び出し元/呼び出し回数」パネルと同じ呼び出し元と呼び出し先が表示されますが、「属性同期待ち時間」など、「概要」ページで選択されたほかのメトリックも表示されます。

    2 つの関数 lock_global() および lock_local() を探すと、これらの関数が示している「属性 CPU 合計時間」はほとんど同じですが、「属性同期待ち時間」は大きく異なっています。

  5. lock_global() 関数を選択して「ソース」ビューに切り替えます。

    image:「ソース」ビュー

    すべての「同期待ち時間」は、「CPU 時間合計」が 0 である pthread_mutex_lock(&global_lock) の呼び出しがある行で費やされています。関数名から推測されるように、このタスクを実行する 4 つのスレッドはすべて、グローバルロックを 1 つずつ獲得するときに各自の処理を実行します。

  6. 「関数」ビューに戻って lock_global() を選択し、「フィルタ」アイコンをクリックして「フィルタの追加: 選択した関数を含むスタックのみを含める」を選択します。

  7. 「タイムライン」ビューを選択すると、4 つのスレッドが見えます。

    image:4 つのタスクスレッドを表示する「タイムライン」ビュー

    ロックを取得するための最初のスレッド (スクリーンショットの T:17) は 2.65 秒を費やしたあと、ロックを諦めます。そのスレッドのスレッド状態バーは緑色であり、その時間のすべてが「ユーザー CPU 時間」で消費され、「ユーザーロック時間」では消費されなかったことがわかります。また、同期トレースの呼び出しスタックを表す 2 番目のバーには image:同期トレースの呼び出しスタックアイコン マークが付き、このスレッドの呼び出しスタックがないことを示しています。

    2 番目のスレッド (スクリーンショットの T:16) は「ユーザーロック時間」で 2.6 秒待ったあと、2.65 秒にわたって計算し、ロックを諦めます。同期トレースの呼び出しスタックは「ユーザーロック時間」と同時期です。

    3 番目のスレッド (T:15) は「ユーザーロック時間」で 5.3 秒待ったあと、2.65 秒にわたって計算し、ロックを諦めます。

    最後のスレッド (T:14) は「ユーザーロック時間」で 7.9 秒待ったあと、2.65 秒にわたって計算します。合計の計算は 2.65 x 4 または 10.6 秒以下でした。

    合計の同期待ちは 2.6 + 5.3 + 7.9 または 15.9 秒以下でした。このことは「関数」ビューで確認できます。

  8. 「アクティブなフィルタ」パネルの「X」をクリックしてフィルタを削除します。

  9. 「関数」ビューに戻り、関数 lock_local() を選択して「ソース」ビューに切り替えます。

    image:「ソース」ビューに lock_local のコードを表示

    pthread_mutex_lock(&array->lock) の呼び出しがある行 (スクリーンショットの行 1043) で、「同期待ち時間」は 0 です。その理由は、ロックがワークブロックにローカルであるため、競合がなく、4 つのスレッドすべてが同時に計算することです。

ここまで見てきた実験は、測定に基づくしきい値を使用して記録されたものです。次のセクションでは、make コマンドの実行時にしきい値をゼロにして記録された 2 番目の実験と比較します。