[Erlang] 実行時間計測

Eralngで簡単な実行時間計測を行うモジュールを作った。

statistics(runtime), statistics(wall_clock)の一度目の呼び出しはそれぞれCPU時間・実経過時間を0に初期化する。返り値は次の要素から成るタプル(引数にwall_clockを指定)で構成される。

{Total_Wallclock_Time, Wallclock_Time_Since_Last_Call}

prof.erl

-module(prof).
-export([start/0, stop/1, test/0]).

%% prof:start() -> B.
%%  Start the profiler.
start() ->
  statistics(runtime),
  statistics(wall_clock),
  {_, T1} = statistics(runtime),
  {_, T2} = statistics(wall_clock),
  {ok, {T1, T2}}.

%% return -> {Runtime, Wall-clock time}
stop(B) ->
  case B of
    {ok, {OldT1, OldT2}} ->
      {_, T1} = statistics(runtime),
      {_, T2} = statistics(wall_clock),
      {T1- OldT1, T2 - OldT2};
    Other ->
      {error, Other}
   end.

%% test()
%% Profile test
test() ->
  B = start(),
  lists:foreach(fun (X) -> math:pow(X, 10) end, lists:seq(1, 1000000)),
  {Time1, Time2} = stop(B),
  io:format("time=~p (~p) msec~n", [Time1, Time2]).

実行結果

1> c(prof).
{ok, prof}
2> prof:test().
time=300 (1194) msec
ok
3> prof:test().
time=370 (1238) msec
ok

症状
プロセス数を増やしすぎて、CPU時間が短いのに実経過時間が極度に大きくなる場合は、物理メモリが不足しスワップが発生しているサインである。