Linux STARTUP for Programmers / Capter 2 (make)

3.3.6 実行状況と性能の解析(prof)

prof はプログラムの実行状況と性能を解析します。 C、 Fortran、 Pascal に適用できます。 prof はプログラムが呼び出した各関数について以下の情報を出力します。

CPU を使用した割合
呼ばれた回数
1 回実行するのに要した平均時間

対象となるプログラムはあらかじめプロファイルオプション(-p)でコンパイルされていなければなりません。このオプションが付いたプログラムを実行するとカレントディレクトリに mon.out が作成され、このファイルを prof が解析します。

【入力フォーマット】

prof オプション［実行イメージ］

【実行例】

	% cat -n a.c
	     1	#include <stdio.h>
	     2	#include <math.h>
	     3	
	     4	double pai( int n )
	     5	{
	     6		return 6.23 * ((n%100)/100);
	     7	}
	     8	
	     9	double mySin( double r )
	    10	{
	    11		return sin(r * cos(r) );
	    12	}
	    13	
	    14	main()
	    15	{
	    16		int	i,j;
	    17		for(i=0;i<1000;i++) {
	    18			for(j=0;j<10000;j++) mySin( pai(j) );
	    19		}
	    20	}
	% cc -p a.c -lm
	% a.out

	% prof a.out
	Profile listing generated Sat Apr 25 14:46:40 1998 with: 
	   prof a.out  

	----------------------------------------------------------------------------
	*  -p[rocedures] using pc-sampling;                                        *
	*  sorted in descending order by total time spent in each procedure;       *
	*  unexecuted procedures excluded                                          *
	----------------------------------------------------------------------------

	Each sample covers 8.00 byte(s) for 0.014% of 6.9609 seconds 
								  
	%time     seconds  cum %   cum sec  procedure (file)     
								   
	 54.5      3.7910   54.5      3.79 pai ()
	 23.4      1.6270   77.8      5.42 
	 12.7      0.8828   90.5      6.30 mySin ()
	  9.5      0.6602  100.0      6.96 main ()

また cc(1) の feedback 機能と合わせれば、統計情報を元に最適化が可能です。
例:プロファイリングによる最適化先のソースをコンパイルし実行してみると、次の結果が得られました。この結果では最適化レベル３が最もよい成績を出しています。

	% cc -lm a.c
	% repeat 3 time a.out
	6.90u 0.02s 0:07 98% 0+1k 0+2io 0pf+0w
	6.90u 0.04s 0:07 98% 0+1k 0+0io 0pf+0w
	6.90u 0.02s 0:07 98% 0+1k 0+0io 0pf+0w
	% cc -lm -O2 a.c
	% repeat 3 time a.out
	6.90u 0.02s 0:07 98% 0+1k 0+0io 0pf+0w
	6.91u 0.02s 0:06 99% 0+1k 0+3io 0pf+0w
	6.91u 0.02s 0:06 99% 0+1k 0+0io 0pf+0w
	% cc -lm -O3 a.c
	% repeat 5 time a.out
	6.42u 0.03s 0:06 98% 0+1k 0+0io 0pf+0w
	6.42u 0.03s 0:06 99% 0+1k 0+3io 0pf+0w
	6.42u 0.02s 0:06 99% 0+1k 0+0io 0pf+0w
	% cc -lm -O4 a.c
	% repeat 3 time a.out
	6.45u 0.04s 0:06 98% 0+1k 0+0io 0pf+0w
	6.47u 0.03s 0:06 94% 0+1k 0+0io 0pf+0w
	6.46u 0.02s 0:06 99% 0+1k 0+3io 0pf+0w

つぎに feedback を用いてコンパイラに最適化させてみます。

フィードバック用ファイル作成オプション(-gen_feedback)
gen_feedback オプションを付けてコンパイルします。
```
	% cc -lm -gen_feedback a.c
```

pixie の実行

pixie コマンドにより、プロファイル収集用イメージを生成します。これにより a.out.pixie が作成されます。

	% pixie a.out
	pixie: executing: "atom -tool pixie a.out"
	% ls -lt a.out*
	-rw-r-----   1 yakoshi	system	     628 04月25日 14:36 a.out.Addrs
	-rwxr-x---   1 yakoshi	system	  246336 04月25日 14:36 a.out.pixie
	-rwxr-x---   1 yakoshi	system	   24576 04月25日 14:36 a.out

プロファイル取得

a.out.pixie を実行し、プロファイル情報を取得します。このとき実行時間がかなりかかります。

	% time a.out.pixie
	48.20u 0.16s 0:48 98% 0+1k 2+15io 0pf+0w
	% ls -lt a.out*
	-rw-r-----   1 yakoshi	system	    1016 04月25日 14:37 a.out.Counts
	-rw-r-----   1 yakoshi	system	     628 04月25日 14:36 a.out.Addrs
	-rwxr-x---   1 yakoshi	system	  246336 04月25日 14:36 a.out.pixie
	-rwxr-x---   1 yakoshi	system	   24576 04月25日 14:36 a.out

フィードバックファイル作成
prof により、フィードバックファイルを作成します。
```
	% prof -pixie -feedback a.out.feedback a.out
```
この時の実行ファイル名が *.pixie でない点に注意してください。

再コンパイル

このフィードバックファイルを元に、最適化コンパイルを行います。このときにも最適化レベルが影響します。

	% cc -lm -feedback a.out.feedback -O2 a.c
	% repeat 3 time a.out
	6.91u 0.05s 0:07 94% 0+1k 0+0io 0pf+0w
	6.90u 0.02s 0:07 97% 0+1k 0+3io 0pf+0w
	6.90u 0.03s 0:06 99% 0+1k 0+0io 0pf+0w
	% cc -lm -feedback a.out.feedback -O3 a.c
	% repeat 3 time a.out
	6.19u 0.04s 0:06 98% 0+1k 0+0io 0pf+0w
	6.19u 0.02s 0:06 98% 0+1k 0+3io 0pf+0w
	6.19u 0.03s 0:06 99% 0+1k 0+0io 0pf+0w

Section Next|Prev|Up|Index|凡例