How to: Only enable Ecto logging on errors?

Questions / Help
, ,
1 
      {:ecto_sql, "~> 3.4"},
      {:phoenix, "~> 1.5.8"},
      {:phoenix_ecto, "~> 4.1"},
      {:myxql, "~> 0.4.0"},

Currently Ecto is driving me crazy in development by outputting hundreds of lines of [debug] code into the console (running iex -S mix phx.server). [1] If I put log: :error into adapter config, this only makes those same hundreds of lines to output with [error] :slight_smile: [2]

I don’t want to disable ecto logging entirely though. If there’s an error happening, I want Ecto to log the error. I don’t think the docs cover how to do it. Do I somehow configure Telemetry to achieve what I need?

Send help! :slight_smile:

[1]

image
image1253Ă—734 105 KB

[2]

image
image1262Ă—733 107 KB

2

Those logs are just printing “query”. If error happens before query executed - you’ll see the error logged. If error happens after query executed - you’ll see both [deug] QUERY... and the error. You could set log: false and only errors, are supposed to be logged anyway.

1 Like
3

You should set your log level in your dev.exs file. See Logger — Logger v1.12.2 and Logger — Logger v1.12.2 for more info.

2 Likes
4

Take a look at the application configuration section of the Logger docs where it describes the :compile_time_purge_matching option. Find the corresponding Ecto function that’s printing the debug log, then just silence that module + function with level_lower_than: :info

config :logger,
  compile_time_purge_matching: [
    [module: Bar, function: "foo/3", level_lower_than: :error]
  ]

This is the beauty of Elixir separation of concerns that I’m still learning and coming across these great examples: instead of trying to cater for many different logging requirements by trying to configure Ecto, reconfigure at the Logger side!

2 Likes
5

Just tried my own advice and this unfortunately won’t work! :sob:

Docs say that

  • :function - purges all messages with the “function/arity” Remember that if you want to purge log calls from a dependency, the dependency must be recompiled.

So I first modified my logger config to find the logging function:

config :logger, :console,
  format: "$time\n[$level] $metadata\n$message\n\n",
  metadata: [:mfa, :file, :line]

That resulted in

[debug] mfa=Ecto.Adapters.SQL.log/4 file=lib/ecto/adapters/sql.ex line=938
QUERY OK …

But the ecto_sql library at line 938 invokes Logger.log/3 which warns that

The macros debug/2, info/2, notice/2, warning/2, error/2, critical/2, alert/2, and emergency/2 are preferred over this macro as they can automatically eliminate the call to Logger altogether at compile time if desired (see the documentation for the Logger module).

I added an explicit :debug case option to the log/4 source code in my deps folder and recompiled as instructed with mix deps.compile ecto_sql but it’s still logging?

:debug ->
  IO.puts("SQL debug")
  Logger.debug(
    fn -> log_iodata(measurements, metadata) end,
    ansi_color: sql_color(query_string)
  )

config.exs

config :logger, :console,
  format: "$time\n[$level] $metadata\n$message\n\n",
  metadata: [:mfa, :file, :line],
  compile_time_purge_matching: [
    [module: Ecto.Adapters.SQL, function: "log/4", level_lower_than: :info]
  ]

iex(1)> Repo.all(User)
SQL debug
14:02:05.547
[debug] mfa=Ecto.Adapters.SQL.log/4 file=lib/ecto/adapters/sql.ex line=939 
QUERY OK source="users" ...

Hopefully someone with more experience can provide some insight :pray:

3 Likes
6

Thank you all for suggestions! I haven’t had the time to try them all out, I will try tomorrow!

7

This has been frustrating me since I started with Elixir years ago. Kind of a crazy oversight imo. It seems that in production all SQL logs are hidden by default and that includes errors.

I’ve heard this again many times and it just doesn’t seem to be the case.

8

The first thing that comes to my mind is to disable default ecto logs and provide custom handler for [:myapp, :repo, :query] telemetry events.

1 Like
9

Logger configuration affects the entire application. :thinking:

In this case I only want to reduce verbosity of Ecto. Because I may have my own debug calls that I want to see in the console.

10

Ok, this works, at least for me, and in my particular case.

Given log: false in the config, I made a deliberate error in a query (idd instead of id):

  def get_page_data(id) do
    Quire.Repo.one(from(p in Page, where: p.idd == ^id, select: p))
  end

Ecto failed and printed the following error:

[error] #PID<0.1021.0> running QuireWeb.Endpoint (connection #PID<0.967.0>, stream id 8) terminated
Server: localhost:4000 (http)
Request: GET /admin/pages/33
** (exit) an exception was raised:
    ** (Ecto.QueryError) lib/quire/cms.ex:186: field `idd` in `where` does not exist in schema Quire.CMS.Page in query:

from p0 in Quire.CMS.Page,
  where: p0.idd == ^33,
  select: p0

No other debug logs. At this point this probably covers 99.999% of my needs.

@KristerV Give it a try. Quite possible if it wasn’t working for you it was a bug that was solved at one point.

3 Likes