Telemetry Logging Error

I receive the same type of error message upon any query I perform on my Ecto database in my Phoenix web application. I have checked both the Elixir forums and Github Forums and can’t seem to find a solution. A suggested solution I often see is adding the :ecto_sql dependency to the mix.exs file, which I have done. Code for mix.exs is at the bottom of this post.

Elixir Version: 1.7.3
Phoenix Version: 1.2.5

The error seems to have something to do with Telemetry. It looks like this:

[error] an exception was raised logging %DBConnection.LogEntry{call: :prepare_execute, connection_time: 16384, decode_time: 0, params: [], pool_time: 0, query: %Postgrex.Query{cache: :reference, columns: nil, name: "ecto_4516", param_formats: nil, param_oids: nil, param_types: nil, ref: nil, result_formats: nil, result_oids: nil, result_types: nil, statement: "SELECT u0.\"id\", u0.\"name\", u0.\"username\", u0.\"password_hash\", u0.\"inserted_at\", u0.\"updated_at\" FROM \"users\" AS u0", types: nil}, result: {:ok, %Postgrex.Query{cache: :reference, columns: ["id", "name", "username", "password_hash", "inserted_at", "updated_at"], name: "ecto_4516", param_formats: [], param_oids: [], param_types: [], ref: #Reference<0.2732196140.1558446083.208234>, result_formats: [:binary, :binary, :binary, :binary, :binary, :binary], result_oids: [20, 1043, 1043, 1043, 1114, 1114], result_types: [Postgrex.Extensions.Int8, Postgrex.Extensions.Raw, Postgrex.Extensions.Raw, Postgrex.Extensions.Raw, Postgrex.Extensions.Timestamp, Postgrex.Extensions.Timestamp], statement: "SELECT u0.\"id\", u0.\"name\", u0.\"username\", u0.\"password_hash\", u0.\"inserted_at\", u0.\"updated_at\" FROM \"users\" AS u0", types: {Postgrex.DefaultTypes, #Reference<0.2732196140.1558577157.207684>}}, %Postgrex.Result{columns: ["id", "name", "username", "password_hash", "inserted_at", "updated_at"], command: :select, connection_id: 12648, messages: [], num_rows: 3, rows: [[18, "Shandy Sulen", "shandysulen", nil, ~N[2018-12-09 20:33:42.000000], ~N[2018-12-09 20:33:42.000000]], [19, "Erik Tastepe", "eriktastepe", nil, ~N[2018-12-09 20:38:33.000000], ~N[2018-12-09 20:38:33.000000]], [20, "Test", "test", nil, ~N[2018-12-09 21:13:08.000000], ~N[2018-12-09 21:13:08.000000]]]}}}: ** (ArgumentError) argument error
    (stdlib) :ets.lookup(Telemetry.HandlerTable, [:rumbl, :repo, :query])
    lib/telemetry/handler_table.ex:59: Telemetry.HandlerTable.list_for_event/1
    lib/telemetry.ex:76: Telemetry.execute/3
    lib/ecto/adapters/sql.ex:770: Ecto.Adapters.SQL.log/4
    (db_connection) lib/db_connection.ex:1311: DBConnection.log/5
    lib/ecto/adapters/sql.ex:545: Ecto.Adapters.SQL.execute!/4
    lib/ecto/adapters/sql.ex:537: Ecto.Adapters.SQL.execute/5
    (ecto) lib/ecto/repo/queryable.ex:147: Ecto.Repo.Queryable.execute/4
    (ecto) lib/ecto/repo/queryable.ex:18: Ecto.Repo.Queryable.all/3
    (stdlib) erl_eval.erl:677: :erl_eval.do_apply/6
    (elixir) src/elixir.erl:265: :elixir.eval_forms/4
    (iex) lib/iex/evaluator.ex:249: IEx.Evaluator.handle_eval/5
    (iex) lib/iex/evaluator.ex:229: IEx.Evaluator.do_eval/3
    (iex) lib/iex/evaluator.ex:207: IEx.Evaluator.eval/3
    (iex) lib/iex/evaluator.ex:94: IEx.Evaluator.loop/1
    (iex) lib/iex/evaluator.ex:24: IEx.Evaluator.init/4
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3

mix.exs

defmodule Rumbl.Mixfile do
  use Mix.Project

  def project do
    [app: :rumbl,
     version: "0.0.1",
     elixir: "~> 1.2",
     elixirc_paths: elixirc_paths(Mix.env),
     compilers: [:phoenix, :gettext] ++ Mix.compilers,
     build_embedded: Mix.env == :prod,
     start_permanent: Mix.env == :prod,
     aliases: aliases(),
     deps: deps()]
  end

  # Configuration for the OTP application.
  #
  # Type `mix help compile.app` for more information.
  def application do
    [mod: {Rumbl, []},
     applications: [:phoenix, :phoenix_pubsub, :phoenix_html, :cowboy, :logger, :gettext,
                    :phoenix_ecto, :postgrex, :comeonin]]
  end

  # Specifies which paths to compile per environment.
  defp elixirc_paths(:test), do: ["lib", "web", "test/support"]
  defp elixirc_paths(_),     do: ["lib", "web"]

  # Specifies your project dependencies.
  #
  # Type `mix help deps` for examples and options.
  defp deps do
    [{:phoenix, "~> 1.2.5"},
     {:phoenix_pubsub, "~> 1.0"},
     {:phoenix_ecto, "~> 3.0"},
     {:ecto_sql, "~> 3.0-rc.1"},
     {:postgrex, ">= 0.0.0"},
     {:phoenix_html, "~> 2.6"},
     {:phoenix_live_reload, "~> 1.0", only: :dev},
     {:gettext, "~> 0.11"},
     {:cowboy, "~> 1.0"},
     {:comeonin, "~> 2.0"}]
  end

  # Aliases are shortcuts or tasks specific to the current project.
  # For example, to create, migrate and run the seeds file at once:
  #
  #     $ mix ecto.setup
  #
  # See the documentation for `Mix` for more info on aliases.
  defp aliases do
    ["ecto.setup": ["ecto.create", "ecto.migrate", "run priv/repo/seeds.exs"],
     "ecto.reset": ["ecto.drop", "ecto.setup"],
     test: ["ecto.create --quiet", "ecto.migrate", "test"]]
  end
end

My guess is that you need to add telemetry to your list of applications.

I’d recommend removing applications from you mix.exs though and add other_applications: [:logger, :gettext]. Elixir made this the default about a year ago. It’ll automatically detect if your dependencies are applications for you. Typically the only ones you need to add are the ones that Elixir or Erlang provide that are not started for you automatically.

As @blatyo mentioned, the problem lies in :telemetry not being started. Telemetry is required by EctoSQL and should be started as its dependency, but :ecto_sql is not added to your :applications list as well.

Anyway, this is strange for other reasons. Since you’re using Phoenix 1.2.x and Phoenix.Ecto 3.x, your Ecto version should be 2.x and Telemetry is not integrated with that version. The error shouldn’t be there in the first place.

Could you remove :ecto_sql from your dependencies (since you don’t need it with your version of Phoenix), run mix deps.get and paste the contents of your mix.lock file in the reply?

You meant to say extra_applications: [:logger]. :slight_smile:

4 Likes

For me i had to add
Application.ensure_all_started(:ecto_sql)
to my
MyApp.Repo.init/2 since i overrided it with some custom APM metrics handler.