プログラムのパフォーマンス解析 ホーム目次前ページへ次ページへ索引


第 2 章

チュートリアル:標本コレクタおよび標本アナライザの使用方法

この章では、次に示す 3 つのサンプルプログラムのパフォーマンスを通じて、標本コレクタおよび標本アナライザを使用する方法を示します。

これらの例で、各プログラムは、次に示す同じパフォーマンスの問題を検討します。

資源の大部分を費やしているプログラム内の箇所がわかったら、Analyzer を使用すると、さまざまな方法でそのコードを調べることができるので、その理由を判断することができます。


注 - これらのすべての例で示される時間は、特定の実験で収集されたデータに基づくものです。異なる環境で行われた実験で収集されたデータからは、異なる数値が得られます。

これらの各デモプログラムのソースコードは、配布媒体に含まれています。このチュートリアルを開始する前に、次の作業が必要です。

1. 使用するパスに Sun WorkShop ディレクトリが追加されていることを確認してください。

/opt/SUNWspro/bin 

2. いくつかのデモディレクトリに含まれているファイルを自分の作業領域にコピーし、make を行なって、デモプログラムを作成します。

例 1:synprog

synprog プログラムには、興味深いパフォーマンス特性を示す、いくつかのプログラミング構造 (単純なメトリック解析、再帰、動的にリンクされた共用オブジェクトの読み込みと読み込み解除など) が組み込まれています。synprog プログラムは、標本コレクタと標本アナライザの操作演習に適しています。

synprog は、いわゆる「gprof の誤った推論」を引き起こします。標準 UNIX パフォーマンスツールである gprof コマンドは、synprog プログラムの CPU 時間のほとんどを自身で消費する関数 (さらに呼び出した関数が消費する時間は含まない) を正しく特定しますが、その関数を呼び出す関数を誤って報告します。

synprog のコピー

Sun WorkShop のインストールプログラムによって、synprog ソースファイルは、次のディレクトリにインストールされます。

/installation_directory/SUNWspro/WS6/examples/analyzer/synprog

デフォルトインストールの installation_directory は、/opt になります。

チュートリアルのこの部分を開始するにあたり、作業ディレクトリを作成し、synprog ソースファイルと Makefile をこの作業ディレクトリにコピーします。

cp -r installation_directory ~/synprog 

synprog の作成

synprog プログラムを作成する前に次の作業を実施します。

Makefile には、環境変数 ARCHOFLAGS の代替設定値が含まれています。

synprog を作成するには、次の手順に従います。

1. Makefile を保存し、エディタを閉じます。

2. コマンドプロンプトで make と入力します。

synprog に関するデータの収集

synprog に関するパフォーマンスデータを収集するには、次の手順に従います。

1. 次のように入力して、Sun WorkShop を起動します。

% workshop 

2. 「デバッグ」ボタンをクリックし、「デバッグ」ウィンドウを開きます。


3. synprog を「デバッグ」ウィンドウに読み込みます。

    1. 「デバッグ」メニューから「デバッグ」 「新規プログラム」を選択します。
    2. 「新規プログラムデバッグ」ダイアログの「名前」フィールドに、synprog のパスを入力するか、またはリストボックスを使用して synprog までナビゲートします。
    3. 「了解」をクリックします。

4. 「デバッグ」ウィンドウのメニューバーから「ウィンドウ」 「標本コレクタ」を選択し、「標本コレクタ」ウィンドウを開きます。

次のようになっているはずです。

5. 「開始」ボタンをクリックします。


synprog は、「デバッグ」ウィンドウで実行され、標本コレクタが時間ベースのプロファイルデータを収集し、デフォルトの実験レコードファイルである test.1.er に格納します。

synprog パフォーマンスメトリックの解析

アナライザを開き、test.1.er をアナライザに読み込むには、次の操作を行います。

1. Sun WorkShop メインウィンドウまたは「標本コレクタ」ウィンドウにあるツールバーの「解析」ボタンをクリックします。


2. 「実験ファイルの読み込み」ダイアログで、test.1.er と入力し、「了解」をクリックします。

アナライザを起動し、コマンド行からを test.1.er を読み込むには、次の操作を行います。

「アナライザ」ウィンドウには、synprog の関数一覧が表示されます。関数一覧には、次に示すデフォルトの時間ベースのプロファイリングメトリックが表示されます。

関数一覧は、専用ユーザー CPU 時間でソートされます。

単純なメトリック解析

まず、cputime() および icputime() という非常に単純な関数の実行時間を見ていましょう。どちらの関数にも for ループが含まれており、変数 x が 1 ずつインクリメントされています。ただし、cputime() の場合、x は浮動小数点であり、icputime() の場合は整数です。

1. 「関数リスト」表示で cputime()icputime() を見つけます。

これら 2 つの関数の専用ユーザー CPU 時間を見ると、cputime() のほうが、icputime() に比べ、はるかに実行に時間がかかっていることに気づくはずです。そこで、別の解析機能を使用して、この理由が何かを探ってみます。

2. 「関数リスト」表示で cputime() をクリックして選択します。

3. ウィンドウ下部にある「ソース」をクリックします。

テキストエディタが開き、cputime() 関数の注釈付きソースコードが表示されます。このとき、テキストエディタのウィンドウの幅を広げる必要があるかもしれません。
実行時間の大部分がループ行と、x がインクリメントされる行で費やされているのがわかります。

for(j=0; j<1000000; j++) {
        x = x + 1.0;
}

4. 今度は「関数リスト」表示で「icputime()」を選択し、「ソース」をクリックします。

テキストエディタには、cputime() のソースコードに代わって、icputime() のソースコードが表示されます。ループ行と x がインクリメントされる行を見てみます。

for(j=0; j<1000000; j++) {
        x = x + 1;
}

この icputime() 内のこの行は、対応する cputime() 内の行ほど実行に時間がかかっていません。なお、ループ行自体にかかっている時間は、cputime() 関数とほとんど同じです。
それでは、これらの関数の注釈付き逆アセンブリコードを見て、このようになっている理由を調べます。

5. 「関数リスト」表示で cputime() を選択し、ウィンドウ下部にある「逆アセンブル」をクリックします。

テキストエディタに、cputime() の注釈付き逆アセンブリコードが表示されます。ゼロでない測定値が見つかるまでスクロールダウンします。x がインクリメントされているソースコードの行を見つけます。
x と 1 の読み込みと加算にはほとんど時間が費やされていませんが、fstod 命令の実行に大部分の時間が費やされているのがわかります。この命令は、x の値を単精度浮動小数点型の値から倍精度浮動小数点型の値に変換し、同じく倍精度浮動小数点型の値として定義されている 1 だけインクリメントできるようにしています。後に、x を単精度浮動小数点型の値に戻す fdtos 指令で、やや CPU 時間をとられています。これら 2 つの演算で、費やされる CPU 時間の約 3/4 を占めています。

6. 「関数リスト」表示で icputime() を選択し、「逆アセンブル」をクリックします。

テキストエディタに icputime() の注釈付き逆アセンブリコードが表示されます。x がインクリメントされているソースコード行のパフォーマンスメトリックが見つかるまで、スクロールダウンします。
関係する操作は、単純な読み込み、加算、格納だけであり、これらに要する時間は、浮動小数点を使用した加算に要する時間の約 1/3 ですんでいます。その理由は、変換が不要だからです。ここでは、値 1 をレジスタにロードする必要もありません。値 1 は直接 x に加算できます。

再帰の効果

synprog プログラムには、再帰呼び出しシーケンスに関する 2 つの例が含まれています。

いずれの場合も、排他メトリックは、実際に処理が実行される関数に属します。この例では、real_recurse() bounce_a() が実際にタスクが実行される関数に相当します。これらの排他メトリックは、最終的な関数を呼び出すあらゆる関数に包含メトリックとして渡されます。

まず、recurse() および real_recurse() のメトリックを見ていきます。

1. 「関数リスト」表示で関数 recurse() を見つけ、クリックして選択します。

recurse() 関数には、包含ユーザー CPU 時間が表示されますが、その専用ユーザー CPU 時間がゼロになっていることに注意してください。これは、recurse()real_recurse() の呼び出し以外に何も行なっていないからです。


注 - 場合によっては、recurse() に小さなユーザー排他 CPU 時間値が表示されることがあります。これは、プロファイル実験が統計的な性質をもっており、synprog 上で行う実験が recurse() 関数の消費したごく短かな時間を記録している可能性があるからです。しかし、この排他時間は、包含時間に比べるとごくわずかです。

2. 「呼び出し元-呼び出し先」をクリックし、「呼び出し元-呼び出し先」ウィンドウを開きます。このウィンドウには、recurse() が関数 real_recurse() を呼び出している部分が表示されます。

3. real_recurse() をクリックして選択します。

「呼び出し元-呼び出し先」ウィンドウには、次の情報が表示されます。

今度は、間接再帰シーケンスではどのようになるかを見てみましょう。

1. 「関数リスト」表示で関数 bounce() を見つけ、クリックして選択します。

bounce() 関数には、包含ユーザー CPU 時間が表示されますが、その排他ユーザー CPU 時間はゼロであることに注意してください。これは、bounce() は、bounce_a() の呼び出し以外に何も行わないからです。

2. 「呼び出し元-呼び出し先」をクリックし、「呼び出し元-呼び出し先」ウィンドウを開きます。このウィンドウでは、bounce() が関数 bounce_a() を呼び出している部分だけが表示されます。

3. bounce_a() をクリックして選択します。

「呼び出し元-呼び出し先」ウィンドウには、次の情報が表示されます。

4. bounce_b() をクリックして選択します。

bounce_b() は、bounce_a() の呼び出し側、および bounce_a() によって呼び出される側の両方として表示されます。bounce_a() の排他メトリックおよび包含メトリックが、呼び出し側区画と呼び出され側区画の両方に表示されます。これは、ある関数によって排他メトリックが生成される場合、アナライザは、その関数が表示される「呼び出し元-呼び出し先」ウィンドウ内のどの区画にも、その関数のメトリックを表示するからです。

gprof の誤った推論

ここでは、synprog に対する gprof の誤った推論を、アナライザがどのように解決していくかを見ていきます。

gpf_work() という関数を選択します。これは、synprog がもっとも多く時間を費やす関数の 1 つです。

しかし、この例では、プログラムがどこに時間を費やしているかを知ることよりも、なぜそのようになっているかを考えるほうが重要です。そのために、gpf_work() を呼び出す関数と、それらの関数がどのように gpf_work() を呼び出すかを見てみましょう。

呼び出し側の区画を見ると、gpf_workgpf_b()gpf_a() という 2 つの関数によって呼び出されているのがわかります。アナライザによれば、gpf_work() の大部分の時間は gpf_b() からの呼び出しで費やされており、gpf_a() からの呼び出しではあまり費やされていません。そこで、gpf_b() からの呼び出しが gpf_a() からの呼び出しに比べ、gpf_work で 10 倍の時間が費やされている理由を知るために、これらの呼び出し側を調べてみる必要があります。

1. 呼び出し側区画で gpf_a() をクリックして選択します。

gpf_a() が現在選択されている関数なので、これが中央の区画に移動します。その呼び出し側は上の呼び出し側区画に表示されます。呼び出され側の gpf_work() は、下の呼び出され側区画に表示されます。

2. メインの「アナライザ」ウィンドウ (gpf_a() が現在選択されている関数として表示されている) に戻り、「ソース」ボタンをクリックしてテキストエディタを開き、gpf_a() の注釈付きソースコードを表示します。

3. テキストエディタでスクロールを行い、gpf_a()gpf_b() の両方のコードを表示します。

コードから、gpf_a() が引数に 1 を設定して gpf_work() を 10 回呼び出しているのがわかります。一方、gpf_b() は、gpf_work() を 1 回しか呼び出していませんが、引数に 10 を設定しています。gpf_a()gpf_b() からの引数は、gpf_work() の仮引数 amt に渡されます。

今度は、gpf_work() のコードを調べ、gpf_work() の呼び出し方がなぜ違いを生むのかを調べてみましょう。

これは、gprof にどのような関係があるのでしょうか。「gprof の誤った推論」は、呼び出された関数が渡された引数をどのように使用するかを考慮することなく、関数の呼び出し回数に基づいて、その関数に要する時間を見積っていることにあります。したがって、synprog の解析の場合、gprof であれば、gpf_a() からの呼び出しに、gpf_b() からの呼び出しの 10 倍の時間を当てることになるでしょう。これが gprof の誤った推論です。

関数の CPU 時間が、引数の累乗に依存していればいるほど、このようなゆがみは大きくなります。たとえば、次数が 3 乗される行列乗算であれば、さらに敏感に反映されるでしょう。

動的にリンクされた共用オブジェクトの読み込み

synprog ディレクトリには、2 つの動的にリンクされた共用オブジェクト so_syn.soso_syx.so があります。実行中に、synprog は、まず so_syn.so を読み込み、それに含まれる関数の so_burncpu() を呼び出します。次に、so_syn.so の読み込みを解除し、so_syx.so をたまたま同じアドレスに読み込み、so_syx.so に含まれる関数の sx_burncpu() を呼び出します。次に、so_syx.so の読み込みを解除せずに、再度 so_syn.so を別のアドレスに読み込み、so_burncpu() を呼び出します。so_syn.so を別のアドレスに読み込んだのは、最初に読み込んだアドレスが別の共用オブジェクトによって使用されているからです。

関数 so_burncpu() および sx_burncpu() は、そのソースコードからわかるようにまったく同じ操作を行います。したがって、実行時に同じユーザー CPU 時間を費やすはずです。

共用オブジェクトの読み込み先アドレスは、実行時に決定され、実行時ローダーがオブジェクトの読み込み場所を選択します。

このやや手の込んだ練習問題は、同一の関数が異なる実行時点で異なるアドレスから呼び出され得ること、異なる関数が同一のアドレスから呼び出され得ること、および アナライザがこのような動作を正しく処理し、関数の存在するアドレスに関係なく、その関数のデータを集計していることを示しています。

1. 「関数リスト」表示で sx_burncpu() をクリックして選択します。

2. 「表示」 「概要メトリックを表示」を選択します。

sx_burncpu() について「概要メトリック」ウィンドウが表示されます。sx_burncpu() のユーザー CPU 時間に注目してください。

3. 次に、so_burncpu() をクリックして選択します。so_burncpu() の概要データが「概要メトリック」ウィンドウに表示されます。

so_burncpu()sx_burncpu() とは処理内容が同じですが、so_burncpu() のユーザー CPU 時間は、sx_burncpu() のユーザー CPU 時間のほぼ 2 倍かかっています。これは、so_burncpu() が 2 回実行されているからです。このように、アナライザは、プログラムの実行中に同じ関数が別のアドレスに読み込まれたとしても、同じ関数が実行されたことを認識し、そのデータを集計します。

例 2:omptest


注 - omptest は、OpenMP 指示が含まれた Fortran プログラムであり、SPARC プラットフォーム上でコンパイルするには Fortran 95 コンパイラが必要です。

omptest プログラムは、OpenMP の並列化機能を使用しており、並列分散の効率をテストするように設計されています。omptest の解析では、次の問題を扱います。

omptest のコピー

Sun WorkShop のインストールプログラムによって、omptest ソースファイルは、次のディレクトリにインストールされます。

/installation_directory/SUNWspro/WS6/examples/analyzer/omptest

デフォルトインストールの installation_directory は、/opt になります。

このチュートリアルのここの部分を開始するにあたって、作業ディレクトリを作成し、omptest ソースファイルと Makefile をこの作業ディレクトリにコピーします。

% cp -r installation_directory ~/omptest 

omptest の作成

omptest プログラムを作成する前に次の作業を実施します。

omptest を作成するには、次の操作を行います。

1. Makefile を保存し、エディタを閉じます。

2. コマンドプロンプトで make と入力します。

omptest に関するデータの収集

デモンストレーションのこの部分では、4 CPU 以上のシステム上で omptest を実行しなければなりません。Sun WorkShop をマシン上にインストールしなければなりません。これによって、標本コレクタを実行して、パフォーマンスデータを収集できます。


注 - 並行化戦略および OpenMP 指令の背景については、『Fortran プログラミングガイド』の並行化と OpenMP の章を参照してください。

1. 次のように入力して、Sun WorkShop を起動します。

% workshop 

2. 「デバッグ」ボタンをクリックし、「デバッグ」ウィンドウを開きます。


3. omptest を「デバッグ」ウィンドウに読み込みます。

    1. 「デバッグ」メニューから「デバッグ」 「新規プログラム」を選択します。
    2. 「新規プログラムデバッグ」ダイアログの「名前」フィールドに、omptest のパスを入力するか、またはリストボックスを使用して omptest までナビゲートします。
    3. 「了解」をクリックします。

4. 環境変数 PARALLEL に値 4 を設定します。

    1. 「デバッグ」 「実行時の引数の編集」を選択して、「実行時の引数の編集」ダイアログを開きます。
    2. 「環境変数」をクリックし、「環境変数」ダイアログを開きます。
    3. 「名前」フィールドに PARALLEL と入力し、「値」フィールドに 4 を入力します。
    4. 「環境変数」ダイアログと「実行時の引数の編集」ダイアログを、それぞれ「了解」をクリックして閉じます。

5. 「デバッグ」ウィンドウのメニューバーから「ウィンドウ」 「標本コレクタ」を選択し、「標本コレクタ」ウィンドウを開きます。

次のようになっているはずです。

6. 「開始」ボタンをクリックします。


omptest は、「デバッグ」ウィンドウで実行され、標本コレクタが時間ベースのプロファイルデータを収集し、デフォルトの実験レコードファイルである omptest.1.er に格納します。

7. PARALLEL に 2 を設定して、手順 4 から手順 6 を繰り返し、パフォーマンス情報を omptest.2.er に保存します。

omptest パフォーマンスメトリックの解析

並行化戦略を解析するために、4 つの関数を調べ、それらを 4 台の CPU で実行する場合と 2 台の CPU で実行する場合とで、動作にどのような違いが生ずるかを比較します。

これらのルーチンはすべて、OpenMT 指令を omptest ソースコードに挿入した結果、コンパイル時に生成されたルーチンです。psec_()pdo_() の組と、critsum_()redsum_() の組は、効率的な並行化のための対照的な戦略を示しています。


注 - 並列コードの動作は、予期できないことがあります。このコードの動作の詳細については、「並列実行およびコンパイラ生成の本体関数」、および 「コンパイラ生成の本体関数」を参照してください。

まず、4 台の CPU と 2 台の CPU 上で実行される psec_()pdo_() のパフォーマンスを見てみましょう。

各「アナライザ」ウィンドウで次の作業を行います。

1. 「関数リスト」表示で psec_() のデータを見つけ、その行をクリックして選択します。

2. 「表示」 「概要メトリックを表示」を選択します。

「概要メトリック」ウィンドウが表示され、psec_() のメトリックが表示されます。

3. ユーザー CPU 時間、待ち時間、および総 LWP の包含メトリックを調べます。

2 CPU で実行した場合、psec_() のユーザー CPU 時間は約 8.9 秒、待ち時間は約 4.8 秒、総 LWP 時間は約 9.6 秒です。待ち時間と、ユーザー CPU 時間または総 LWP との比率は約 1 対 2 です。これは、比較的並列化の効率がよいことを物語っています。
一方、4 CPU で実行した場合、psec_() のユーザー CPU 時間は、2 CPU で実行した場合とほとんど同じ (8.4 秒) ですが、待ち時間と総 LWP 時間がともに長くなっています (それぞれ、6.12 秒と 11.55 秒)。psec() の場合、4 CPU マシンで実行した方が時間がかかっています。psec_() PARALLEL SECTION 構造には 2 つのセクションしかないため、それらを実行するには、スレッドが 2 つだけ必要です。したがって、使用可能な 4 台の CPU のうち、同時に使用されているのは 2 台だけです。なお、4 台の CPU マシン上でのパフォーマンスがわずかに劣っているのは、4 台の CPU 間でスレッドをスケジュールするという負荷がかかるためです。

4. 関数 pdo_() までスクロールし、その行をクリックして選択します。

5. 「アナライザ」のメニューから「表示」 「概要メトリックを表示」を選択します。

「概要メトリック」ウィンドウが表示され、pdo_() のメトリックが表示されます。

6. ユーザー CPU 時間、待ち時間、および総 LWP の包含メトリックを調べます。

pdo_() のユーザー CPU 時間は、psec_() とほぼ同じです (2 CPU で実行した場合は 8.4 秒、4 CPU で実行した場合は約 8.6 秒)。しかし、待ち時間対ユーザー CPU 時間の比率は、2 CPU の場合で約 1 対 2 ですが、4 CPU の場合は、約 1 対 4 になっています。このことは、利用できる CPU の数を考慮し、ループを適切にスケジュールすることで、pdo_() の並行化戦略において CPU の数により良く比例したパフォーマンスを得ることができることを意味します。

今度は、critsec_()reduc_() のルーチンの相対的な効率を見てみましょう。この場合、注釈付きのソースコードを見ると、各並行化戦略が、一組のdo ループに埋め込まれた同じ代入文をどの程度効率的に処理しているかがわかります。なお、この do ループの目的は、3 つの 2 次元配列の内容を合計することです。

t = (a(j,i)+b(j,i)+c(j,i))/k
sum = sum+t

1. 「関数リスト」表示で critsum_() のデータを見つけ、その行をクリックして選択します。

2. 「アナライザ」ウィンドウの下部にある「ソース」ボタンをクリックします。

critsum_() の生成元となるソースコードが注釈付きでテキストエディタに表示されます。

3. 包含ユーザー CPU 時間を調べます。

約 13 秒という大変大きな数値になっています。この包含ユーザー CPU 時間が非常に大きいのは、critsum_() が重要領域の並行化戦略を使用しているからです。すなわち、加算演算は 4 台すべての CPU に分散されますが。t という値を sum に合計できるのは、同時に 1 台の CPU だけです。これは、並行化を有効に活用した戦略とは言えません。

4. テキストエディタを閉じて、redsum_() のデータまでスクロールします。その行をクリックして選択します。

5. 「アナライザ」ウィンドウの下部にある「ソース」をクリックします。

redsum_() の生成元となるソースコードが注釈付きでテキストエディタに表示されます。

6. 包含ユーザー CPU 時間を調べます。

ここでは、約 1.7 秒と大幅に値が縮小されています。これは、redsum_() が削減戦略を使用しているからです。削減戦略によって、(a(j,i)+b(j,i)+c(j,i))/k の部分合計の計算が複数の CPUに分散して行われます。その後、これらの中間値が sum に加算されます。この戦略によって、利用可能な CPU の有効活用が行われています。

例 3:mttest

mttest プログラムは、クライアント-サーバ環境にあるサーバをエミュレートします。ここでは、クライアントが要求をキューに入れ、サーバが複数のスレッドを使用して、それらにサービスを提供します。このとき、明示的にスレッド機能を使用します。mttest で収集されたパフォーマンスデータは、さまざまなロック戦略から発生する競合と、実行時にキャッシュ機能を使用する効果を示します。

mttest のコピー

Sun WorkShop のインストールプログラムによって、mttest ソースファイルは、次のディレクトリにインストールされます。

/installation_directory/SUNWspro/WS6/examples/analyzer/mttest

デフォルトインストールの installation_directory は、/opt になります。

このチュートリアルのここの部分を開始するにあたって、作業ディレクトリを作成し、mttest ソースファイルと Makefile をこの作業ディレクトリにコピーします。

% cp -r installation_directory ~/mttest 

mttest の作成

mttest プログラムを作成する前に次の作業を実施します。

Makefile には、環境変数 ARCH、OFLAGS、THREADS および FLAG の代替設定値が含まれています。

mttest を作成するには、次の操作を行います。

1. Makefile を保存し、エディタを閉じます。

2. コマンドプロンプトに対し make と入力します。

mttest に関するデータの収集と解析

ここで作成した実行可能プログラム mttest は、明示的なマルチスレッド機能を使用するようにコンパイルされ、複数の CPU が搭載されたマシンまたは CPU が 1 台搭載されたマシン上でマルチスレッドプログラムとして実行します。CPU が 1 台搭載されたマシン上で mttest を実行すると、パフォーマンスメトリックに関する興味深い相違点と類似点がわかります。

次の 2 つの節「mttest に関するデータ収集 (4 CPU システム)」および 「mttest パフォーマンスメトリックの解析 (4 CPU システム)」では、4 CPU マシン上での mttest のパフォーマンスに注目してください。さらに続く 2 つの節 「mttest に関するデータ収集 (1 CPU システム)」および 「mttest パフォーマンスメトリックの解析 (1 CPU システム)」では、1 CPU マシン上での同じパフォーマンスメトリック群に注目してください。

mttest に関するデータ収集 (4 CPU システム)

デモンストレーションのこの部分では、4 CPU システム上で mttest を実行させなければなりません。標本コレクタを実行して、パフォーマンスデータを収集するには、Sun WorkShop をマシン上にインストールしておく必要があります。

1. 次のように入力して、Sun WorkShop を起動します。

% workshop 

2. 「デバッグ」ボタンをクリックし、「デバッグ」ウィンドウを開きます。


3. mttest を「デバッグ」ウィンドウに読み込みます。

    1. 「デバッグ」メニューから「デバッグ」 「新規プログラム」を選択します。
    2. 「新規プログラムデバッグ」ダイアログの「名前」フィールドに、mttest のパスを入力するか、リストボックスを使用して mttest までナビゲートします。
    3. 「了解」をクリックします。

4. 「デバッグ」ウィンドウメニューから「ウィンドウ」 「標本コレクタ」を選択し、「標本コレクタ」ウィンドウを開きます。

次のようになっているはずです。

5. この実験では、時間ベースのプロファイリングに加え、同期待ちの監視情報も収集します。そのため「同期待ちの監視」チェックボックスを選択します。

6. 「開始」ボタンをクリックします。


mttest は、「デバッグ」ウィンドウで実行され、標本コレクタが時間ベースのプロファイルデータおよび同期待ちの監視データを収集し、それを実験レコードファイルmttest.1.er に格納します。

mttest パフォーマンスメトリックの解析 (4 CPU システム)

アナライザを開き、mttest.1.er を読み込むには、次の操作を行います。

1. Sun WorkShop メインウィンドウまたは「標本コレクタ」ウィンドウのツールバー上の「解析」ボタンをクリックします。


2. 「実験ファイルの読み込み」ダイアログで mttest.1.er と入力し、「了解」をクリックします。

アナライザを起動し、コマンド行からを mttest.1.er を読み込むには、次の操作を行います。

1. 「関数リスト」表示で lock_local() および lock_global() のデータまでスクロールダウンします。

これらの関数の包含ユーザー CPU 時間は同じです (約 3.2 秒)。これは、両方の機能が同じ量のタスクを実行していることを示しています。
ただし、lock_global() は、同期待ちに多くの時間 (約 5秒) を費やしていますが、lock_local() は、同期待ちには時間を費やしていません。これらの関数の注釈付きソースコードを表示してみると、その理由がわかります。

2. lock_global() のデータ行をクリックし、それを選択します。

3. 「アナライザ」ウィンドウの下部にある「ソース」ボタンをクリックします。

テキストエディタに lock_global() 関数のソースコードが注釈付きで表示されます。このコードから、lock_global() がデータに大域ロックをかけているのがわかります。

mutex_lock(&global_lock);

大域ロックのために、実行中の全スレッドでデータへのアクセスのための競合が発生しています。同時にアクセスできるのは 1 つのスレッドだけです。残りのスレッドがデータにアクセスするためには、作業中のスレッドがロックを解くまで待たなければなりません。

4. lock_local() のデータ行をクリックし、それを選択します。

5. 「アナライザ」ウィンドウの下部にある「ソース」ボタンをクリックします。

テキストエディタに lock_local() 関数のソースコードが注釈付きで表示されます。このコードから、lock_local() が特定のスレッドの作業ブロック内にあるデータにだけロックをかけているのがわかります。

mutex_lock(&(array->lock));

どのスレッドも他のスレッドの作業ブロックにはアクセスできないため、スレッドは、競合や同期待ちによる無駄な時間なしに処理を続行できます。lock_local() の待ち時間は、ゼロ秒です。

6. 「アナライザ」ウィンドウの「関数リスト」表示に戻り、関数 computeA() および computeB() のデータまでスクロールします。

7. computeA() のデータ行をクリックして選択します。

8. 「アナライザ」ウィンドウの下部にある「ソース」ボタンをクリックします。

テキストエディタが開き、computeA() のソースコードが注釈付きで表示されます。

9. テキストエディタをスクロールダウンし、computeA() および computeB() のソースコードを表示します。

これらの関数のコードは実質的に同じ (ループのところで変数に 1 を加算している) ですが、computeB() は、包含ユーザー CPU 時間のほぼ 10 秒をここで費やし、computeA() は、約 3.3 秒しか費やしていません。このような相違点の理由を見つけるために、computeA()computeB() を呼び出しているコードを調べてみる必要があります。

10. 「アナライザ」ウィンドウの「関数リスト」表示に戻り、computeA() のデータ行をクリックして選択します。

11. ウィンドウの下部にある「呼び出し元-呼び出し先」ボタンをクリックします。

「呼び出し元-呼び出し先」ウィンドウが開き、中央の表示区画に選択した機能が、上の区画にその呼び出し側が表示されます。

12. 呼び出し側の lock_none() をクリックして選択します。

13. 「アナライザ」ウィンドウの「関数リスト」表示に戻ります。

ここで、lock_none() が現在選択されている関数であることに注意してください。

14. 「アナライザ」ウィンドウの下部にある「ソース」ボタンをクリックします。

テキストエディタが開き、lock_none() のソースコードが注釈付きで表示されます。

15. スクロールダウンし、computeB() を呼び出している cache_trash() という関数のコードを表示します。

16. computeA() および computeB() の呼び出し方を比較します。

computeA() は、スレッドの作業ブロック内にある 1 つの倍精度浮動小数点数型の値 (&array->list[0]) を引数として使用して呼び出されています。これは、他のスレッドと競合することなく、直接読み取りと書き込みを行うことができます。
computeB() は、メモリー内で連続した語を占める一連の倍精度浮動小数点数型の値 (element[array->index]) を使用して呼び出されています。あるスレッドがメモリー内にあるこれらのアドレスの 1 つに書き込みを行う場合、キャッシュ内にそのアドレスの内容を保持している他のスレッドは、必ずそのデータを削除しなければなりません。なぜなら、そのデータはすでに古くなっているからです。後にスレッドの 1 つがプログラムでそのデータを必要とした場合は、メモリーからデータキャッシュにコピーし直さなければなりません。これは非常に時間のかかる操作です。キャッシュ上にデータが無い、すなわち、データキャッシュ上で使用可能でないデータにアクセスしようとすることによって、多くの CPU 時間が無駄に費やされます。これが、computeB()computeA() に比べ 3 倍もの CPU 時間がかかっている理由です。

17. 「アナライザ」ウィンドウの「関数リスト」表示に戻り、computeB() の行をクリックして選択します。

18. ウィンドウの下部にある「逆アセンブル」をクリックします。

テキストエディタが開き、computeB() の逆アセンブリコードが注釈付きで表示されます。ユーザー CPU 時間 (7 秒を超える) の大部分が fadd 命令に費やされているのがわかります。fadd 命令は、キャッシュ上にないレジスタの読み込みを待っています。

mttest に関するデータ収集 (1 CPU システム)

デモンストレーションのこの部分では、1 CPU システム上で mttest を実行しなければなりません。まず、標本コレクタを実行して、パフォーマンスデータを収集するには、Sun WorkShop をマシン上にインストールしておく必要があります。

1. 次のように入力して、Sun WorkShop を起動します。

% workshop 

2. 「デバッグ」ボタンをクリックし、「デバッグ」ウィンドウを開きます。


3. mttest を「デバッグ」メニューに読み込みます。

    1. 「デバッグ」メニューから「デバッグ」 「新規プログラム」を選択します。
    2. 「新規プログラムデバッグ」ダイアログの「名前」フィールドに、 mttest のパスを入力するか、リストボックスを使用して mttest までナビゲートします。
    3. 「了解」をクリックします。

4. 「デバッグ」ウィンドウメニューバーから「ウィンドウ」 「標本コレクタ」を選択し、「標本コレクタ」ウィンドウを開きます。

次のようになっているはずです。

5. この実験では、時間ベースのプロファイリングに加え、同期待ちの監視情報も収集します。そのため「同期待ちの監視」チェックボックスを選択します。

6. 「開始」ボタンをクリックします。


mttest は、「デバッグ」ウィンドウで実行され、標本コレクタが時間ベースのプロファイルデータおよび同期待ちの監視データを収集し、それをデフォルトの実験レコードファイル mttest.2.er に格納します。

mttest パフォーマンスメトリックの解析 (1 CPU システム)

アナライザを開き、mttest.2.er を読み込むには、次の操作を行います。

1. 次のように入力します。

% analyzer mttest.2.er 

「アナライザ」ウィンドウには、mttest の関数一覧が表示されます。

2. 「関数リスト」表示で lock_local() および lock_global() のデータまでスクロールダウンします。

4 CPU システムの場合と同様に、これらの関数の包含ユーザー CPU 時間は同じです (約 10 秒)。このことは、両方の関数のタスク量が同じであることを示しています。
ただし、lock_global() の総 LWP 時間は、実際に lock_local() より少なく (25 秒対 37秒) なっています。それぞれのロックシステムのスレッドに CPU を割り当てる方法の違いによって、このようなことが起こり得ます。lock_global() で設定された大域ロックを使用すると、各スレッドは、順番に処理が完了するまで実行することができます。つまり、最初のスレッドが 2.5 秒間実行し終了するまでの間、他のスレッドは待ち状態になります。次に、最初のスレッドを待っていた 2 番目のスレッドが、2.5 秒間実行します。この時点で総 LWP 時間は 5 秒になります。3 番目のスレッドは、最初の 2 つのスレッドの終了を 5 秒待たされた後に実行され、総 LWP 時間は 7.5 秒になります。4 番目のスレッドは、7.5 秒待たされた後に実行され、総 LWP 時間は 10 秒になります。一方、lock_local() の局所ロックの場合は、CPU 上の各スレッドは、少しずつ実行するようにスケジュールされ、すべてのスレッドが完了するまで、この処理が繰り返されます。4 つのすべてのスレッドは、10 秒という実行時間のほぼ 3/4 が待ち状態にあります。
lock_global() は、多くの時間を同期待ちに費やしています (約 15 秒:2.5 + 5 + 7.5) が、lock_local() には、同期待ちの時間がありません。lock_local() は、特定のスレッドの作業ブロック内にあるデータにだけロックをかけます。lock_local() の処理は、4 CPU システムの場合と同様に、競合や同期待ちによる無駄時間なしに行われます。lock_local() の同期待ち時間はゼロ秒です。

3. 「アナライザ」ウィンドウの「関数リスト」表示に戻り、関数 computeA() および computeB() のデータまでスクロールします。

4. computeA() のデータ行をクリックして選択します。

5. 「アナライザ」ウィンドウの下部にある「ソース」ボタンをクリックします。

テキストエディタが開き、computeA() のソースコードが注釈付きで表示されます。

6. テキストエディタをスクロールダウンし、computeA() および computeB() のソースコードを表示します。

1 CPU システムの場合、これらの関数の包含 CPU 時間はほぼ同じです。

7. 「アナライザ」ウィンドウの「関数リスト」表示に戻り、computeA() のデータ行をクリックして選択します。

8. ウィンドウの下部にある「呼び出し元-呼び出し先」ボタンをクリックします。

「呼び出し元-呼び出し先」ウィンドウが開き、中央の表示区画に選択した関数 computeA() が、上の区画にその呼び出し側が表示されます。

9. 呼び出し側である cache_trash() をクリックして選択します。

10. 「アナライザ」ウィンドウの「関数リスト」表示に戻ります。

現在、cache_trash() が選択されています。

11. ウィンドウの下部にある「ソース」ボタンをクリックします。

テキストエディタが開き、cache_trash() のソースコードが注釈付きでが表示されます。

12. スクロールアップし、computeA() を呼び出している lock_none() という関数のコードを表示します。

13. computeA() および computeB() の呼び出し方を比較します。

computeA() は、スレッドの作業ブロック内にある 1 つの倍精度浮動小数点数型の値 (&array->list[0]) を引数として呼び出されます。これは、他のスレッドと競合することなく、直接読み取りと書き込みを行うことができます。
computeB() は、一続きの倍精度浮動小数点数型の値 (element[array->index]) を使用して呼び出されています。この一連の倍精度浮動小数点数型の値は、メモリー内で連続した語を占め、データキャッシュを介してアクセスされます。複数のスレッドが複数の CPU 上で実行されているときに、あるスレッドがメモリー内にあるこれらのアドレスの 1 つに書き込みを行う場合、キャッシュ内にそのアドレスの内容を保持している他のスレッドは、必ずそのデータを削除しなければなりません。なぜなら、そのデータはすでに古くなっているからです。後にスレッドの 1 つがプログラムでそのデータを必要とした場合は、メモリーからデータキャッシュにコピーし直さなければなりません。これは非常に時間のかかる操作です。キャッシュ上でのデータ消失によって、多くの CPU 時間が無駄に費やされます。
しかし、実行中のスレッドが 1 つだけで、かつ他のスレッドがメモリーに書き込みを行なっていない場合は、実行中のスレッドのキャッシュデータが無効になることはありません。キャッシュにデータが無いためにメモリーからコピーすることもありません。したがって、1 CPU マシン上の computeB() のパフォーマンスは、computeA() のパフォーマンスと同様に良好になります。


サン・マイクロシステムズ株式会社
Copyright information. All rights reserved.
ホーム   |   目次   |   前ページへ   |   次ページへ   |   索引