本稿は「Elixirでスタックトレースを取得する」をもとに加筆・補正し、文章を整えました。Elixirで例外が起きたときだけでなく、普通の場合も含めて、スタックトレースの情報の取り出し方についてご説明します。

例外が起きたとき

例外が起きたときには当然、詳細なログを出すためにスタックトレース情報が必要です。例外時のスタックトレースの情報は、Elixir 1.7に備わった__STACKTRACE__/0で得られます。それより前のバージョンでは、System.stacktrace/0をお使いください。ただし、v1.7以降で用いることは推奨されません(「Elixir v1.7がリリースされた」「__STACKTRACE__構造体」参照)。たとえば、つぎのコードをtest.exsに書いてみましょう。¹

defmodule X do
  def f() do
    throw 42
  end
  def g() do
    f() + 1
  end
  def h() do
    g() + 1
  end
end

try do
  X.h()
catch
  42 ->
    # IO.inspect System.stacktrace()  # v1.7より前に対応させたいとき
    IO.inspect __STACKTRACE__  # v1.7以降
end

コマンドラインツールにiex test.exsと打ち込むと、スタックトレース情報が出力されます。

[
  {X, :f, 0, [file: 'test.exs', line: 3]},
  {X, :g, 0, [file: 'test.exs', line: 6]},
  {X, :h, 0, [file: 'test.exs', line: 9]},
  {:elixir_compiler_0, :__FILE__, 1, [file: 'test.exs', line: 14]},
  {:elixir_compiler, :dispatch, 4, [file: 'src/elixir_compiler.erl', line: 79]},
  {:elixir_compiler, :compile, 3, [file: 'src/elixir_compiler.erl', line: 63]},
  {:elixir_lexical, :run, 2, [file: 'src/elixir_lexical.erl', line: 17]},
  {:elixir_compiler, :quoted, 2, [file: 'src/elixir_compiler.erl', line: 23]}
]

__STACKTRACE__/0の戻り値をさらにException.format_stacktrace/1に渡せば、出力が整形されます。

try do
  X.h()
catch
  42 ->
    # IO.inspect __STACKTRACE__
    IO.puts Exception.format_stacktrace(__STACKTRACE__)
end

test.exs:3: X.f/0
test.exs:6: X.g/0
test.exs:9: X.h/0
test.exs:14: (file)
(elixir) src/elixir_compiler.erl:79: :elixir_compiler.dispatch/4
(elixir) src/elixir_compiler.erl:63: :elixir_compiler.compile/3
(elixir) src/elixir_lexical.erl:17: :elixir_lexical.run/2
(elixir) src/elixir_compiler.erl:23: :elixir_compiler.quoted/2

通常のとき

例外が起きていなくても、関数がどこから呼ばれたか確かめたいことはあります。たとえば、共通処理の関数内でLogger.infoによりログを出力するとき、スタックトレースの情報があれば、問題はすぐにつきとめられるでしょう。

通常のときにスタックトレースの情報を取得するのは、Process.info/2です。関数には、つぎのように現在のプロセスを与えます。

defmodule X do
  def f() do
    {:current_stacktrace, t} = Process.info(self(), :current_stacktrace)
    IO.inspect t
    0
  end
  def g() do
    f() + 1
  end
  def h() do
    g() + 1
  end
end

X.h() + 1

[
  {Process, :info, 2, [file: 'lib/process.ex', line: 767]},
  {X, :f, 0, [file: 'test.exs', line: 3]},
  {X, :g, 0, [file: 'test.exs', line: 8]},
  {X, :h, 0, [file: 'test.exs', line: 11]},
  {:elixir_compiler_0, :__FILE__, 1, [file: 'test.exs', line: 15]},
  {:elixir_compiler, :dispatch, 4, [file: 'src/elixir_compiler.erl', line: 79]},
  {:elixir_compiler, :compile, 3, [file: 'src/elixir_compiler.erl', line: 63]}
]

例外時と同じく、Exception.format_stacktrace/1で出力は整形できます。

def f() do
  {:current_stacktrace, t} = Process.info(self(), :current_stacktrace)
  # IO.inspect t
  IO.puts Exception.format_stacktrace(Enum.drop(t, 1))
  0
end

Process.info/2から得た値をEnum.drop/2に渡したのは、Process.info/2の呼び出し情報は除きたかったためです。

test.exs:3: X.f/0
test.exs:8: X.g/0
test.exs:11: X.h/0
test.exs:15: (file)
(elixir) src/elixir_compiler.erl:79: :elixir_compiler.dispatch/4
(elixir) src/elixir_compiler.erl:63: :elixir_compiler.compile/3

Exception.format_stacktrace/1のドキュメントは、引数がないときはProcess.info/2から得た現行プロセスのスタックトレース情報を返すように書いています。ただしこの場合、呼び出しもと関数の情報が含まれません。

def f() do
  # {:current_stacktrace, t} = Process.info(self(), :current_stacktrace)
  # IO.puts Exception.format_stacktrace(Enum.drop(t, 1))
  IO.puts Exception.format_stacktrace()
  0
end

つぎのように、X.f/0の情報が抜けてしまいます。

test.exs:7: X.g/0
test.exs:10: X.h/0
test.exs:14: (file)
(elixir) src/elixir_compiler.erl:79: :elixir_compiler.dispatch/4

Exception.format_stacktrace/1のコードを見ると、Enum.drop/2で、はじめの3つのトレース情報を削っているのです。

はじめのふたつはProcess.info/2とException.format_stacktrace/1ですから、省くことはわかります。けれど、なぜかさらにもうひとつ、呼び出しもと関数(X.f/0)の情報も消しているのです。これはあった方がよいという場合は、ダミーのスタック情報をひとつ積んで呼び出せばよいでしょう。

def format_stacktrace() do  # スタック情報をひとつ積む
  Exception.format_stacktrace() <> ""
end
def f() do
  # IO.puts Exception.format_stacktrace()
  IO.puts format_stacktrace()
  0
end

test.exs:6: X.f/0
test.exs:10: X.g/0
test.exs:13: X.h/0
test.exs:17: (file)

なお、スタックトレースの情報は7個までしか取得していないようです。ただでさえ少ない情報が3つも削られてしまうのは、かなりもったいないといえます。どのように取得するのがよいかは、少し考えた方がよさそうです。

f() + 1のように+1を加えているのは、末尾呼び出し最適化を妨げるためです。詳しくは「Elixirのスタックトレースと末尾呼び出し最適化」をお読みください。 ↩

Blog

Elixir: スタックトレースを取得する

gumi TECH

例外が起きたとき

通常のとき

Join Our Newsletter. No Spam, Only the good stuff.

Related