8    プログラムのプロファイルによる性能の向上

プロファイルとは,全実行時間のうちの大きな割合をどのコード・セクションが消費しているかを識別するためのメソッドです。 通常のプログラムでは,実行時間のほとんどはコード内の比較的少数のセクションで消費されます。 プログラムの性能を向上させるためには,実行時間を集中的に消費するセクションのコーディング効率を向上させることが最も有効です。

Tru64 UNIX では,性能の向上のために次の 4 つの方法をサポートしています。

これらの方法のいずれか 1 つだけで十分な場合もありますが,1 つの方法でプログラムの性能のすべての面に対処できない場合は,複数の方法を組み合わせる方がよいかもしれません。 自動最適化とプロファイル主導の最適化は,性能を改善するための最も簡単な方法です。 この章では,最後の 3 つ (手動) の性能改善方法について説明するとともに,それをサポートするために Tru64 UNIX で提供するツールについて説明します。 また,次の項目についても説明します。

詳細については,次のリファレンス・ページおよびドキュメントを参照してください。

8.1    プロファイルのサンプル・プログラム

この章で取り上げる例では,sample プログラムを参照しています。 sample プログラムのソース・コードのファイルは,profsample.c (main プログラム), add_vector.c, mul_by_scalar.c, print_it.c, profsample.h です。 これらのファイルを例 8-1 に示します。

例 8-1:  プロファイルのサンプル・プログラム

****************** profsample.c *************
#include <math.h>
#include <stdio.h>
#include "profsample.h"
 
static void mul_by_pi(double ary[])
{
    mul_by_scalar(ary, LEN/2, 3.14159);
}
 
void main()
{
    double ary1[LEN];
    double *ary2;
    double sum = 0.0;
    int i;
 
    ary2 = malloc(LEN * sizeof(double));
    for (i=0; i<LEN; i++) {
        ary1[i] = 0.0;
        ary2[i] = sqrt((double)i);
    }
    mul_by_pi(ary1);
    mul_by_scalar(ary2, LEN, 2.71828);
    for (i=0; i<100; i++)
        add_vector(ary1, ary2, LEN);
    for (i=0; i<100; i++)
	sum += ary1[i];
    if (sum < 0.0)
	print_it(0.0);
    else
	print_it(sum);
}
****************** profsample.h: ********************
 
void mul_by_scalar(double ary[], int len, double num);
void add_vector(double arya[], double aryb[], int len);
void print_it(double value);
#define LEN 100000
 
***************** add_vector.c: ********************
 
#include "profsample.h"
 
void add_vector(double arya[], double aryb[], int len)
{
    int i;
    for (i=0; i<LEN; i++) {
        arya[i] += aryb[i];
    }
}
**************** mul_by_scalar.c: ******************
 
#include "profsample.h"
 
void mul_by_scalar(double ary[], int len, double num)
{
    int i;
    for (i=0; i<LEN; i++) {
        ary[i] *= num;
    }
}
**************** print_it.c: **********************
 
#include <stdio.h>
#include "profsample.h"
 
void print_it(double value)
{
    printf("Value = %f\n", value);
}

8.2    プロファイルのコンパイラ・オプション

cc コマンドのデバッグ・オプションと最適化オプションを使用する場合には,次の点に注意してください。 これらの注意事項は,特に断らない限り,この章で説明するすべてのプロファイル・ツールに適用されます。

8.3    手動による設計とコードの最適化

この節では,手動による設計とコードの最適化に使用する手法とツールについて説明します。

8.3.1    手法

10.1 節で説明した自動最適化の効果は,プログラムが使用するアルゴリズムの効率によって制限されます。 アルゴリズムとデータ構造を手動で最適化することにより,プログラムの性能をさらに向上させることができます。 このような最適化には,N 乗から対数 N へ複雑さを低減したり,データのコピーを避けたり,使用するデータの量を減らしたりすることなどがあります。 また,プログラムを実行する特定のマシンのアーキテクチャに合わせてアルゴリズムを調整する場合もあります。 たとえば,処理のフェーズごとに配列全体をデータ・キャッシュに読み込むかわりに,大きな配列を小さなブロックに分けて処理し,処理全体に対して各々のブロックがデータ・キャッシュに残るようにします。

Tru64 UNIX では,手動による最適化にプロファイル・ツールを使用できます。 このツールでは,アプリケーションの中で最大の CPU 負荷を課す部分 (CPU サイクル,キャッシュ・ミスなど) を特定します。 プログラムのさまざまなプロファイルを評価することにより,プログラムのどの部分が最も多くの CPU リソースを使用しているかを特定することができ,それらの部分のアルゴリズムの設計やコーディングを見直して,リソースの使用量を減らすことができます。 また,プロファイルを使用すると,リソース使用の少ないコードではなく,最もリソース使用の激しいコードに作業を集中することができるため,作業の費用対効果が大きくなります。

8.3.2    ツールと例

以降の各項では,呼び出しグラフを使用して CPU 時間のプロファイルを行うためのツールと,ソース行と命令を使用して CPU 時間またはイベントのプロファイルを行うためのツールについて説明します。

8.3.2.1    呼び出しグラフを使用した CPU 時間のプロファイル

呼び出しグラフのプロファイルは,各プロシージャで使用された CPU 時間と,そのプロシージャが呼び出した他のすべてのプロシージャで使用された CPU 時間を示します。 このプロファイルでは,プログラムの中のどのフェーズまたはサブシステムが全 CPU 時間のうち最も多くの時間を費やしたのかを示すことができるため,プログラムの性能を全般的に理解することができます。 この項では,この情報を得るための 2 つのツールについて説明します。

どちらのツールも gprof ツールとともに明示的または暗示的に使用して,プロファイルのフォーマットと表示を行います。

オプションとして dxprof コマンドを使用すると,CPU 時間の呼び出しグラフのプロファイルをグラフィカル表示できます。

8.3.2.1.1    hiprof プロファイラを使用する方法

hiprof プロファイラ ( hiprof(1) を参照) は,プログラムを計測し,計測機構付きプログラムの実行中に呼び出しグラフを生成します。 このプロファイラでは,プログラムは 8.2 節に示した以外の特定の方法でコンパイルされている必要はありません。 hiprof コマンドでは,シェアード・ライブラリとプログラム・コードの呼び出しグラフを作成できます。 その際には,適度な最適化を行い,最小限のデバッグ情報を付けることができます。 たとえば,次のようにコマンドを実行します。

% cc -o libsample.so -shared -g1 -O2 add_vector.c mul_by_scalar.c print_it.c [1]

% cc -o sample -g1 -O2 profsample.c -L. -lsample -lm [2]

% hiprof -numbers -L. -inc libsample.so sample [3]

  1. 8.2 節で説明したように,3 つのソース・モジュールからシェアード・ライブラリ libsample.so を,最適化およびデバッグ情報付きで作成します。 [例に戻る]

  2. ソース・モジュール profsample をコンパイルし,シェアード・ライブラリ libsample.so (現在のディレクトリ上) とリンクして,実行可能ファイル sample を作成します。 [例に戻る]

  3. -inc[obj] オプションにより,実行可能ファイル (sample) に加えて libsample.so のプロファイルを行うよう hiprof に指示します。 hiprof コマンドはプログラムの計測機構付きバージョン (sample.hiprof) を作成します。 gprof オプション (-numbers) が少なくとも 1 つ指定されているため,hiprof は計測機構付きプログラムを自動的に実行してプロファイル・データ・ファイル (sample.hiout) を作成し,gprof を実行してプロファイルを表示します。 -numbers オプションにより,各プロシージャの開始行番号,ソース・ファイル名,ライブラリ名が表示されます。 これにより,同じ名前の静的プロシージャが複数ある場合にも識別が可能になります。 [例に戻る]

結果のサンプル・プロファイルを例 8-2 に示します。 呼び出しグラフのプロファイルは,そのプロシージャが呼び出す他のプロシージャを含め,あるプロシージャの呼び出しにかかる総コストを概算します。 この概算では,特定のプロシージャの呼び出しには毎回同じ時間がかかると仮定しています。 これは,多くの場合に事実とは異なりますが,呼び出し元が単一の場合には正確な概算になります。

省略時の設定では,hiprof は低頻度のサンプリング手法を使用します。 この手法では,選択されているすべてのライブラリを含め,プログラムが実行するすべてのコードのプロファイルを行うことができます。 また,選択されているすべてのプロシージャ (スレッド関係のシステム・ライブラリを除く) の呼び出しグラフのプロファイルと,ソース行または機械語命令のレベルでの詳細なプロファイル (選択されている場合) も作成します。

例 8-2:  gprof を使用した hiprof の省略時のプロファイル例

% cc -o libsample.so -shared -g1 -O2 add_vector.c mul_by_scalar.c print_it.c
add_vector.c:
mul_by_scalar.c:
print_it.c:
 
% cc -o sample -g1 -O2 profsample.c -L. -lsample -lm
 
% hiprof -numbers -L. -inc libsample.so sample
hiprof: info: instrumenting sample ...
 
hiprof: info: the LD_LIBRARY_PATH environment variable is not defined
hiprof: info: setting LD_LIBRARY_PATH=.:. [1]
hiprof: info: running instrumented program sample.hiprof ...
 
Value = 179804.149985
 
hiprof: info: instrumented program exited with status 0
hiprof: info: displaying profile for sample ...
 
gprof -b -scaled -all -numbers -L. sample.hiprof ./sample.hiout [2]
 
*********************** call-graph profile ******************* [3]
 
granularity: samples per 4 bytes; units: seconds*1e-3; total: 323e-3 seconds
 
                                    called /     total    parents
index  %total   self  descendents   called +      self  name      index
                                    called /     total    children
 
                     2       321         1 /         1    __start [2]
[1]    100.0         2       321         1              main [1] [4]
                   318         0       100 /       100    add_vector [3] [5]
                     3         0         2 /         2    mul_by_scalar [4]
                     0         0         1 /         1    print_it [5]
 
------------------------------------------------------
 
                   318         0       100 /       100    main [1] [6]
[3]     98.5       318         0       100              add_vector [3]
 
------------------------------------------------------
 
                     3         0         2 /         2    main [1]
[4]      0.9         3         0         2              mul_by_scalar [4]
 
------------------------------------------------------
 
                     0         0         1 /         1    main [1]
[5]      0.0         0         0         1              print_it [5]
 
------------------------------------------------------
 
*********************** timing profile section ***************
 
granularity: samples per 4 bytes; units: seconds*1e-3; total: 323e-3 seconds
 
  %   cumulative     self           self/call total/call
total     units     units     calls   seconds   seconds  name
 98.5       318       318       100   3184e-6   3184e-6 add_vector [3]
  0.9       321         3         2   1465e-6   1465e-6 mul_by_scalar [4]
  0.6       323         2         1   1953e-6 323242e-6 main [1]
  0.0       323         0         1         0         0 print_it [5]
 
*********************** index section ************************
Index by function name - 4 entries
 
   [3] add_vector         :"add_vector.c":1
   [1] main               :"profsample.c":12
   [4] mul_by_scalar      :"mul_by_scalar.c":1
   [5] print_it           :"print_it.c":4

  1. LD_LIBRARY_PATH 環境変数は,計測機構付きシェアード・ライブラリ libsample がある作業ディレクトリを指定するよう自動的に設定されます (8.6.4.1 項を参照)。 [例に戻る]

  2. 自動的に生成された gprof コマンド行は,省略時の設定により -scaled オプションを使用します。 このオプションでは,表示対象として選択されたプロシージャの実行時間が短い場合に,プロファイルを CPU サイクルの精度とミリ秒単位で表示できます。 [例に戻る]

  3. gprof の出力は,呼び出しグラフのプロファイル,タイミングのプロファイル,およびインデックス (各プロシージャを識別する簡潔な手段) の 3 つのセクションからなります。 この例では,3 つのセクションはアスタリスク (とセクション名) の行で区切られていますが,この行は gprof が作成する出力にはありません。 呼び出しグラフのプロファイルのセクションでは,プログラムの各ルーチンのサブセクションが破線で区切って示され,最初の欄のインデックス番号によって識別されます。 [例に戻る]

  4. この行は main ルーチンを示します。 このルーチンは,このセクションの右端の欄で最も左に表示されているので,このルーチンが,呼び出しグラフのこの部分の主体であることを示しています。 左端の欄のインデックス番号 [1] は,出力の最後のインデックス・セクションのインデックス番号 [1] に対応します。 2 番目の欄のパーセンテージは,main とその子孫 (この場合は add_vector, mul_by_scalar, および print_it) によって占められている,サブグラフ内の時間の合計を示します。 called 欄の 1 は,main ルーチンが呼び出された回数の合計を示します。 [例に戻る]

  5. この行は,add_vectormain の関係を示します。 add_vector はこのセクションで main の下にあるので,main の子であることがわかります。 分数 100/100 は,add_vector への合計 100 回の呼び出し (分母) のうち,100 回 (分子) が main からのものであることを示します。 [例に戻る]

  6. この行は,mainadd_vector の関係を示します。 main は最後の欄で add_vector の上にあるので,add_vector の親であることがわかります。 [例に戻る]

スレッドのないプログラムでは,hiprof は,そのプログラムが使用したマシン・サイクルまたは発生したページ・フォールトの数をカウントすることもできます。 それぞれの親プロシージャの呼び出しコストが正確に計算されるので,親のコストしか概算できない省略時のモードよりも,呼び出しグラフのプロファイルが格段に有用になります。 また,計測機構付きルーチンの CPU 時間 (短いテストのためにはナノ秒単位) またはページ・フォールトのカウントの報告には,そのルーチンが呼び出す計測機構のないルーチンのカウントの報告が含まれます。 こうしてコストの概算を行って,実行時のオーバヘッドを減らすことができますが,計測機構付きプロシージャが少なくとも数秒ごとに呼び出されない場合には,マシン・サイクルのカウンタがラップするため,注意が必要です。

次の例では,hiprof コマンドの -cycles オプションを使用して,sample プログラムが使用するマシン・サイクルのプロファイルを表示します。

% cc -o libsample.so -shared -g1 -O2 add_vector.c mul_by_scalar.c print_it.c
% cc -o sample -g1 -O2 profsample.c -L. -lsample -lm
% hiprof -cycles -numbers -L. -inc libsample.so sample

結果のサンプル・プロファイルを例 8-3 に示します。

例 8-3:  gprof を使用した hiprof の -cycles プロファイルの例

% cc -o libsample.so -shared -g1 -O2 add_vector.c mul_by_scalar.c print_it.c
add_vector.c:
mul_by_scalar.c:
print_it.c:
 
% cc -o sample -g1 -O2 profsample.c -L. -lsample -lm
 
% hiprof -cycles -numbers -L. -inc libsample.so sample
hiprof: info: instrumenting sample ...
 
hiprof: info: the LD_LIBRARY_PATH environment variable is not defined
hiprof: info: setting LD_LIBRARY_PATH=.:.
hiprof: info: running instrumented program sample.hiprof ...
 
Value = 179804.149985
 
hiprof: info: instrumented program exited with status 0
hiprof: info: displaying profile for sample ...
 
gprof -b -scaled -all -numbers -L. sample ./sample.hiout
 
granularity: cycles; units: seconds*1e-9; total: 362320292e-9 seconds
 
                                    called /     total    parents 
index  %total   self  descendents   called +      self  name    	index
                                    called /     total    children
 
                                                          <spontaneous>
[1]    100.0    893310 361426982         1              __start [1]
                       361371860         1 /         1    main [2]
 
------------------------------------------------------
 
                       361371860         1 /         1    __start [1]
[2]     99.7  36316218 325055642         1              main [2]
                       321107275       100 /       100    add_vector [3]
                         3519530         2 /         2    mul_by_scalar [4]
                          428838         1 /         1    print_it [5]
 
------------------------------------------------------
 
                       321107275       100 /       100    main [2]
[3]     88.6 321107275         0       100              add_vector [3]
 
------------------------------------------------------
 
                         3519530         2 /         2    main [2]
[4]      1.0   3519530         0         2              mul_by_scalar [4]
 
------------------------------------------------------
 
                          428838         1 /         1    main [2]
[5]      0.1    428838         0         1              print_it [5]
 
------------------------------------------------------
 
granularity: cycles; units: seconds*1e-9; total: 362320292e-9 seconds
 
  %   cumulative     self           self/call total/call        
total     units     units     calls   seconds   seconds  name    
 88.6 321107275 321107275       100   3211e-6   3211e-6 add_vector [3]
 10.0 357423492  36316218         1  36316e-6 361372e-6 main [2]
  1.0 360943022   3519530         2   1760e-6   1760e-6 mul_by_scalar [4]
  0.2 361836332    893310         1 893310e-9 362320e-6 __start [1]
  0.1 362265170    428838         1 428838e-9 428838e-9 print_it [5]
 
Index by function name - 11 entries
 
   [1] __start            <sample>
   [3] add_vector         <libsample.so>:"add_vector.c":1
   [2] main               <sample>:"profsample.c":12
   [4] mul_by_scalar      <libsample.so>:"mul_by_scalar.c":1
   [5] print_it           <libsample.so>:"print_it.c":4

8.3.2.1.2    cc コマンドの -pg オプションを使用する方法

cc コマンドの -pg オプションは hiprof と同じサンプリング手法を使用しますが,プログラムは -pg オプションでコンパイルすることにより,計測機構が付加されている必要があります (プログラムのコンパイルには,8.2 節で説明したデバッグおよび最適化のオプションも必要です)。 実行可能ファイルのみのプロファイルが行われ (シェアード・ライブラリは除外される),呼び出しグラフのプロファイルの生成のためにコンパイルされるシステム・ライブラリはほとんどありません。 したがって,hiprof を使用する方がよいかもしれません。 ただし,cc コマンドの -pg オプションと gprof は他のベンダの UNIX システムでも良く似た方法でサポートされているので,これが利点となる場合もあります。 たとえば,次のようにコマンドを実行します。

 
% cc -pg -o sample -g1 -O2 *.c -lm [1]
 
% ./sample [2]
 
% gprof -scaled -b -numbers sample [3]

  1. cc コマンドの呼び出しグラフのプロファイル・オプション -pg は,プログラムの計測機構付きバージョン sample を作成します (コンパイルとリンクの両方のフェーズで -pg オプションを指定する必要があります)。 [例に戻る]

  2. 計測機構付きバージョンのプログラムを実行すると,gprof ツールが使用するプロファイル・データ・ファイル (省略時の名前は gmon.out) が作成されます。 複数のデータ・ファイルで作業する場合についての情報は,8.7 節を参照してください。 [例に戻る]

  3. gprof コマンドは,プロファイル・データ・ファイルから情報を取り出して表示します。 -scaled オプションは,レポートの欄幅を超えることなく,最高の精度が得られる単位で CPU 時間を表示します。 -b オプションは,プロファイル内の各フォールドの説明が表示されないようにします。 [例に戻る]

結果のサンプル・プロファイルを例 8-4 に示します。 gprof ツールは,呼び出しグラフのプロファイルでプロシージャ (そのプロシージャが呼び出す他のプロシージャも含む) を呼び出す際にかかる総コストを概算します。

例 8-4:  gprof を使用した cc -pg プロファイルの例

% cc -pg -o sample -g1 -O2 add_vector.c mul_by_scalar.c print_it.c profsample.c -lm
add_vector.c:
mul_by_scalar.c:
print_it.c:
profsample.c:
 
% ./sample
Value = 179804.149985
 
% gprof -scaled -b -numbers sample
 
granularity: samples per 8 bytes; units: seconds*1e-3; total: 326e-3 seconds
 
                                    called /     total    parents 
index  %total   self  descendents   called +      self  name      index
                                    called /     total    children
 
                     5       321         1 /         1    __start [2]
[1]    100.0         5       321         1              main [1]
                   317         0       100 /       100    add_vector [3]
                     4         0         2 /         2    mul_by_scalar [4]
                     0         0         1 /         1    print_it [5]
 
------------------------------------------------------
 
                   317         0       100 /       100    main [1]
[3]     97.3       317         0       100              add_vector [3]
 
------------------------------------------------------
 
                     4         0         2 /         2    main [1]
[4]      1.2         4         0         2              mul_by_scalar [4]
 
------------------------------------------------------
 
                     0         0         1 /         1    main [1]
[5]      0.0         0         0         1              print_it [5]
 
------------------------------------------------------
 
granularity: samples per 8 bytes; units: seconds*1e-3; total: 326e-3 seconds
 
  %   cumulative     self           self/call total/call        
total     units     units     calls   seconds   seconds  name    
 97.3       317       317       100   3174e-6   3174e-6 add_vector [3]
  1.5       322         5         1   4883e-6 326172e-6 main [1]
  1.2       326         4         2   1953e-6   1953e-6 mul_by_scalar [4]
  0.0       326         0         1         0         0 print_it [5]
 
Index by function name - 4 entries
 
   [3] add_vector         <sample>:"add_vector.c":1
   [1] main               <sample>:"profsample.c":12
   [4] mul_by_scalar      <sample>:"mul_by_scalar.c":1
   [5] print_it           <sample>:"print_it.c":4

8.3.2.2    ソース行または命令の,CPU 時間またはイベントのプロファイル

性能の向上を図るための優れた方法は,プロシージャ・レベルのプロファイルをプログラム全体で行うことから始まります (全体像を得るために呼び出しグラフを付けることもあります) が,個別のソース行および命令の詳細なプロファイルに発展することも多くあります。 この情報を得るには,次のツールを使用します。

8.3.2.2.1    uprofile プロファイラを使用する方法

uprofile プロファイラ ( uprofile(1) を参照) は,サンプリング手法を使用して,各プロシージャ,ソース行,または命令に関連する CPU 時間またはイベント (キャッシュ・ミスなど) のプロファイルを生成します。 サンプリングの頻度は,プロセッサのタイプとサンプリングする統計情報によって異なりますが,CPU 時間でミリ秒のオーダです。 このプロファイラは,アプリケーション・プログラムの修正を全く行うことなく,Alpha CPU に組み込まれているハードウェア・カウンタを使用してこの作業を行います。 uprofile コマンドを引数なしで実行すると,マシンのアーキテクチャ特性に基づいて,特定のマシンでプロファイルを行うことができるすべての種類のイベントのリストが作成されます。 省略時の設定では,マシン・サイクルをプロファイルし,その結果,CPU 時間のプロファイルが作成されます。 次の例では,CPU 時間の上位 90% を使用する命令のプロファイルを表示する方法を示します。

% cc -o sample -g1 -O2 *.c -lm [1]

% uprofile -asm -quit 90cum% sample [2]

結果のサンプル・プロファイルと説明文を例 8-5 に示します。

  1. -g1 オプションと -O2 オプションの詳細については,8.2 節を参照してください。 [例に戻る]

  2. uprofile コマンドは sample プログラムを実行し,性能カウンタのデータをプロファイル・データ・ファイル (省略時の名前は umon.out) に収集します。 prof のオプション (-asm-quit) が指定されているので,uprofile は次に自動的に prof ツールを実行して,プロファイルを表示します。

    -asm オプションは,命令ごとにサイクル (および,指定されている場合は,データ・キャッシュ・ミスなど,その他の CPU 統計情報) のプロファイルを行います。 ここではカウンタ統計情報は指定されていないので,uprofile は各命令の CPU 時間プロファイルを表示します。 -quit 90cum% オプションは,プロファイルの全体の 90% が表示されると,その後の表示を切り捨てます (8.6.3 項を参照)。 -heavy オプションも使用できます。 このオプションは,最も多くの命令を実行した行を報告します。 また,各プロシージャ内のソース行ごとにプロファイルを報告する -lines オプションも使用できます (8.6.2 項を参照)。 [例に戻る]

例 8-5:  prof を使用した uprofile の CPU 時間プロファイルの例

% cc -o sample -g1 -O2 add_vector.c mul_by_scalar.c print_it.c profsample.c -lm
add_vector.c:
mul_by_scalar.c:
print_it.c:
profsample.c:
 
% uprofile -asm -quit 90cum% sample
Value = 179804.149985
Writing umon.out
 
Displaying profile for sample:
 
Profile listing generated Thu Dec  3 10:29:25 1998 with:
   prof -asm -quit 90cum% sample umon.out
 
----------------------------------------------------------------------------
*  -a[sm] using performance counters:                                      *
*    cycles0: 1 sample every 65536 Cycles (0.000164 seconds)               *
*  sorted in descending order by total time spent in each procedure;       *
*  unexecuted procedures excluded                                          *
----------------------------------------------------------------------------
 
Each sample covers 4.00 byte(s) for 0.052% of 0.3123 seconds
 
      millisec      %  cum %      address:line  instruction
 
add_vector (add_vector.c)
           0.0   0.00   0.00  0x120001260:2     addl    zero, a2, a2
           0.0   0.00   0.00  0x120001264:5     bis     zero, zero, t0
           0.0   0.00   0.00  0x120001268:5     ble     a2, 0x12000131c
           0.0   0.00   0.00  0x12000126c:5     subl    a2, 0x3, t1
           0.0   0.00   0.00  0x120001270:5     cmple   t1, a2, t2
           0.0   0.00   0.00  0x120001274:5     beq     t2, 0x1200012f4
           0.0   0.00   0.00  0x120001278:5     ble     t1, 0x1200012f4
           0.0   0.00   0.00  0x12000127c:5     subq    a0, a1, t3
           0.0   0.00   0.00  0x120001280:5     lda     t3, 31(t3)
           0.0   0.00   0.00  0x120001284:5     cmpule  t3, 0x3e, t3
           0.0   0.00   0.00  0x120001288:5     bne     t3, 0x1200012f4
           0.0   0.00   0.00  0x12000128c:5     ldq_u   zero, 0(sp)
          20.2   6.45   6.45  0x120001290:6     ldl     zero, 128(a1)
           1.3   0.42   6.87  0x120001294:6     lds     $f31, 128(a0)
          35.6  11.39  18.26  0x120001298:6     ldt     $f0, 0(a1)
          20.0   6.40  24.66  0x12000129c:6     ldt     $f1, 0(a0)
           9.7   3.10  27.75  0x1200012a0:6     ldt     $f10, 8(a1)
          14.9   4.77  32.53  0x1200012a4:6     ldt     $f11, 8(a0)
          17.4   5.56  38.09  0x1200012a8:6     ldt     $f12, 16(a1)
           7.0   2.26  40.35  0x1200012ac:6     ldt     $f13, 16(a0)
           8.2   2.62  42.97  0x1200012b0:6     ldt     $f14, 24(a1)
          12.9   4.14  47.11  0x1200012b4:6     ldt     $f15, 24(a0)
          24.9   7.97  55.09  0x1200012b8:6     addt    $f1,$f0,$f0
          24.7   7.92  63.01  0x1200012bc:6     addt    $f11,$f10,$f10
          37.8  12.12  75.13  0x1200012c0:6     addt    $f13,$f12,$f12
          39.2  12.54  87.67  0x1200012c4:6     addt    $f15,$f14,$f14
           0.8   0.26  87.93  0x1200012c8:5     addl    t0, 0x4, t0
           0.0   0.00  87.93  0x1200012cc:5     lda     a1, 32(a1)
           8.4   2.68  90.61  0x1200012d0:6     stt     $f0, 0(a0)

比較として,次の例に,EV56 Alpha システムでのデータ・キャッシュ・ミスの上位 90% が発生した命令のプロファイルを表示する方法を示します。

% cc -o sample -g1 -O2 *.c -lm
% uprofile -asm -quit 90cum% dcacheldmisses sample

結果のサンプル・プロファイルを例 8-6 に示します。

例 8-6:  prof を使用した uprofile のデータ・キャッシュ・ミス・プロファイルの例

% uprofile -asm -quit 90cum% dcacheldmisses sample
Value = 179804.149985
Writing umon.out
 
Displaying profile for sample:
 
Profile listing generated Thu Dec  3 10:34:25 1998 with:
   prof -asm -quit 90cum% sample umon.out
 
----------------------------------------------------------------------------
*  -a[sm] using performance counters:                                      *
*    dcacheldmiss: 1 sample every 16384 DCache LD Misses [1]              *
*  sorted in descending order by samples recorded for each procedure;      *
*  unexecuted procedures excluded                                          *
----------------------------------------------------------------------------
 
Each sample covers 4.00 byte(s) for 0.18% of 550 samples [2]
 
       samples      %  cum %      address:line  instruction
 
add_vector (add_vector.c)
           0.0   0.00   0.00  0x120001260:2     addl    zero, a2, a2
           0.0   0.00   0.00  0x120001264:5     bis     zero, zero, t0
           0.0   0.00   0.00  0x120001268:5     ble     a2, 0x12000131c
           0.0   0.00   0.00  0x12000126c:5     subl    a2, 0x3, t1
           0.0   0.00   0.00  0x120001270:5     cmple   t1, a2, t2
           0.0   0.00   0.00  0x120001274:5     beq     t2, 0x1200012f4
           0.0   0.00   0.00  0x120001278:5     ble     t1, 0x1200012f4
           0.0   0.00   0.00  0x12000127c:5     subq    a0, a1, t3
           0.0   0.00   0.00  0x120001280:5     lda     t3, 31(t3)
           0.0   0.00   0.00  0x120001284:5     cmpule  t3, 0x3e, t3
           0.0   0.00   0.00  0x120001288:5     bne     t3, 0x1200012f4
           0.0   0.00   0.00  0x12000128c:5     ldq_u   zero, 0(sp)
           1.0   0.18   0.18  0x120001290:6     ldl     zero, 128(a1)
           3.0   0.55   0.73  0x120001294:6     lds     $f31, 128(a0)
          62.0  11.27  12.00  0x120001298:6     ldt     $f0, 0(a1) [3]
          64.0  11.64  23.64  0x12000129c:6     ldt     $f1, 0(a0)
           8.0   1.45  25.09  0x1200012a0:6     ldt     $f10, 8(a1)
          47.0   8.55  33.64  0x1200012a4:6     ldt     $f11, 8(a0)
          13.0   2.36  36.00  0x1200012a8:6     ldt     $f12, 16(a1)
          38.0   6.91  42.91  0x1200012ac:6     ldt     $f13, 16(a0)
          15.0   2.73  45.64  0x1200012b0:6     ldt     $f14, 24(a1)
          51.0   9.27  54.91  0x1200012b4:6     ldt     $f15, 24(a0)
          49.0   8.91  63.82  0x1200012b8:6     addt    $f1,$f0,$f0
         142.0  25.82  89.64  0x1200012bc:6     addt    $f11,$f10,$f10
          13.0   2.36  92.00  0x1200012c0:6     addt    $f13,$f12,$f12

  1. "1 sample every 16384" というサンプリング・レートは,プロファイルに示されるサンプルがそれぞれ 16384 回のデータ・キャッシュ・ミスの後に発生したことを意味しますが,その命令で発生したすべてのサンプルが示されるわけではありません。 [例に戻る]

  2. データ・キャッシュ・ミスの数ではなく,サンプルの総数が示されます。 [例に戻る]

  3. 1 つの命令に記録されたサンプルの数を示します。 これは,統計的にデータ・キャッシュ・ミスの比率を暗示します。 [例に戻る]

uprofile プロファイル手法には,実行時のオーバヘッドが非常に小さいという長所があります。 また,個々の命令またはソース行を実行する手間がかかりますが,これにより得られる詳細情報は,プロシージャ内のどのオペレーションがプログラムの実行速度を遅くしているのかを正確に識別するために不可欠です。

uprofile には,次の短所があります。

8.3.2.2.2    hiprof プロファイラを使用する方法

すでに説明したとおり,hiprof コマンドの省略時の PC サンプリング手法でも,1 ミリ秒弱のサンプリング頻度で,uprofile と同様に CPU 時間プロファイルを生成できます。 呼び出しのカウントが性能に影響するため,このプロファイルはあまり正確にはなりませんが,次のような長所があります。

次の例では,hiprof コマンドの -lines オプションを使用して,各ソース行が使用した CPU 時間のプロファイルをプロシージャごとに分けて表示します。

% cc -o libsample.so -shared -g1 -O2 add_vector.c mul_by_scalar.c print_it.c
% cc -o sample -g1 -O2 profsample.c -L. -lsample -lm
% hiprof -lines -numbers -L. -inc libsample.so sample

結果のサンプル・プロファイルを例 8-7 に示します。

例 8-7:  hiprof -lines による PC サンプリング・プロファイルの例

% cc -o libsample.so -shared -g1 -O2 add_vector.c mul_by_scalar.c print_it.c
add_vector.c:
mul_by_scalar.c:
print_it.c:
 
% cc -o sample -g1 -O2 profsample.c -L. -lsample -lm
 
% hiprof -lines -numbers -L. -inc libsample.so sample
hiprof: info: instrumenting sample ...
 
hiprof: info: the LD_LIBRARY_PATH environment variable is not defined
hiprof: info: setting LD_LIBRARY_PATH=.:.
hiprof: info: running instrumented program sample.hiprof ...
 
Value = 179804.149985
 
hiprof: info: instrumented program exited with status 0
hiprof: info: displaying profile for sample ...
 
gprof -b -scaled -all -lines -numbers -L. sample.hiprof ./sample.hiout
 
Milliseconds per source line, in source order within functions
 
procedure (file)                           line bytes   millisec      %  cum %
 
add_vector (add_vector.c)                     2    52        0.0   0.00   0.00
                                              5    92        1.0   0.30   0.30
                                              6    92      318.4  98.19  98.49
                                              8     4        0.0   0.00  98.49
mul_by_scalar (mul_by_scalar.c)               2    52        0.0   0.00  98.49
                                              5    72        0.0   0.00  98.49
                                              6    64        3.9   1.20  99.70
                                              8     4        0.0   0.00  99.70
main (profsample.c)                           9    32        0.0   0.00  99.70
                                             12   128        0.0   0.00  99.70
                                             16     8        0.0   0.00  99.70
                                             19    32        0.0   0.00  99.70
                                             20    36        0.0   0.00  99.70
                                             21    16        0.0   0.00  99.70
                                             22    24        0.0   0.00  99.70
                                             24     4        0.0   0.00  99.70
                                             25    36        0.0   0.00  99.70
                                             26    16        0.0   0.00  99.70
                                             27    28        1.0   0.30 100.00
                                             28    20        0.0   0.00 100.00
                                             29    40        0.0   0.00 100.00
                                             30     4        0.0   0.00 100.00
                                             31    20        0.0   0.00 100.00
                                             32     4        0.0   0.00 100.00
                                             33    20        0.0   0.00 100.00
                                             34    56        0.0   0.00 100.00
 

8.3.2.2.3    cc コマンドの -p オプションを使用する方法

cc コマンドの -p オプションは,低頻度のサンプリング手法を使用して CPU 時間のプロファイルを生成します。 このプロファイルは uprofile の場合と似ていますが,統計的に精度が低くなります。 しかし,-p オプションには次の長所があります。

-p オプションを使用してプログラムを再リンクする必要がありますが,cc コマンドの -g1 オプションを使用した場合など,元のコンパイルがある程度のデバッグ・レベルを使用して行われている場合は,ソースからコンパイルし直す必要はありません (8.2 節を参照)。 たとえば,プログラムの個々のソース行とプロシージャのプロファイルを行うには,次のようにコマンドを実行します (密度の高いサンプル配列を作成するのに十分な時間プログラムが実行される場合)。

% cc -p -o sample -g1 -O2 *.c -lm [1]

% setenv PROFFLAGS '-all -stride 1' [2]

% ./sample [3]

% prof -all -proc -heavy -numbers sample [4]

  1. cc コマンドの PC サンプル・プロファイル・オプション -p は,計測機構付きバージョンのプログラム sample を作成します。 [例に戻る]

  2. PROFFLAGS 環境変数で指定された -all オプションにより,すべてのシェアード・ライブラリのプロファイルが要求されます (8.6.4 項を参照)。 その結果,CPU 時間の第 2 位の使用者として sqrt (libm.so から) がプロファイル内に表示されます。 変数は,計測機構付きバージョンのプログラムを実行する前にセットする必要があります。

    prof-heavy オプションを使用したソース行ごとのプロファイルを正確にするため,PROFFLAGS-stride 1 オプションにより,各命令に別々のカウンタを使用するよう要求します。 [例に戻る]

  3. 計測機構付きバージョンのプログラムを実行すると,prof ツールが使用する PC サンプリング・データ・ファイル (省略時の名前は mon.out) が作成されます。 複数のデータ・ファイルを使用した作業については,8.7 節を参照してください。 [例に戻る]

  4. prof ツール ( prof(1)を参照) は PC サンプリング・データ・ファイルを使用してプロファイルを作成します。 この手法はプログラム・カウンタの周期的なサンプリングによって機能するため,同じプログラムを複数回プロファイルすると,出力が異なる場合があります。

    この例のように prof を手動で実行する場合は,プロファイルの表示に含めるシェアード・ライブラリを指定することができます。 -all オプションを指定すると,prof はすべてのライブラリを表示します (8.6.4 項を参照)。 -proc[edures] オプションを指定すると,各プロシージャで実行された命令とプロシージャへの呼び出しがプロファイルされます。 -heavy オプションを指定すると,最も多くの命令を実行した行が報告されます。 また,-lines を指定すると行ごとのプロファイルが,-asm を指定すると命令ごとのプロファイルが,どちらもプロシージャごとに分けて表示されます。 [例に戻る]

結果のサンプル・プロファイルを例 8-8 に示します。

例 8-8:  prof を使用した cc -p プロファイルの例

% cc -p -o sample -g1 -O2 add_vector.c mul_by_scalar.c print_it.c profsample.c -lm
add_vector.c:
mul_by_scalar.c:
print_it.c:
profsample.c:
 
% setenv PROFFLAGS "-all -stride 1"
 
% ./sample
Value = 179804.149985
 
% prof -all -proc -heavy -numbers sample
Profile listing generated Mon Feb 23 15:33:07 1998 with: 
   prof -all -proc -heavy -numbers sample  
 
----------------------------------------------------------------------------
*  -p[rocedures] using pc-sampling;                                        *
*  sorted in descending order by total time spent in each procedure;       *
*  unexecuted procedures excluded                                          *
----------------------------------------------------------------------------
 
Each sample covers 4.00 byte(s) for 0.25% of 0.3955 seconds 
 
%time     seconds  cum %   cum sec  procedure (file)     
 
 93.1      0.3682   93.1      0.37 add_vector (<sample>:"add_vector.c":1)
  5.4      0.0215   98.5      0.39 sqrt (<libm.so>)
  1.0      0.0039   99.5      0.39 mul_by_scalar (<sample>:"mul_by_scalar.c":1)
  0.5      0.0020  100.0      0.40 main (<sample>:"profsample.c":12)
 
 
----------------------------------------------------------------------------
*  -h[eavy] using pc-sampling;                                             *
*  sorted in descending order by time spent in each source line;           *
*  unexecuted lines excluded                                               *
----------------------------------------------------------------------------
 
Each sample covers 4.00 byte(s) for 0.25% of 0.3955 seconds 
 
procedure (file)                           line bytes   millisec      %  cum %
 
add_vector (add_vector.c)                     6    80      363.3  91.85  91.85
add_vector (add_vector.c)                     5    96        4.9   1.23  93.09
mul_by_scalar (mul_by_scalar.c)               6    60        3.9   0.99  94.07
main (profsample.c)                          20    36        2.0   0.49  94.57
 

8.3.2.2.4    pixie プロファイラを使用する方法

pixie ツール ( pixie(1) を参照) でも,ソース行と命令 (シェアード・ライブラリを含む) のプロファイルを行うことができますが,cycles のカウントの表示はマシン・サイクルではなく,実行された命令のカウントの報告であるため,注意が必要です。 -truecycles 2 オプションにより,キャッシュによるメモリ・アクセスがすべて満足された場合に使用されるサイクルの数を概算することができます。 ただし,この概算を正確なものにするのに十分なだけプログラムがデータをキャッシュできる場合はほとんどなく,また,この方法で完全にシミュレートできるのは Alpha EV4 および EV5 ファミリだけです。 たとえば,次のようにコマンドを実行します。

% cc -o sample -g1 -O2 *.c -lm [1]

% pixie -all -proc -heavy -quit 5 sample [2]

  1. -g1 オプションと -O2 オプションについては,8.2 節を参照してください。 [例に戻る]

  2. pixie コマンドは,計測機構付きバージョンのプログラム (sample.pixie) と命令アドレス・ファイル (sample.Addrs) を作成します。 prof のオプション (-proc,-heavy,-quit) が指定されているので,pixie は計測機構付きプログラムを自動的に実行して命令カウント・ファイル (sample.Counts) を作成し,次に .Addrs ファイルと .Counts ファイルを入力として使用して prof を実行し,プロファイルを表示します。

    -all オプションにより,シェアード・ライブラリのプロファイルが要求されます。 pixie プロファイルにはシェアード・ライブラリを含めることができますが,システム・ライブラリ (sqrt 関数が含まれる libm.so など) にはソース行番号がないので,-heavy オプションの行ごとのプロファイルには含まれません。 また,静的プロシージャには proc_at... という名前が作成されて与えられます。

    -heavy オプションにより,最も多くの命令を実行した行が報告されます。 -proc[edures] オプションにより,各プロシージャで実行された命令とプロシージャへの呼び出しのプロファイルが行われます。 -quit 5 オプションにより,各モード (-heavy-proc[edures]) で 5 行以降の報告が切り捨てられます。 [例に戻る]

結果のサンプル・プロファイルを例 8-9 に示します。

例 8-9:  prof を使用した pixie プロファイルの例

% cc -o sample -g1 -O2 add_vector.c mul_by_scalar.c print_it.c profsample.c -lm
add_vector.c:
mul_by_scalar.c:
print_it.c:
profsample.c:
 
% pixie -all -proc -heavy -quit 5 sample
pixie: info: instrumenting sample ...
 
pixie: info: the LD_LIBRARY_PATH environment variable is not defined
pixie: info: setting LD_LIBRARY_PATH=.
pixie: info: running instrumented program sample.pixie ...
 
Value = 179804.149985
 
pixie: info: instrumented program exited with status 0
pixie: info: displaying profile for sample ...
 
Profile listing generated Mon Feb 23 15:33:55 1998 with:
   prof -pixie -all -procedures -heavy -quit 5 sample ./sample.Counts 
 
----------------------------------------------------------------------------
*  -p[rocedures] using basic-block counts;                                 *
*  sorted in descending order by the number of cycles executed in each     *
*  procedure; unexecuted procedures are excluded                           *
----------------------------------------------------------------------------
 
69089823 cycles (0.1727 seconds at 400.00 megahertz)
 
    cycles %cycles  cum %  seconds     cycles  bytes procedure (file)
                                        /call  /line
 
  60001400   86.85  86.85   0.1500     600014     48 add_vector (add_vector.c)
   7100008   10.28  97.12   0.0178         72      ? sqrt (<libm.so>)
   1301816    1.88  99.01   0.0033    1301816     27 main (profsample.c)
    675020    0.98  99.98   0.0017     337510     36 mul_by_scalar (mul_by_scalar.c)
       854    0.00  99.98   0.0000        854      ? __cvtas_t_to_a (<libc.so>)
 
----------------------------------------------------------------------------
*  -p[rocedures] using invocation counts;                                  *
*  sorted in descending order by number of calls per procedure;            *
*  unexecuted procedures are excluded                                      *
----------------------------------------------------------------------------
 
100504 invocations total
 
     calls  %calls    cum%    bytes procedure (file)
 
    100000   99.50   99.50      820 sqrt (<libm.so>)
       100    0.10   99.60      192 add_vector (add_vector.c)
        39    0.04   99.64      164 proc_at_0x3ff815bc1e0 (<libc.so>)
        38    0.04   99.67      144 proc_at_0x3ff815bc150 (<libc.so>)
        38    0.04   99.71       16 proc_at_0x3ff815bc140 (<libc.so>)
 
----------------------------------------------------------------------------
*  -h[eavy] using basic-block counts;                                      *
*  sorted in descending order by the number of cycles executed in each     *
*  line; unexecuted lines are excluded                                     *
----------------------------------------------------------------------------
 
procedure (file)                           line bytes     cycles      %  cum %
 
add_vector (add_vector.c)                     6    92   45000000  65.13  65.13
add_vector (add_vector.c)                     5    92   15001200  21.71  86.85
main (profsample.c)                          20    36     600003   0.87  87.71
main (profsample.c)                          22    24     600000   0.87  88.58
mul_by_scalar (mul_by_scalar.c)               6    64     487500   0.71  89.29

-procedures プロファイルには,呼び出しカウントのプロファイルが含まれます。

オプションとして dxprof コマンドを使用すると,pixie または ccコマンドの -p オプションにより収集されたプロファイルがグラフィカル表示されます。

実行可能ファイル sample について prof -pixstats コマンドを実行して,演算コードの頻度,インターロック,ミニプロファイルなどの詳細な報告を生成することもできます。 詳細については, prof(1) を参照してください。

8.4    システム・リソース使用の最小化

この節では,アプリケーションによるシステム・リソースの使用を最小限に抑えるための手法とツールについて説明します。

8.4.1    手法

ここまでに説明した手法では,アプリケーションによる CPU の使用状況だけを改善できます。 コンピュータ・システムのその他のコンポーネント (ヒープ・メモリ,ディスク・ファイル,ネットワーク接続など) のアプリケーションによる使用状況を効率化することにより,さらに性能を向上できます。

リソース使用状況を改善するための処理の最初のフェーズは,CPU のプロファイルと同様に,メモリの使用量,データ I/O,ディスク・スペース,経過時間などを監視することです。 次に,コンピュータのスループットを増加または調整して,コンピュータ・リソースの使用状況を改善できるようプログラムあるいはプログラムの設計を調整します。 たとえば,次のような調整を行います。

Tru64 UNIX システムの解析とチューニングについての広範な説明は,『システムの構成とチューニング』を参照してください。

8.4.2    ツールと例

ここでは,システム・モニタと Third Degree ツールを使用して,システム・リソースの使用を最小限に抑える方法を説明します。

8.4.2.1    システム・モニタ

Tru64 UNIX ベースのシステム・コマンド ps uswapon -s,および vmstat3 を使用すると,現在のアクティブ・プロセスのシステム・リソース (CPU 時間,物理メモリと仮想メモリ,スワップ領域,ページ・フォールトなど) の使用状況を表示できます。 詳細については, ps(1), swapon(8), および vmstat(3) を参照してください。

オプションとして pview コマンドを使用すると,アプリケーションを構成するプロセスについての同様の情報がグラフィカル表示されます。 pview(1) を参照してください。

Tru64 UNIX システムの time コマンドとコマンド・シェルを使用すると,プログラムとその子孫の合計の経過時間と CPU 時間を簡単に測定できます。 time(1) を参照してください。

Performance Manager は,システム性能の監視と管理を行うためのオプションのツールで,グラフィカル・インタフェースを備えています。 pmgr(8X) を参照してください。

関連ツールの詳細については,『システムの構成とチューニング』を参照してください。

8.4.2.2    ヒープ・メモリの解析

Third Degree ツール ( third(1) を参照) は,Third Degree のメモリ使用チェッカでプログラムを計測し,それを実行して,検出したリークのログをプログラムの終了時に表示することにより,プログラムにおけるヒープ・メモリのリークを報告します。 たとえば,次のようにコマンドを実行します。

% cc -o sample -g -non_shared *.c -lm [1]

% third -display sample [2]

  1. Thrid Degree を使用する場合には,通常は完全なデバッグ情報 (-g オプションでコンパイル) を利用できることが望ましいのですが,完全な情報が利用できない場合,レポートはソース・レベルではなく機械語レベルになります。 メモリ・リークをチェックするだけの場合は,-g1 オプションが適しています。 [例に戻る]

  2. third コマンドは,プログラムの計測機構付きバージョン (sample.third) を作成します。 -display オプションが指定されているため,third は作成した計測機構付きプログラムを自動的に実行してログ・ファイル (sample.3log) を作成し,次に more を実行してログ・ファイルを表示します。 [例に戻る]

結果のサンプル・ログ・ファイルを例 8-10 に示します。

例 8-10:  third ログ・ファイルの例

cc -o sample -g -non_shared add_vector.c mul_by_scalar.c print_it.c profsample.c -lm
add_vector.c:
mul_by_scalar.c:
print_it.c:
profsample.c:
third -display sample
third: info: instrumenting sample ...
 
third: info: running instrumented program sample.third ...
 
Value = 179804.149985
 
third: info: instrumented program exited with status 0
third: info: error log for sample ...
 
more ./sample.3log 
Third Degree version 5.0
sample.third run by jpx on frumpy.abc.dec.com at Mon Jun 21 16:59:50 1999
 
//////////////////////////////  Options  //////////////////////////////
-----------------------------------------------------------------------
 
-----------------------------------------------------------------------
 
------------------------------------------------------------------------
------------------------------------------------------------------------
New blocks in heap after program exit
 
Leaks - blocks not yet deallocated but apparently not in use:
 * A leak is not referenced by static memory, active stack frames,
   or unleaked blocks, though it may be referenced by other leaks.
 * A leak "not referenced by other leaks" may be the root of a leaked tree.
 * A block referenced only by registers, unseen thread stacks, mapped memory,
   or uninstrumented library data is falsely reported as a leak. Instrumenting
   shared libraries, if any, may reduce the number of such cases.
 * Any new leak lost its last reference since the previous heap report, if any.
 
A total of 800000 bytes in 1 leak were found:
 
800000 bytes in 1 leak (including 1 not referenced by other leaks) created at:
    malloc                         sample
    main                           sample, profsample.c, line 19
    __start                        sample
 
Objects - blocks not yet deallocated and apparently still in use:
 * An object is referenced by static memory, active stack, or other objects.
 * A leaked block may be falsely reported as an object if a pointer to it
   remains when a new stack frame or heap block reuses the pointer's memory.
   Using the option to report uninitialized stack and heap may avoid such cases.
 * Any new object was allocated since the previous heap report, if any.
 
A total of 0 bytes in 0 objects were found:
 
------------------------------------------------------------------------
------------------------------------------------------------------------
                memory layout at program exit
                           heap     933888 bytes [0x140012000-0x1400f6000]
                          stack     819504 bytes [0x11ff37ed0-0x120000000]
                    sample data      66464 bytes [0x140000000-0x1400103a0]
                    sample text     802816 bytes [0x120000000-0x1200c4000]
 
 
=============================================================================

省略時の設定では,Third Degree はメモリ・リークのプロファイルを行い,オーバヘッドはほとんどありません。

プログラムの起動時やシャットダウン時ではなく,通常の動作中に発生したリークのみを調べたい場合は,以前に報告されなかったリークを調べるための場所を追加指定できます。 たとえば,次のようにしてシャットダウン前のリーク報告にこの情報を含めます。

% third -display -after startup -before shutdown sample

Thrid Degree ではまた,プログラムの正確さや性能に影響を及ぼすさまざまな種類のバグを検出できます。 デバッグとリーク検出の詳細については,第 7 章を参照してください。

オプションとして dxheap コマンドを使用すると,Third Degree のヒープとバグのレポートがグラフィカル表示されます。 dxheap(1) を参照してください。

オプションとして mview コマンドを使用すると,時間の経過に伴うヒープの使用状況の解析がグラフィカル表示されます。 こうしてプログラムのヒープを表示すると,大量のリークやメモリの浪費などの望ましくない傾向の存在を (原因ではないとしても) はっきりと示すことができます。 mview(1) を参照してください。

8.5    テスト・ケースの重要性の確認

この節では,テスト・ケースの重要性を確認するための手法とツールについて説明します。

8.5.1    手法

これまでに説明したプロファイル手法のほとんどは,性能が重視される場面で実行されるプログラムの一部について,プロファイルと最適化または調整を部分的に行う場合にのみ効果があります。 テスト実行のプロファイルでは,ほとんどの場合,使用するデータを慎重に選択すれば十分ですが,1 組のテストで実行されたコードと実行されなかったコードを定量的に解析したい場合もあります。

8.5.2    ツールと例題

pixie コマンドの -t[estcoverage] オプションは,テストで実行されなかったコード行を報告します。 たとえば,次のようにコマンドを実行します。

% cc -o sample -g1 -O2 *.c -lm
% pixie -t sample

同様に,-zero オプションは,一度も実行されなかったプロシージャの名前を報告します。 逆に,pixie-p[rocedure],-h[eavy],および -a[sm] オプションは,実行されたプロシージャ,ソース行,および命令を報告します。

典型的なシナリオを作成するためにテストを複数回実行する必要がある場合は,1 組のプロファイル・データ・ファイルに prof コマンドを単独で実行します。 たとえば,次のようにします。

% cc -o sample -g1 -O2 *.c -lm [1]

% pixie -pids sample [2]

% ./sample.pixie [3]
% ./sample.pixie 

% prof -pixie -t sample sample.Counts.* [4]

  1. -g1 オプションと -O2 オプションの詳細については,8.2 節を参照してください。 [例に戻る]

  2. pixie コマンドはプログラムの計測機構付きバージョン (sample.pixie) と命令アドレス・ファイル (sample.Addrs) を作成します。 -pids オプションは,作成したプロファイル・データ・ファイルの名前に,計測機構付きバージョンのプログラムのテスト実行のプロセス ID (item 3) を追加して,一回の実行ごとに別々のファイルが残るようにします。 複数のデータ・ファイルを使用した作業の詳細については,8.7 節を参照してください。 [例に戻る]

  3. 計測機構付きプログラムを 2 回実行 (通常は異なる入力データを使用) して,sample.Counts.pid という名前の 2 つのプロファイル・データ・ファイルを作成します。 [例に戻る]

  4. -pixie オプションは,省略時の PC サンプリング・モードではなく pixie モードを使用するよう prof に指示します。 prof ツールは,sample.Addrs ファイルと 2 つの sample.Counts.pid ファイルを使用して,2 回の実行結果からプロファイルを作成します。 [例に戻る]

8.6    表示するプロファイル情報の選択

アプリケーションのサイズおよび指定したプロファイルのタイプによっては,プロファイラが生成する出力の量が非常に大きくなる場合があります。 しかし,アプリケーションの特定の一部分に関するデータのみをプロファイルしたい場合も多くあります。 ここでは,適切な情報を選択するための方法について説明します。 次のオプションを使用します。

prof オプションと gprof オプションの多くは類似した機能を実行し,類似した名前と構文を持っています。 ここでは prof オプションの例を示します。 詳細については, hiprof(1)pixie(1)uprofile(1)prof(1)gprof(1) を参照してください。

monitor ルーチンを使用したプロファイルの制御については,8.9 節を参照してください。

8.6.1    プロファイルの表示を特定プロシージャのみに制限する

prof コマンドの -only オプションを使用すると,指定したプロシージャだけのプロファイル情報が表示されます。 このオプションは,コマンド行に複数回使用できます。 たとえば,次のようにコマンドを実行します。

% pixie -only mul_by_scalar -only add_vector sample

-exclude オプションを使用すると,指定したプロシージャ以外のすべてのプロシージャのプロファイル情報が表示されます。 このオプションは,コマンド行に複数回使用できます。 同じコマンド行に -only オプションと -exclude オプションを一緒に使用することはできません。

prof プロファイル・オプションの多くは,出力をパーセンテージで表示します。 たとえば,合計の実行時間に対する特定のプロシージャの実行時間をパーセンテージで示す場合などがあります。

省略時の設定では,-only オプションおよび -exclude オプションを使用すると,プロシージャがリストから省かれている場合でも,prof はアプリケーションのすべてのプロシージャに基づいてパーセンテージを計算します。 -Only および -Exclude オプションを使用すると,この動作を変更することができます。 -Only および -Exclude オプションは,-only および -exclude と同じ働きをしますが,リストに含まれるプロシージャだけに基づいて prof が計算を行うようにします。

-totals オプションを -procedures-invocations のリストとともに使用すると,オブジェクトの個々のプロシージャではなく,オブジェクト・ファイル全体の累計の統計情報が表示されます。

8.6.2    ソース行ごとのプロファイル情報の表示

profgprof の -heavy および -lines オプションを使用すると,マシン・サイクル,命令,ページ・フォールト,キャッシュ・ミスなどの数がアプリケーションのソース行ごとに表示されます。 -asm オプションでは,これらの情報が命令ごとに表示されます。

-heavy オプションでは,ソース行ごとにエントリが表示されます。 エントリは,その行について最も使用量の多いものから順に並べられます。 -heavy オプションを使用すると多数のエントリが表示されることが多いので,-quit-only-exclude オプションのいずれかを使用して,扱いやすい量に出力を減らすこともできます (8.6.3 項を参照)。

-lines オプションは -heavy オプションに似ていますが,出力のソート順序が異なります。 このオプションでは,個々のプロシージャの行を,ソース・ファイル内での出現順に表示します。 一度も実行されなかった行も表示されます。 プロシージャそのものは,合計使用量の多いものから順に並べられます。

8.6.3    行ごとのプロファイル表示の制限

-quit オプションを使用すると,表示されるプロファイル出力の量が制限されます。 このオプションは,-procedures-heavy,および -lines プロファイル・モードからの出力に影響を及ぼします。

-quit オプションには,次の 3 つの形式があります。

-quit N N 行より後のリストを切り捨てる。
-quit N% 表示が合計の N% より少ない最初の行より後のリストを切り捨てる。
-quit Ncum% 累計が全体の N% に達した行より後のリストを切り捨てる。

同一のコマンド行に複数のモードを指定した場合,-quit オプションは各モードの出力に影響を及ぼします。 次のコマンドは,消費時間が上位 20 個のプロシージャと消費時間が上位 20 個のソース行のみを表示します。

% pixie -procedures -heavy -quit 20 sample

合計は,プロファイル・モードによって,時間の合計,実行された命令の合計数,呼び出しカウントの合計のいずれかに相当します。

8.6.4    プロファイル情報にシェアード・ライブラリを含める

hiprofpixiethirdprofgprof のいずれかのコマンドを使用する場合は,次のオプションにより,プログラムが使用するシェアード・ライブラリのプロファイル情報を選択して表示することができます。

たとえば,次のコマンドは user1.so 以外のすべてのシェアード・ライブラリのプロファイル情報を表示します。

% prof -all -excobj user1.so sample

cc コマンドの -p オプションを使用して PC サンプリング・プロファイルを取得する場合は,PROFFLAGS 環境変数を使用して,計測機構付きバージョンのプログラムの実行時にシェアード・ライブラリのプロファイル情報を含めるか,または除外するかを指定できます (例 8-8 を参照)。 PROFFLAGS 変数には -all-incobj,および excobj オプションを指定できます。

シェアード・ライブラリに固有の情報については,8.6.4.1 項を参照してください。

8.6.4.1    計測機構付きシェアード・ライブラリの位置の指定

LD_LIBRARY_PATH 環境変数を使用すると,ローダに対して,計測機構付きシェアード・ライブラリを探す位置を指定することができます。

省略時の設定では,hiprofpixie,または third を実行すると,LD_LIBRARY_PATH 変数は作業ディレクトリを指すよう自動的に設定されます。 任意のディレクトリを指定するように,この変数を設定することができます。 次に C シェルの例を示します。

% setenv LD_LIBRARY_PATH "my_inst_libraries"

8.7    プロファイル・データ・ファイルのマージ

プロファイルするプログラムがかなり複雑な場合は,プロファイルの正確な像を得るため,異なる入力でプログラムを複数回実行することがあります。 どのプロファイル・ツールでも,プログラムの複数回の実行から得られたプロファイル・データをマージすることができます。 ただし,計測機構付きプログラムが省略時の動作で既存のデータ・ファイルを上書きする場合は,まず,その動作を無効にする必要があります。 8.7.1 項ではその方法について説明し,8.7.2 項ではデータ・ファイルをマージする方法について説明します。

8.7.1    データ・ファイルの命名規則

プロファイル・データ・ファイルの省略時の名前は,それを作成するのに使用したツールによって異なります。

ツール プロファイル・データ・ファイルの省略時の名前
hiprof program.hiout
pixie program.Counts (program.Addrs ファイルとともに使用)
uprofile umon.out
cc -p mon.out
cc -pg gmon.out

省略時の設定では,複数のプロファイルを実行すると,作業ディレクトリ内の既存のデータ・ファイルは実行のたびに上書きされます。 どのツールにもデータ・ファイルの名称変更オプションがあるので,各実行時にファイルを保存することができます。 hiprofpixie,および uprofile コマンドには,次のオプションがあります。

-dirname path データ・ファイルを作成するディレクトリを指定する。
-pids 計測機構付きプログラムの実行のプロセス ID をデータ・ファイル名に追加する。

たとえば,次のコマンド・シーケンスでは,sample.pid.hiout 形式の 2 つのデータ・ファイルがサブディレクトリ profdata に作成されます。

% hiprof -dir profdata -pids sample
% ./sample
% ./sample

次に,gprof コマンドを使用するときにワイルドカードを指定して,ディレクトリ内のプロファイル・データ・ファイルをすべて含めることができます。

% gprof -b sample profdata/*

プロファイル・オプション cc -p または cc -pg を使用する場合は,PROFFLAGS 環境変数を (計測機構付きプログラムを実行する前に) 設定する必要があります。 たとえば,次のコマンド・シーケンスでは,pid.sample 形式の 2 つのデータ・ファイルがサブディレクトリ profdata に作成されます (C シェルの例)。

% cc -pg -o sample -g1 -O2 *.c -lm
% setenv PROFFLAGS "-dir profdata -pids"
% ./sample
% ./sample

PROFFLAGS 環境変数は,プログラムの実行中に,プログラムのプロファイルの動作に影響を及ぼしますが,ポストプロセッサ profgprof には影響を与えません。 PROFFLAGS にヌル文字列を設定すると,プロファイルは行われません。

ファイルの命名規則の詳細については,ツールのリファレンス・ページを参照してください。 マルチスレッド・プログラムのファイル命名規則については,8.8 節を参照してください。

8.7.2    データ・ファイルのマージ手法

プログラムを複数回実行し,複数のプロファイル・データ・ファイルを作成した後,これらのファイルの平均に基づいてプロファイル情報を表示することができます。

ポストプロセッサ prof または gprof を,使用するプロファイル手法に応じて使い分けます。

プロファイル・ツール ポストプロセッサ
cc -puprofile,または pixie prof
cc -pg,または hiprof gprof

マージ手法の 1 つは,各データ・ファイルの名前をコマンド行に明示的に指定することです。 たとえば,次のコマンドでは,hiprof を使用して生成した 2 つのプロファイル・データ・ファイルのプロファイル情報を表示します。

% gprof sample sample.1510.hiout sample.1522.hiout

しかし,多くの異なるプロファイル・データ・ファイルを追跡することが困難な場合があります。 そのため,profgprof では,複数のデータ・ファイルをまとめて 1 つのファイルにマージする -merge オプションを提供しています。 profpixie モードで動作する場合 (prof -pixie),-merge オプションは .Counts ファイルを結合します。 prof が PC サンプリング・モードで動作する場合は,-merge オプションは mon.out や他のプロファイル・データ・ファイルを結合します。

次の例では,2 つのプロファイル・データ・ファイルを total.out という名前の 1 つのデータ・ファイルにマージします。

% prof -merge total.out sample 1773.sample 1777.sample

この後,通常の mon.out ファイルを使用する場合と同様に,結合されたファイルを使用してプロファイル・データを表示できます。

% prof -procedures sample total.out

-pixie モードの場合も,マージ処理は類似しています。 実行可能ファイル名,.Addrs ファイル,およびそれぞれの .Counts ファイルを指定します。 たとえば,次のようにコマンドを実行します。

% prof -pixie -merge total.Counts a.out a.out.Addrs \
  a.out.Counts.1866 a.out.Counts.1868

8.8    マルチスレッド・アプリケーションのプロファイル

注意

予想される論理および性能上の問題についてマルチスレッドのアプリケーションを解析するには,Visual Threads を使用できます。 Visual Threads は,「Tru64 UNIX Associated Products Volume 1」CD-ROM に含まれています。 Visual Threads は,POSIX Threads Library アプリケーションと Java アプリケーションに使用できます。 dxthreads(1) を参照してください。

マルチスレッド・アプリケーションのプロファイルは,スレッドなしのアプリケーションのプロファイルと本質的に同じです。 ただし,マルチスレッド・アプリケーションをプロファイルするには,cc コマンドの定義に従い,-pthread または -threads オプションを使用して,プログラムをコンパイルする必要があります。 これ以外のスレッド・パッケージはサポートされていません。

hiprof(1)pixie(1),または third(1) を使用する場合は,-pthread オプションを指定して,そのツールでスレッド・セーフなプロファイルがサポートされるようにします。 uprofile(1) コマンドと cc コマンドの -p および -pg オプションには,スレッド・セーフにするための追加のオプションは必要ありません。

マルチスレッド・アプリケーションのプロファイルを行う場合,省略時の設定では 1 つのプロファイルですべてのスレッドをカバーします。 この場合は,プロセス全体にわたるプロファイルが行われ,すべてのスレッドからのプロファイル・データを含む 1 つの出力ファイルが作成されます。

hiprof(1) または pixie(1) を使用する場合は,-threads オプションを使用するとスレッドごとのデータが得られます。

cc コマンドの -p または -pg オプションを使用する場合は,次の C シェルの例に示すように,PROFFLAGS 環境変数に -threads を設定してスレッドごとのプロファイルを指定します。

setenv PROFFLAGS "-threads"

uprofile(1) および third(1) ツールでは,スレッドごとのデータは得られません。

スレッドごとのプロファイル・データ・ファイルには,一意のスレッド番号を含む名前が付けられます。 この番号は,スレッドが作成されたシーケンスまたはプロファイルが開始されたシーケンスを反映します。

monitor( ) または monstartup( ) 呼び出し (8.9 節を参照) をスレッド付きプログラムで使用する場合は,アプリケーションのプロファイルを完全に制御できるように,最初に PROFFLAGS"-disable_default -threads" を設定しておく必要があります。

アプリケーションが monitor( ) を使用して,プロファイルされる各スレッドに別個のバッファを割り当てる場合には,最初に PROFFLAGS"-disable_default -threads" を設定する必要があります。 これは,使用されるファイル命名規則はこの設定の影響を受けるからです。 -threads オプションがない場合は,monitor または monstartup の最初の呼び出しの結果として使用されるバッファとアドレス範囲が,その後にプロファイルを要求するすべてのスレッドに適用されます。 この場合,プロファイルされるすべてのスレッドをカバーする 1 つのデータ・ファイルが作成されます。

プロセス内の各スレッドは,monitor( ) または monstartup( ) ルーチンを呼び出して,自らのプロファイルを開始する必要があります。

8.9    monitor ルーチンを使用したプロファイルの制御

cc コマンドの -p および -pg モードの Tru64 UNIX システムでの省略時の動作は,プログラムのテキスト・セグメント全体のプロファイルを行い,プロファイル・データを mon.out (prof プロファイルの場合) または gmon.out (gprof プロファイルの場合) に出力することです。 大規模なプログラムでは,テキスト・セグメント全体のプロファイルを行う必要がない場合があります。 monitor ルーチンには,関数アドレス範囲の下位アドレスと上位アドレスの境界によって指定されるプログラムの一部をプロファイルす機能があります。

monitor ルーチンには,次のものがあります。

monitor

このルーチンを使用すると,特定のテキスト範囲のプロファイルをオン/オフすることにより,プロファイルを明示的に制御できます。 このルーチンは,gprof プロファイルでは使用できません。

monstartup

monitor と似ていますが, このルーチンではアドレス範囲の指定のみが可能で,gprof プロファイルで使用できます。

moncontrol

このルーチンを monitor および monstartup と併用すると,プログラムの実行中に特定のプロセスまたはスレッドに対して,PC サンプリングのオン/オフを切り替えることができます。

monitor_signal

このルーチンを使用すると,デーモンなど終了しないプログラムのプロファイルを行うことができます。

monitor および monstartup を使用すると,静的な実行可能ファイルだけでなく個々のシェアード・ライブラリ内のアドレス範囲をプロファイルすることができます。

これらの関数の詳細については, monitor(3) を参照してください。

省略時の設定では,プログラムの実行が開始した直後にプロファイルが開始されます。 この動作を変更するには,次に示す C シェルの例のように,PROFFLAGS 環境変数に -disable_default を設定します。

setenv PROFFLAGS "-disable_default"

次に,monitor ルーチンを使用すると,monitor または monstartup の最初の呼び出しの後にプロファイルを開始するように設定できます。

例 8-11 では,monstartup ルーチンと monitor ルーチンを プログラム内で使用して,プロファイルの開始と終了を行う方法を示します。

例 8-11:  monstartup() と monitor() の使用

   /*  Profile the domath( ) routine using monstartup.
    *  This example allocates a buffer for the entire program.
    *  Compile command: cc -p foo.c -o foo -lm
    *  Before running the executable, enter the following
    *  from the command line to disable default profiling support:
    *  setenv PROFFLAGS -disable_default
    */
 
    #include <stdio.h>
    #include <sys/syslimits.h>
 
    char dir[PATH_MAX];
 
    extern void _ _start( );
    extern unsigned long _etext;
 
    main( )
    {
        int i;
        int a = 1;
 
        /* Start profiling between _ _start (beginning of text)
         * and _etext (end of text).  The profiling library
         * routines will allocate the buffer.
         */
 
        monstartup(_ _start,&_etext);
 
           for(i=0;i<10;i++)
                domath( );
 
        /* Stop profiling and write the profiling output file. */
 
        monitor(0);
   }
    domath( )
   {
      int i;
      double d1, d2;
 
      d2 = 3.1415;
      for (i=0;  i<1000000;  i++)
         d1 = sqrt(d2)*sqrt(d2);
   }

外部名 _etext がすべてのプログラム・テキストの直前にあります。 詳細については, end(3) を参照してください。

PROFFLAGS 環境変数を -disable_default に設定すると,省略時のプロファイル・バッファ・サポートが無効になるため,例 8-12 に示すように,バッファをプログラム内に割り当てることができます。

例 8-12:  プログラム内のプロファイル・バッファの割り当て

   /*  Profile the domath routine using monitor().
    *  Compile command: cc -p foo.c -o foo -lm
    *  Before running the executable, enter the following
    *  from the command line to disable default profiling support:
    *  setenv PROFFLAGS -disable_default
    */
 
   #include <sys/types.h>
   #include <sys/syslimits.h>
 
   extern char *calloc( );
 
   void domath(void);
   void nextproc(void);
 
   #define INST_SIZE 4          /* Instruction size on Alpha */
   char dir[PATH_MAX];
 
   main( )
   {
        int i;
        char *buffer;
        size_t bufsize;
 
        /*  Allocate one counter for each instruction to
         *  be sampled. Each counter is an unsigned short.
         */
 
        bufsize = (((char *)nextproc - (char *)domath)/INST_SIZE)
         * sizeof(unsigned short);
 
         /*  Use calloc( ) to ensure that the buffer is clean
          *  before sampling begins.
          */
 
         buffer = calloc(bufsize,1);
 
         /*  Start sampling.  */
          monitor(domath,nextproc,buffer,bufsize,0);
          for(i=0;i<10;i++)
                domath( );
 
         /* Stop sampling and write out profiling buffer.  */
                  monitor(0);
  }
   void domath(void)
  {
    int i;
    double d1, d2;
 
       d2 = 3.1415;
       for (i=0;  i<1000000;  i++)
           d1 = sqrt(d2)*sqrt(d2);
   }
 
   void nextproc(void)
   {}

monitor_signal( ) ルーチンを使用すると,終了しないプログラムのプロファイルを行うことができます。 プログラム内でこのルーチンを単一のハンドラとして宣言し,prof または gprof プロファイル用にプログラムを作成します。 プログラムの実行中に,kill コマンドを使用してシェルから信号を送信します。

プログラムが信号を受け取ると,monitor_signal が呼び出され,データ・ファイルにプロファイル・データを書き込みます。 プログラムが別の信号を受け取ると,データ・ファイルは上書きされます。

例 8-13 に, monitor_signal ルーチンの使用方法を示します。

PROFFLAGS 環境変数を -sigdump SIGNAME に設定すると,新しいプログラム・コードを追加することなく同じ機能を得ることができます。

例 8-13:  monitor_signal() を使用した,終了しないプログラムのプロファイル

/* From the shell, start up the program in background.
 * Send a signal to the process, for example: kill -30 <pid>
 * Process the [g]mon.out file normally using gprof or prof
 */
 
#include <signal.h>
 
extern int monitor_signal();
 
main()
{
    int i;
    double d1, d2;
 
    /*
     * Declare monitor_signal() as signal handler for SIGUSR1
     */
    signal(SIGUSR1,monitor_signal);
    d2 = 3.1415;
    /*
     * Loop infinitely (absurd example of non-terminating process)
     */
    for (;;)
        d1 = sqrt(d2)*sqrt(d2);
}