UNIXを使っている人で、実行速度などが気になるソフトウェアを開発している人は、是非知って いなければならないのが「プロファイル」です。「プロフィール」と呼ぶ人もいます。英語で書け ばprofileで、これを使うと、プログラムのprofile、横顔、輪廓が分かるという優れ物です。

コンパイル時に、cc -p としてプロファイルオプションを付けてコンパイルしてできた実行モジュー ルは、プログラム実行時に、プログラムの実行状態をmon.outというファイルに書き込みます。実 行終了後、profコマンドで、プログラムがどのように実行されたかを調べることができます。

単純なプログラムでプロファイルを使うことは少いのですが、図１４−２のような複雑な３次元 形状を生成するプログラム（正確には、「ソリッドモデラ」と呼ぶ）のような、相当面倒な開発を している場合には、プロファイルの存在は「天の助け」です。

図１４−２　ソリッドモデルによる 　　　３次元形状生成と断面の表示

図１４−３が、図１４−２の形状を生成、表示した後、profコマンドで実行状態を表示した例で す。最初の行に、タイトル行が出てきます。図には、先頭の100行分だけ示しています。

図１４−３　ソリッドモデラに対するプロファイル

fuji@belle(p1)$ prof solidx 26.6 12.82 39 328.72 _fac_pack 9.5 17.39 _SolidCrossFaceEdge_ 7.9 21.20 555515 0.01 _SolidIsparfac_ 7.6 24.87 mcount 6.0 27.75 23 125.22 _SolidDisplay 5.2 30.27 226294 0.01 _SolidFvitobox_ 4.1 32.24 27722 0.07 _SolidInsidlop_ 2.3 33.36 48974 0.02 _SolidIsonlnsg_ 2.2 34.40 53263 0.02 _cfree 2.0 35.35 238275 0.00 _SolidCrossbox_ 1.7 36.17 _fabs 1.6 36.94 53263 0.01 _free 1.6 37.69 10618 0.07 _SolidDispInsidlop_ 1.5 38.39 20496 0.03 _SolidDTrans_ 1.2 38.99 4205 0.14 _memset 1.2 39.56 24072 0.02 _realloc 1.1 40.09 51975 0.01 _malloc 1.1 40.60 13738 0.04 _SolidInsidObj_ 1.0 41.08 _sqrt 1.0 41.55 29998 0.02 _SolidSetprjix_ 0.9 41.98 8527 0.05 _SolidClip3dim_ 0.9 42.39 18 22.78 _SolidSetcured_ 0.8 42.78 5225 0.07 _SolidFacinbxi_ 0.8 43.17 10476 0.04 _bcopy 0.7 43.49 14884 0.02 _SolidIncDivEdgBox_ 0.6 43.80 1721 0.18 _SolidDspTrncl_ 0.6 44.09 98456 0.00 _SolidAbsnear_ 0.6 44.38 20052 0.01 _SolidVecn_ 0.6 44.65 4526 0.06 _SolidSortediv_ 0.5 44.91 87272 0.00 _SolidVeci_ 0.5 45.16 47494 0.01 _bzero 0.5 45.40 _SolidDelGrp_ 0.5 45.64 39 6.15 _packinit 0.4 45.84 79 2.53 _SolidFcginbxi_ 0.4 46.02 2 90.00 _SolidGraphicsClose_ 0.3 46.16 48140 0.00 .umul 0.3 46.29 10029 0.01 _SolidAddediv_ 0.2 46.41 60 2.00 _SolidDelObj_ 0.2 46.53 20210 0.01 _SolidVecv_ 0.2 46.64 _SolidShellHaiSetName 0.2 46.74 20052 0.00 _SolidVecl_ 0.2 46.83 10608 0.01 _SolidDispSetprjix_ 0.2 46.92 _SolidPackObject_ 0.1 46.99 13252 0.01 _SolidEdgevisi_ 0.1 47.05 836 0.07 _SolidWTrans_ 0.1 47.11 22 2.73 _vfork 0.1 47.16 4911 0.01 _SolidFacevisi_ 0.1 47.21 7606 0.01 _SolidGraphicsTypedLine_ 0.1 47.26 114 0.44 _SolidObjinbox_ 0.1 47.31 _SolidShellErrorExit 0.1 47.36 47494 0.00 _calloc 0.1 47.41 152 0.33 _sbrk 0.1 47.45 15895 0.00 _SolidRelnear_ 0.1 47.49 11968 0.00 _SolidReqedg_ 0.1 47.52 19608 0.00 .rem 0.1 47.55 10608 0.00 _SolidDispInsidfac_ 0.1 47.58 7250 0.00 _SolidDspTrans__ 0.1 47.61 25793 0.00 _SolidInsidfac_ 0.1 47.64 333 0.09 _SolidVecr_ 0.1 47.67 _XDrawLine 0.1 47.70 _acos 0.1 47.73 300 0.10 _decimal_to_unpacked 0.1 47.76 39 0.77 _lop_pack 0.1 47.79 92 0.33 _write 0.0 47.81 7606 0.00 _SolidGraphicsLine_ 0.0 47.83 1 20.00 _SolidIncbox_ 0.0 47.85 _SolidMakeArbitraryPrism_ 0.0 47.87 _SolidShellGetLabelPoint 0.0 47.89 4143 0.00 _SolidVecdet_ 0.0 47.91 _atan 0.0 47.93 39 0.51 _edg_pack 0.0 47.95 _sincos 0.0 47.97 25 0.80 _syscall 0.0 47.98 .div 0.0 47.99 5 2.00 _SolidCopy 0.0 48.00 1277 0.01 _SolidCutDsptr_ 0.0 48.01 2365 0.00 _SolidEdgangle_ 0.0 48.02 78 0.13 _SolidGrpAdd_ 0.0 48.03 1 10.00 _SolidInitfedis_ 0.0 48.04 4568 0.00 _SolidReqlop_ 0.0 48.05 77 0.13 _SolidReqobj_ 0.0 48.06 7597 0.00 _SolidReqvtx_ 0.0 48.07 1 10.00 _SolidShellRunIP 0.0 48.08 418 0.02 _SolidStoWTrns_ 0.0 48.09 13 0.77 _SolidVecd2_ 0.0 48.10 _XCreateGC 0.0 48.11 300 0.03 __big_binary_to_unpacked 0.0 48.12 57 0.18 __doscan 0.0 48.13 32 0.31 _chgvtx_m 0.0 48.14 77 0.13 _gettimeofday 0.0 48.15 16 0.62 _read 0.0 48.16 88 0.11 _sigblock 0.0 48.17 39 0.26 _vtx_pack 0.0 48.17 1 0.00 .mul 0.0 48.17 997 0.00 .udiv 0.0 48.17 844 0.00 .urem 0.0 48.17 197 0.00 _ShellDataGetData 0.0 48.17 2 0.00 _SolidAffine

左から順に、

    %time    関数が消費した時間の％表示
    cumsecs  累積の時間数（秒単位）
    #call    呼び出し回数
    ms/call  １回の呼び出しの平均時間（ミリ秒）
    name     関数名

関数名の最初はほとんど全部が_（下線）で始まっていますが、これはＣの関数には自動的に最 初に_をつけ、リンクのときに、他のコンパイラ言語などの出力とぶつからないように工夫してい るためです。

リスト１４−３によると、関数_fac_packは、全実行時間の26.6%も消費しています。呼び出し回 数はたった39回なのに、1回の呼び出しで平均328.78ミリ秒もかかっています。forループが多重に でもなっていて、猛烈に時間を食う、もしかしたらCPUを浪費している関数ではないかと思えます。 ちょっと、この関数は見直した方がよいかも知れないことが分かります。

関数_SolidIsparfac_は,まったく逆ですね。呼び出し回数は555515回もありますが、1回の呼び 出しでは平均0.01ミリ秒しかかかっていません。この関数は、まちがいなく単純な関数でしょう。 しかし、呼び出し回数が非常に多いので、呼び出し回数を減らす工夫や、関数を止めてマクロ定義 してしまうとか、インライン関数にして、関数呼び出しのオーバーヘッドを減らすなど考えられる でしょうか。

もう、このソリッドモデラは、プロファイルを十分に使って最適化されています。最適化されて いないプログラムのプロファイルを取ると、たった1つの関数が、実行時間の過半数を食っている ことが多いものです。数個の関数で90%以上の時間を使い切っていることが一般的です。

このような計測情報が得られると、プログラムのチューンアップが楽ですね。その昔、MS-DOSで けっこう面倒なプログラムを作ったのですが、どこに手を入れれば性能アップにつながるのか良く 分かりませんでした。遅そうな部分の見当はついたのですが、客観的なデータのないままプログラ ムをいじるのは時間の浪費になると思い、ソースをUNIXマシンに吸い上げ、プロファイルを取り、 その結果をMS-DOS版のソフトに反映させたことがありました。

とにかく、プロファイルは使ってみる価値があります。今回のこの膨大なソフトウェア、実は今 まで開発していた人たちは一度も使っていなかったのです。速度がどうのこうのと言っていながら、 客観的なデータを一度も取っていなかったのです。驚くなかれ、プロファイルを知らなかったので す。肝腎なツールも知らずに延々とプログラムを書き、高速化するのに、どうやっていたのか本当 に不思議です。「この辺が遅そうだから直そうか」というような方法を取っていたのでしょうか。 せっかく素晴らしい道具があってもネー、と思ってしまいました。

「猫に小判」、「豚に真珠」のような平凡な諺では表現し尽くせません。コンピュータ業界で通 用する、もっと強力な諺でもないとぴったりきませんね。