みずりゅの自由帳

主に参加したイベントやソフトウェア技術/開発について記録しています

Elixirの関数の処理時間を「:timer.tc」で計測する

Elixirの関数の処理時間を計測するとき、Erlangの関数:timer.tcを利用します。

:timer.tcの使い方としては、次の通り3種類あります。

  • tc/1: 関数名を指定(引数なし)
  • tc/2: 関数名、引数を指定。引数はリスト形式で渡す。
  • tc/3: モジュール名、関数名、引数を指定。関数名の前にはコロン(:)を付与し、引数はリスト形式で渡す。

戻り値は、「処理時間(microseconds(マイクロ秒))」と「関数の結果」のタプルです。

「milliseconds(ミリ秒)」の値を渡すとその時間だけsleepする関数Process.sleep/1で実行すると、約1000倍の値を返しています。

以下、1秒、5秒、60秒で実施しました。

iex> :timer.tc(Process, :sleep, [1000])
{1000266, :ok}

iex> :timer.tc(Process, :sleep, [5000])
{5000677, :ok}

iex> :timer.tc(Process, :sleep, [60000])
{60000242, :ok}

以下、パターン別の利用例です。

関数名を指定(引数なし)

関数名をそのまま渡します。

iex> fc0 = fn -> "Hello World" end
#Function<45.97283095/0 in :erl_eval.expr/5>

iex> fc0.()
"Hello World"

iex> :timer.tc(fc0)
{11, "Hello World"}
関数名、引数を指定

引数は、リストに格納した形式で渡します。

たとえば、"hogehoge"を渡す場合は["hogehoge"]とします。

iex> fc1 = &(IO.puts/1)
&IO.puts/1

iex> fc1.("hoogehoge")
hoogehoge
:ok

iex> :timer.tc(fc1, ["hogehoge"])
hogehoge
{35, :ok}
モジュール名、関数名、引数を指定

モジュール名、関数名、引数の順番で渡します。

関数名の前にはコロン(:)を付与します。

たとえば、My.fc2/1の場合、関数名は:fc2となります。

引数は、リストに格納した形式で渡します。

引数がない場合は、[]とします。

iex> defmodule My do
...>   def fc2, do: 0
...>   def fc2(x), do: x
...>   def fc2(x,y), do: x+y
...> end

iex> My.fc2
0
iex> My.fc2(10)
10
iex> My.fc2(10,5)
15

iex> :timer.tc(My, :fc2, [])
{2, 0}

iex> :timer.tc(My, :fc2, [10])
{2, 10}

iex> :timer.tc(My, :fc2, [10,5])
{1, 15}
参考情報:再帰関数を計測

非末尾再帰ではない再帰関数で計測してみます。

確認用のリストを作成する無名関数を使い、以下のデータの総和を求めてみます。

  • 1..100
  • 1..1000
  • 1..10000
  • 1..100000

実行してみると、徐々に処理にかかる時間が増えていくのがわかります。

iex> defmodule My2 do
...>   def fc2([]), do: 0
...>   def fc2([head | tail]), do: head + fc2(tail)
...> end

iex> nl = fn n -> 1..n |> Enum.to_list end
#Function<44.97283095/1 in :erl_eval.expr/5>

iex> nl_100 = nl.(100)
[1, 2, 3, 4, 5, 6, 7, 8, 9, 10,  ...]
iex> nl_1000 = nl.(1000)
[1, 2, 3, 4, 5, 6, 7, 8, 9, 10,  ...]
iex> nl_10000 = nl.(10000)
[1, 2, 3, 4, 5, 6, 7, 8, 9, 10,  ...]
iex> nl_100000 = nl.(100000)
[1, 2, 3, 4, 5, 6, 7, 8, 9, 10,  ...]

iex> :timer.tc(My2, :fc2, [nl_100])
{4, 5050}

iex> :timer.tc(My2, :fc2, [nl_1000])
{27, 500500}

iex> :timer.tc(My2, :fc2, [nl_10000])
{372, 50005000}

iex> :timer.tc(My2, :fc2, [nl_100000])
{9785, 5000050000}
参考情報: :timer.tcのヘルプ
iex> h :timer.tc

                            :timer.tc/1

  @spec tc(fun) :: {time, value}
        when fun: function(), time: integer(), value: term()

Module was compiled without docs. Showing only specs.


                            :timer.tc/2

  @spec tc(fun, arguments) :: {time, value}
        when fun: function(),
             arguments: [term()],
             time: integer(),
             value: term()

Module was compiled without docs. Showing only specs.


                            :timer.tc/3

  @spec tc(module, function, arguments) :: {time, value}
        when module: module(),
             function: atom(),
             arguments: [term()],
             time: integer(),
             value: term()

Module was compiled without docs. Showing only specs.