Emit notice logs in :console backend #11304

riccardomanfrin · 2021-10-08T12:55:51Z

yes.. this is not very "backward compatible"..
I guess adding some config flag to enable it, and
default it to false.. would be proper (?)

josevalim · 2021-10-08T13:09:52Z

Yes, unfortunately we cannot introduce this as it would break all existing Logger backends, as they will now receive a format they don't know how to handle. However, what we can do instead is to change the erlang_metadata_to_elixir_metadata function to have a erlang_level key in it. And we can use this erlang_level key in the console backend. Can you please try this route?

zoten · 2021-10-08T13:46:44Z

@josevalim an erl_level metadata is already injected into the metadata, I think we could use directly this.

Is a little overhead (keyword find) in re-translating back elixir level into erlang level acceptable in :console backend?

yes.. this is not very "backward compatible".. I guess adding some config flag to enable it, and default it to false.. would be proper (?)

riccardomanfrin · 2021-10-08T14:00:25Z

I've added support for :notice in the formatter.ex and changed the console.ex backend.. I hope this is limiting the propagation of the :notice to only the console backend, leaving the rest of backends happy (the key was there already as erl_level)

Is this what you meant?

It's in any case breaking the format of preexisting log collections in case someone was logging to notice.

lib/logger/lib/logger/backends/console.ex

Co-authored-by: José Valim <jose.valim@gmail.com>

lib/logger/lib/logger/formatter.ex

Co-authored-by: José Valim <jose.valim@gmail.com>

lib/logger/lib/logger/backends/console.ex

Co-authored-by: Alberto Sartori <alberto.sartori.as@gmail.com>

albertored · 2021-10-08T15:01:14Z

we should also convert back erlang :warning level to :warn

albertored · 2021-10-08T15:16:44Z

In addition, the same logic should be used also in the buffer_event function so maybe is cleaner to move it in the handle_event function.

In this way, it goes also through the meet_level? function so it is possible to specify erlang log levels as the minimum level for a message to be logged. Not sure if this is the intended behavior though

riccardomanfrin · 2021-10-08T15:19:28Z

In addition, the same logic should be used also in the buffer_event function so maybe is cleaner to move it in the handle_event function.

In this way, it goes also through the meet_level? function so it is possible to specify erlang log levels as the minimum level for a message to be logged. Not sure if this is the intended behavior though

unintended at all.

josevalim · 2021-10-08T15:22:32Z

lib/logger/lib/logger/backends/console.ex

+    level = case level do
+      :warning -> :warn
+      _ -> level
+    end


No, let's not convert back. Logger.warn is already deprecated, so it is a good opportunity to move to warning. :)

josevalim · 2021-10-08T15:26:07Z

@riccardomanfrin also please take a look at CI. We need to add at least two tests:

That we are now logging notice in the actual message
That we can filter on the backend using notice and similar

What about pad levels?

lib/logger/lib/logger/backends/console.ex

josevalim · 2021-10-08T17:23:03Z

@riccardomanfrin there is a failure in ex_unit suite now because of the changes: make test_ex_unit. :) Should be a quick fix!

josevalim · 2021-10-08T19:05:16Z

/cc @hauleth in case you want to review it too.

lib/logger/test/logger/backends/console_test.exs

lib/logger/test/logger/handler_test.exs

hauleth

Ignoring all the comments, I have different concept how we can add support for more features from Erlang logger instead.

add new optional callback for the backends, for example type/0 that will return :legacy | :rich and will default to :legacy if not defined
for :legacy backends receives message in the current, tuple based, format
for :rich (can use different name there) backend receives message in "raw" format from the Erlang (possibly with some alterations to wrap :report_cb for example)

This approach should give us a way to make full transition in future (possibly still in multiple steps).

What do you think @josevalim about such approach? It would give a way to have smother transition period, and possibly migrate to "new" format even without bumping Logger's major version (which would imply bumping Elixir's major version).

hauleth · 2021-10-09T12:42:38Z

lib/logger/lib/logger/backends/console.ex

@@ -138,6 +138,8 @@ defmodule Logger.Backends.Console do
  def handle_event({level, _gl, {Logger, msg, ts, md}}, state) do
    %{level: log_level, ref: ref, buffer_size: buffer_size, max_buffer: max_buffer} = state

+    {:erl_level, level} = List.keyfind(md, :erl_level, 0, {:erl_level, level})


md is defined to be keyword list, so why use List.keyfind/4 instead of Keyword.get/3?

Both are fine. List.keyfind can be a tiny bit more efficient.

hauleth · 2021-10-09T12:43:07Z

lib/logger/lib/logger/formatter.ex

@@ -163,10 +163,10 @@ defmodule Logger.Formatter do
  defp output(:levelpad, level, _, _, _), do: levelpad(level)
  defp output(other, _, _, _, _), do: other

-  defp levelpad(:debug), do: ""
+  # TODO: Deprecate me on Elixir v1.13+ or later


levelpad is not very useful now when one of the levels is "critical". There will be just too much padding on something like "info" (4 chars to be more precise).

hauleth · 2021-10-09T12:46:04Z

lib/logger/lib/logger/backends/console.ex

+      alert: Keyword.get(colors, :debug, :red),
+      critical: Keyword.get(colors, :debug, :red),
+      emergency: Keyword.get(colors, :debug, :red),


I think it should be:

Suggested change

alert: Keyword.get(colors, :debug, :red),

critical: Keyword.get(colors, :debug, :red),

emergency: Keyword.get(colors, :debug, :red),

alert: Keyword.get(colors, :alert, :red),

critical: Keyword.get(colors, :critical, :red),

emergency: Keyword.get(colors, :emergency, :red),

However in my logger_colorful I have used background color for all these levels to mark that it is "higher than error".

Good catch. Those should be all error. We should add a fallback for custom colors in another PR.

hauleth · 2021-10-09T12:47:02Z

lib/logger/lib/logger/backends/console.ex

      error: Keyword.get(colors, :error, :red),
+      notice: Keyword.get(colors, :info, :normal),
      enabled: Keyword.get(colors, :enabled, IO.ANSI.enabled?())
    }


Order of the keys in this map is now weird. Earlier it was in decreasing verbosity, and now it is "whatever".

josevalim · 2021-10-09T14:39:51Z

@hauleth thanks for the review. What you described is precisely the plan for #7328. The idea is that the old handlers will be wrapped by an internal gen_event handler and the new handle_event message will be much closer to what Erlang emits. I would say this PR is something necessary to help us get there, so the backend is already ready for the new version.

josevalim · 2021-10-09T14:56:34Z

💚 💙 💜 💛 ❤️

hauleth · 2021-10-09T15:13:35Z

@josevalim you probably meant #7928. I can see if I can craft something like that as a part of Hacktoberfest.

I wouldn't say that it is strictly needed to get us there, but for sure can ease transition period (unless I really will be able to craft my PR before 1.13).

josevalim · 2021-10-09T15:55:42Z

Yes, correct on both. :)

Emit notice logs in :console backend

cc55a82

yes.. this is not very "backward compatible".. I guess adding some config flag to enable it, and default it to false.. would be proper (?)

riccardomanfrin force-pushed the master branch from e654458 to cc55a82 Compare October 8, 2021 13:57

Adds higher-than-error level colors (in red)

f434078

josevalim reviewed Oct 8, 2021

View reviewed changes

lib/logger/lib/logger/backends/console.ex Outdated Show resolved Hide resolved

Update lib/logger/lib/logger/backends/console.ex

3a3a304

Co-authored-by: José Valim <jose.valim@gmail.com>

josevalim reviewed Oct 8, 2021

View reviewed changes

lib/logger/lib/logger/formatter.ex Outdated Show resolved Hide resolved

Update lib/logger/lib/logger/formatter.ex

7df3574

Co-authored-by: José Valim <jose.valim@gmail.com>

albertored reviewed Oct 8, 2021

View reviewed changes

lib/logger/lib/logger/backends/console.ex Outdated Show resolved Hide resolved

Update lib/logger/lib/logger/backends/console.ex

3a59e1d

Co-authored-by: Alberto Sartori <alberto.sartori.as@gmail.com>

convert back erlang :warning level to :warn

80ba8cf

Allows meet_level to work on actual level

6278877

josevalim reviewed Oct 8, 2021

View reviewed changes

Migrate to warning

f2aa3e4

What about pad levels?

josevalim reviewed Oct 8, 2021

View reviewed changes

lib/logger/lib/logger/backends/console.ex Outdated Show resolved Hide resolved

josevalim reviewed Oct 8, 2021

View reviewed changes

lib/logger/lib/logger/backends/console.ex Outdated Show resolved Hide resolved

We cannot change the public APi but use warning internally

dda2092

josevalim reviewed Oct 8, 2021

View reviewed changes

lib/logger/lib/logger/backends/console.ex Outdated Show resolved Hide resolved

josevalim and others added 4 commits October 8, 2021 17:44

Update lib/logger/lib/logger/backends/console.ex

502c2af

Tests fixed

58b3383

Tests we are now logging notice in the actual message

d1eb8cd

Test we can filter on the backend using notice

1cc427a

Update capture_log_test.exs

0bfbf84

josevalim reviewed Oct 8, 2021

View reviewed changes

lib/logger/test/logger/backends/console_test.exs Outdated Show resolved Hide resolved

Update lib/logger/test/logger/backends/console_test.exs

fd3bb45

josevalim reviewed Oct 8, 2021

View reviewed changes

lib/logger/test/logger/handler_test.exs Outdated Show resolved Hide resolved

Update lib/logger/test/logger/handler_test.exs

5ee8aad

hauleth suggested changes Oct 9, 2021

View reviewed changes

Update console.ex

f67af5f

josevalim merged commit 2af0411 into elixir-lang:master Oct 9, 2021

Emit notice logs in :console backend #11304

Emit notice logs in :console backend #11304

Uh oh!

Conversation

riccardomanfrin commented Oct 8, 2021

Uh oh!

josevalim commented Oct 8, 2021

Uh oh!

zoten commented Oct 8, 2021

Uh oh!

riccardomanfrin commented Oct 8, 2021

Uh oh!

Uh oh!

Uh oh!

Uh oh!

albertored commented Oct 8, 2021

Uh oh!

albertored commented Oct 8, 2021

Uh oh!

riccardomanfrin commented Oct 8, 2021

Uh oh!

josevalim Oct 8, 2021

Choose a reason for hiding this comment

Uh oh!

josevalim commented Oct 8, 2021

Uh oh!

Uh oh!

Uh oh!

Uh oh!

josevalim commented Oct 8, 2021

Uh oh!

josevalim commented Oct 8, 2021

Uh oh!

Uh oh!

Uh oh!

hauleth left a comment

Choose a reason for hiding this comment

Uh oh!

hauleth Oct 9, 2021

Choose a reason for hiding this comment

Uh oh!

josevalim Oct 9, 2021

Choose a reason for hiding this comment

Uh oh!

hauleth Oct 9, 2021

Choose a reason for hiding this comment

Uh oh!

josevalim Oct 9, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

hauleth Oct 9, 2021

Choose a reason for hiding this comment

Uh oh!

josevalim Oct 9, 2021

Choose a reason for hiding this comment

Uh oh!

hauleth Oct 9, 2021

Choose a reason for hiding this comment

Uh oh!

josevalim commented Oct 9, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

josevalim commented Oct 9, 2021

Uh oh!

hauleth commented Oct 9, 2021

Uh oh!

josevalim commented Oct 9, 2021

Uh oh!

Uh oh!

josevalim Oct 9, 2021 •

edited

Loading

josevalim commented Oct 9, 2021 •

edited

Loading