hauleth

hauleth

Call for testers: new Elixir Logger backend

As some of you are aware (and the rest will be if they read this post) the OTP 21 introduced new logger module which provides real-life logger to the Erlang itself. For a long time (I think that Elixir 1.7 was the first one with integration) Elixir was hooking into it to listen for messages sent by Erlang libraries, but it was only one way integration (so messages sent by Elixir wasn’t available to Erlang handlers).

But it is no more, as PR 9333 was merged to the master, now Logger is a thin wrapper over Erlang’s built in functionality with compatibility layer on top to support all backends that already are there.

However that one is a huge change and I with @josevalim were working on it for over a month to find all problems and provide good implementation. We are pretty confident with the implementation, but nothing is better than testing in production. So this is time for all of You, embrace your fears and boldly go where no one has gone before. We need You to test it with your applications (of course locally, we do not encourage anyone to test it in real production).

Please, test it, break it, report it.


For those who are interested in “what it will give us anyway?”:

  • Unified metadata between loggers (and potentially other libraries like opentelemetry)
  • Out of the box integration with Lager as Lager hooks into logger as well
  • Built in support for logging to disk via logger_disk_log_h

These are for now, in future the changes will include:

  • Additional log levels (notice, critical, alert, emergency)
  • Support for structured logging
  • Module and application level control about logs verbosity

But anyway, play with it, test it, and if you break it, let us know so we can polish it before final release of 1.10 (oh, by the way this will make Elixir 1.10 OTP 21+ only).

First Post!

josevalim

josevalim

Creator of Elixir

Most Liked

hauleth

hauleth

Yeah, it seems like there is first bug :wink: Thanks

The point is that :warn used by Elixir Logger is now :warning form the Erlang, but there should be translation from old format to the new format. This was done, but in the meantime we have changed code a little to provide given message, and the translation perished. Will provide fix in a moment.

sneako

sneako

Thanks for these contributions! I installed elixir master using asdf:

asdf install elixir ref:67dec4683de49e6e8153f9c49d0a0a179c550f9f

and gave it a try in a phoenix app where I have:

config :logger, level: :warn

And I get:

Erlang/OTP 22 [erts-10.4.3] [source] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] [hipe]

warning: the level for Erlang's logger was set to :debug, but Elixir's logger was set to :warn. Elixir's logger value will take higher precedence
  (logger 1.10.0-dev) lib/logger/app.ex:96: Logger.App.add_elixir_handler/2
  (logger 1.10.0-dev) lib/logger/app.ex:24: Logger.App.start/2
  (kernel 6.4.1) application_master.erl:277: :application_master.start_it_old/4

** (MatchError) no match of right hand side value: {:error, {:bad_return, {{Logger.App, :start, [:normal, []]}, {:EXIT, {{:badmatch, {:error, {:invalid_level, :warn}}}, [{Logger.App, :add_elixir_handler, 2, [file: 'lib/logger/app.ex', line: 103]}, {Logger.App, :start, 2, [file: 'lib/logger/app.ex', line: 24]}, {:application_master, :start_it_old, 4, [file: 'application_master.erl', line: 277]}]}}}}}
    (mix 1.10.0-dev) lib/mix/cli.ex:106: Mix.CLI.restart_logger/0
    (mix 1.10.0-dev) lib/mix/cli.ex:82: Mix.CLI.run_task/2
    (elixir 1.10.0-dev) lib/code.ex:912: Code.require_file/2

So the first thing to note is that the log level :warn is deprecated, but is there also a new way to configure the log level?

Trying level: :info or level: :warning produce a similar warning, but no match error, and logging seems to work as usual.

dom

dom

Very excited about this. Thanks for all your work!

I’m curious what approach you have in mind for structured logging. So far I’ve been doing it this way:

  • At the call site, pass structured data via metadata:
      Logger.log(level, "Processing request",
        method: conn.method,
        path: conn.request_path,
        ...
      )
    
  • Define a custom formatter which takes all metadata:
    config :logger, :file_log,
      path: "app.log",
      level: :info,
      format: {MyApp.Logger, :format},
      metadata: :all
    
  • In the formatter, generate JSON, roughly like:
    def format(level, message, timestamp, metadata) do
     %{
        "timestamp" => format_timestamp(timestamp),
        "level" => level,
        "message" => IO.iodata_to_binary(message)
      }
      |> add_metadata(metadata)
      |> Jason.encode!()
    end
    
    where add_metadata reads each key/value pair from metadata, converts the value to a printable representation, and adds it to the event map, similar to Honeybadger.JSON.

It works, but it’s not ideal - we had to reimplement functionality from the default formatter, for instance formatting time or converting PIDs to strings. OTP reports also can’t be structured, because they’re a string blob by the time they reach the formatter (not a huge deal though).

Could we achieve JSON logging more easily with the new backend, or with future development?

Last Post!

hauleth

hauleth

You can use 'test.log' instead.

Where Next?

Popular in Discussions Top

New
Crowdhailer
I’ve been hearing much about the new formatter and it’s something I have been keen to try. I find examples buy far the most illuminating...
248 19814 150
New
rower687
Hi all, I’ve been reading a lot about the “let it crash” term and how supervising processes and the whole messaging passing make an elixi...
New
joeerl
I’m playing with Elixir - It’s fun. I think @rvirding does give Elixir courses these days. Re: files and database - when I given Erlang ...
New
PragTob
Hey everyone, this has been brewing in my head some time and it came up again while reading Adopting Elixir. GenServers, supervisors et...
New
PragTob
Hello everyone, I know we had quite some threads (read through lots of them) about background job processing but it remains a hotly deba...
New
tomekowal
Hey guys! I want to create a toy project that shows a chart of temperature over time and updates every 5 seconds. I feel LiveView is per...
New

Other popular topics Top

Qqwy
Original source of discussion: This topic on the Pragmatic Programmers’ Functional Web Development with Elixir, OTP, and Phoenix forum. ...
New
New
hariharasudhan94
Lets say I have map like this fetching from my database %{"_id" => #BSON.ObjectId<58eb1a7a9ad169198c3dXXXX>, "email" => ...
New
msaraiva
Surface is an experimental library built on top of Phoenix LiveView and its new LiveComponent API that aims to provide a more declarative...
564 44265 214
New
siddhant3030
Hi, I have to write a raw query for one of my project. But till now I have used ecto queries and don’t have much experience writing raw ...
New
Patoshizzle
After calling mix ecto.create I get this error: 17:00:32.162 [error] GenServer #PID<0.412.0> terminating ** (Postgrex.Error) FATAL...
New

We're in Beta

About us Mission Statement