【D言語】-profileで関数の実行時間を計測してみる【dmd】

D言語erの皆さん、こんにちは。 今回は、-profileを使って、関数の実行時間を計測してみます。

-profile？

---

dmdでコンパイルするときに、オプションとして-profileを渡すと、各関数の実行時間を測ることができます。 便利ですね。

実際に使ってみる

---

以下のコードで試してみます。

// calc.d
import std.conv;
void main(){
    foreach(Unused; 0..1_000)
        paren("((((1234))))");
}

int paren(string input){
    if(input[0] == '('){
        return paren(input[1..$-1]);
    }else{
        return input.to!int;
    }
}

これを、以下のようにコンパイルし、実行します。

dmd -profile calc.d
./calc

すると、計測結果が書かれた、trace.logというファイルが現れます。

trace.logの中身

---

trace.logの下の方に、関数が、実行時間が長い順に書かれています。 上の例をとある環境で試してみると、以下のようになります。

======== Timer Is 3579545 Ticks/Sec, Times are in Microsecs ========

  Num          Tree        Func        Per
  Calls        Time        Time        Call

   1000       86167       84480          84     int std.conv.parse!(int, immutable(char)[]).parse(ref immutable(char)[])
   5000      662473       41731           8     int d.paren(immutable(char)[])
      1      182125       37278       37278     _Dmain
   1000      103116        8650           8     int std.conv.to!(int).to!(immutable(char)[]).to(immutable(char)[])
   1000       94465        8298           8     int std.conv.toImpl!(int, immutable(char)[]).toImpl(immutable(char)[])
   4000        1063         955           0     @property dchar std.array.front!(immutable(char)[]).front(immutable(char)[])
   5000         618         618           0     pure nothrow @property @safe bool std.array.empty!(char).empty(const(char[]))
   4000         108         108           0     pure @trusted dchar std.utf.decode!(immutable(char)[]).decode(ref immutable(char)[], ref ulong)
   4000           3           3           0     pure nothrow @trusted void std.array.popFront!(immutable(char)[]).popFront(ref immutable(char)[])

それぞれ、

• Num Calls:
  関数が呼ばれた回数
• Tree Time:
  関数の実行するのにかかった時間。
• Func Time:
  Tree Timeから、関数内で呼び出している他の関数の実行にかかった時間を引いた時間。つまり、その関数の正味の実行時間。
• Per call:
  Func TimeをNum Callsで割ったもの、つまり一回の関数実行にかかった時間の平均

という内容です。 表はFunc Timeでソートされています。 表を見ると、最適化するべきなのはstd.conv.parse!(〜〜〜)であることがわかります。

まとめ

---

-profileについて、見てきました。 コンパイラにこういう機能があると、色々と捗りますね。 皆さんも、コードを最適化がしたい時などに、ぜひ使ってみて下さい。

担当：美馬（ctpgの最適化を頑張りたい）