String interpolation emits duplicate :imported_function trace events

[wojtekmach]

Environment

• Elixir & Erlang/OTP versions (elixir --version): Elixir 1.10.0-rc.0 (105770c) (compiled with Erlang/OTP 22)

Current behavior

Given this script:

Code.compiler_options(tracers: [CallerTracer])

defmodule CallerTracer do
  def trace({:imported_function, meta, module, name, arity}, env) do
    IO.puts "#{env.file}:#{meta[:line]} #{inspect(module)}.#{name}/#{arity}"
    :ok
  end

  def trace(_, _) do
    :ok
  end
end

Code.compile_string(~S"""
defmodule A do
  def a() do
  end
end

defmodule B do
  import A

  def b() do
    "#{a()}"
  end
end
""")

running it outputs:

% elixir run.exs
nofile:10 A.a/0
nofile:10 A.a/0

Changing "#{a()}" to a() causes just one event to be emitted.

Similarly, when changing the trace to:

  def trace({:remote_function, meta, A = module, name, arity}, env) do
    IO.puts "#{env.file}:#{meta[:line]} #{inspect(module)}.#{name}/#{arity}"
    :ok
  end

it outputs two events too:

nofile: A.a/0
nofile: A.a/0

(note without line information this time)

I assume this is because how string interpolation works under the hood but I thought I'd mention this anyway.

Expected behavior

One trace event.