Elixir/Phoenix：为什么某些文件/行没有显示在我的异常堆栈跟踪中？

Question

每天几次在我的 Phoenix 应用程序中浏览错误堆栈跟踪时，我注意到某些肯定正在执行的文件没有显示在堆栈跟踪中。

示例 1：省略了视图助手方法

这是一个涉及从我的模板调用的 format_date 助手的示例。代码：

# The template, `...web/templates/home/index.html.eex`:
<h1>My Super Old Company</h1>
<p>We've been operating since <%= format_date(Timex.now()) %>!!</p>

# The `format_date` helper lives in the corresponding View module:
def format_date(date) do
  template = "%b %d, %Y"
  method = :strftime
  # Whoops, it looks like I passed a bad value to Timex here
  Timex.format!(nil, template, method)
end

尝试呈现此页面产生异常：

Request: GET /
** (exit) an exception was raised:
    ** (ArgumentError) invalid_date
        (timex) lib/format/datetime/formatter.ex:60: Timex.Format.DateTime.Formatter.lformat!/4
        (rtl) lib/rtl_web/templates/home/index.html.eex:3: RTLWeb.HomeView."index.html"/1
        (rtl) lib/rtl_web/templates/layout/app.html.eex:27: RTLWeb.LayoutView."app.html"/1
        ...

可以理解，Timex.format!/3 不喜欢 nil 并且它爆炸了。但是等等，为什么堆栈跟踪中没有提到我的 format_date/1 助手？毕竟，那个助手就是错误所在。并且代码肯定运行s 通过该函数；如果我更改上面的 nil 以传递 date 变量，错误就会消失。

我可以查看模板代码来推断调用了这个特定的助手，但我无法确定错误出在哪一行。如果函数很长或涉及多个 Timex 调用，我很容易对哪个特定调用出错感到困惑。

示例 2：省略上下文函数

这是另一个例子。在这种情况下，我的控制器正在调用上下文帮助程序来获取 Ecto 记录。

# The controller action:
def index(conn, _params) do
  # Whoops, looks like I hard-coded the project id by accident
  project = MyContext.get_project!(42)
  render(conn, "index.html", project: project)
end

# The MyContext context defines `get_project!/1` to fetch that id from the repo:
def get_project!(id) do
  Repo.get!(Project, id)
end

正如预期的那样，当我运行我的控制器测试时，我得到一个 Ecto.NoResultsError 因为不存在具有该 ID 的项目。但是，我再次注意到对 MyContext.get_project!/1 的调用未包含在堆栈跟踪中：

** (Ecto.NoResultsError) expected at least one result but got none in query:

from p in RTL.Projects.Project,
  where: p.id == ^42

code: conn = get(conn, Routes.home_path(conn, :index))
stacktrace:
  (ecto) lib/ecto/repo/queryable.ex:80: Ecto.Repo.Queryable.one!/4
  (rtl) lib/rtl_web/controllers/home_controller.ex:5: RTLWeb.HomeController.index/2
  (rtl) lib/rtl_web/controllers/home_controller.ex:1: RTLWeb.HomeController.action/2
  (rtl) lib/rtl_web/controllers/home_controller.ex:1: RTLWeb.HomeController.phoenix_controller_pipeline/2
  ...

更奇怪的是，我注意到如果我像这样在 get_project/1 末尾添加一条语句，堆栈跟踪会更改 以包含该行。

# When I add this nil at the tail...
def get_project!(id) do
  Repo.get!(Project, id)
  nil
end

# The stacktrace includes the function call.
...
(ecto) lib/ecto/repo/queryable.ex:80: Ecto.Repo.Queryable.one!/4
(rtl) lib/rtl/projects/projects.ex:12: RTL.Projects.get_project!/1
(rtl) lib/rtl_web/controllers/home_controller.ex:5: RTLWeb.HomeController.index/2
...

但是如果我将 nil 移动到函数的顶部，该行再次从堆栈跟踪中消失。

# When I move the nil to above the Repo.get! call...
def get_project!(id) do
  nil
  Repo.get!(Project, id)
end

# The stacktrace excludes the function call.
...
(ecto) lib/ecto/repo/queryable.ex:80: Ecto.Repo.Queryable.one!/4
(rtl) lib/rtl_web/controllers/home_controller.ex:5: RTLWeb.HomeController.index/2
...

示例 3：省略了测试断言助手

这是一个调用断言助手的控制器测试，该助手调用另一个助手，该助手调用另一个最终使断言失败的助手。但是在我的测试失败堆栈跟踪中，我没有看到任何迹象表明这些助手被调用了；我只得到我测试块中最高级别的行。

# The test example and helpers:
test "#index renders the page", %{conn: conn} do
  conn = get(conn, Routes.home_path(conn, :index))
  assert_foo("foo")
  assert html_response(conn, 200) =~ "bring personal storytelling back"
end

defp assert_foo(object) do
  assert_bar(object)
end

defp assert_bar(object) do
  assert_baz(object)
end

defp assert_baz(object) do
  learn_secret_of_life(object)
end

defp learn_secret_of_life(object) do
  assert object == "elixir"
end

# The test failure message:
Assertion with == failed
code:  assert object == "elixir"
left:  "foo"
right: "elixir"
stacktrace:
  test/rtl_web/controllers/home_controller_test.exs:6: (test)

如果我在 sub-sub-sub-helper 中引发异常，而不是简单地做出注定失败的断言，stacktrace 会提到最终的 helper 方法，但继续忽略中间方法：

# Modified helper function:
defp learn_secret_of_life(object) do
  assert object == raise("OMG")
end

# Now the stacktrace includes this helper, but not any of the chain of helpers that lead to its invocation:
** (RuntimeError) OMG
code: assert_foo("foo")
stacktrace:
  test/rtl_web/controllers/home_controller_test.exs:23: RTLWeb.HomeControllerTest.learn_secret_of_life/1
  test/rtl_web/controllers/home_controller_test.exs:6: (test)

显然，在这个人为设计的示例中，调用链很容易被追踪。但是在我最近一直在排除故障的实际应用程序中，我可能需要在几个不同的模块之间跳转以了解异常被调用的位置，当我不能指望每个链链接到出现在报告的堆栈跟踪中。我想我认为堆栈跟踪的工作是，您知道，列出异常发生时正在执行的每个文件和代码行。所以我对上面显示的行为感到非常困惑。

我的问题：

为什么 Elixir 有时会从堆栈跟踪中忽略某些文件/行？
有什么办法告诉它请不要那样做？
就我一个人糊涂吗？

Answer 1

发生这种情况是因为尾调用优化。

通常，一个函数有一个堆栈帧，其中包含它的局部变量和调用者的地址。当它调用另一个函数时，在顶部添加另一个堆栈帧，当函数 returns 时，它丢弃堆栈帧并跳回到调用者。

然而，当一个函数做的最后一件事是调用另一个函数时，不需要保留栈帧，因为它会在内部函数 returns 之后立即被丢弃。相反，内部函数的堆栈帧 替换了 外部函数的堆栈帧。

这样的优点是递归函数使用恒定数量的堆栈 space，但正如您已经注意到的那样，它的缺点是错误中的堆栈跟踪不完整。

为避免这种情况，请更改代码，使内部函数调用不再是外部函数执行的最后一件事。正如您所注意到的，returning nil 而不是内部函数的 return 值有效 - 这就是我将为断言助手所做的。对于 non-test 代码，我更不愿意这样做，因为尾调用优化通常是您想要的：它减少内存使用和执行时间。虽然看起来对于从模板调用的函数这样做可能是值得的，只是为了提高可调试性。

您绝对不是唯一对此感到困惑的人：这种情况经常发生 mentioned in the Erlang FAQ. See also the discussion in https://github.com/elixir-lang/elixir/issues/6357。

Elixir/Phoenix：为什么某些文件/行没有显示在我的异常堆栈跟踪中？

Elixir/Phoenix: Why are certain files / lines not shown in my exception stacktrace?

stack-trace

elixir

示例 1：省略了视图助手方法

示例 2：省略上下文函数

示例 3：省略了测试断言助手

我的问题：