Deep Dive into Elixir Logger

1 day ago 2

When your application suddenly fails at 3 AM, logs will be your best friend the next morning. But until this happens, we often treat logs as an afterthought. Sometimes there is a discussion on log levels or wording of the message, but we rarely go beyond that. After all, what's so interesting in pushing out a bunch of letters, perhaps with some additional metadata, which we will not use 95% of the time?

The Elixir Logger module has us covered well. It's a solid foundation for our basic logging needs. But behind its superficial simplicity hides a powerful beast. Perhaps getting to know it better, tame it -- if you will, can take our observability game to the next level?

In this article, I will cover some more in-depth aspects of the Elixir Logger. I hope you will find them interesting.

Log levels and their configuration

Just to quickly recap on Elixir Logger and how to use it.

First, you need to require it in the module you use:

defmodule MyApp do require Logger end

After that, we can use the Logger like this:

Logger.info("Application started...")

... or like this:

Logger.error("Something really bad happened!")

error, warning, info, and debug are the most used log levels. They are ordered like this - from the most dire to the least interesting. We can draw the line to define what is interesting. For example, by default in a production Phoenix app, we don't use logs with debug, only info and above. This is defined by this line in config/prod.exs:

# Do not print debug messages in production config :logger, level: :info

prod.exs is evaluated at compile time, and all logs in this environment below the :info level are filtered out. But are they always? Not necessarily. Logger supports runtime configuration, so we can change it even with the application already compiled and running. This is as simple as calling Logger.configure(level: :debug) somewhere. A common place would be inside a live iex session attached to the production application.

Turning on the debug level for the whole application will likely flood us with messages. But often we just need to have a better look at a single suspicious module in the app. Again, Elixir has our back here. We can change the level just for a single module like this:

Logger.put_module_level(MyApp.VeryShadyPriceCalculator, :debug)

Now, only debug logs from the module we want to observe will start being printed.

Formatting log messages with a formatter

Logging is generally simple. You tell it to log a string, it logs a string (and some metadata, like current timestamp or maybe an OTP application it originates in). We can adjust how the logs look though. The simplest approach is to do that in the config file. As an example, this entry in config.exs:

config :logger, :default_formatter, format: "\n$time $metadata[$level] $message\n",

... will result in the following message:

23:15:25.714 [info] this is a test

This gives us some options, but maybe not enough for our creative needs? Let's define a custom formatter instead!

defmodule MyLogFormatter do def format(level, message, timestamp, _metadata) do [ inspect(timestamp), " ", message |> IO.chardata_to_string() |> String.reverse(), "\n" ] end end # and in config.exs config :logger, :default_formatter, format: {MyLogFormatter, :format}

Now our log messages have a distinct taste.

{{2025, 8, 29}, {23, 39, 29, 111}} tset a si siht

You can also notice a format in which the timestamp is passed. Hint: you can use Date.from_erl!/2 and Time.from_erl!/3 to parse it into something more digestible by a fellow human.

A classic example of a widely used formatter is logger_json, which logs messages as a JSON string. But hey, if you want to format them as XML instead, I'm not judging, and you now know the basics of how to do that.

Elixir Logger backends

Logs are printed to the terminal from which the application was started. It makes sense as a default, but what if you would like something different? Perhaps without a surprise, Elixir's Logger supports it out of the box. A destination for the log messages is called a backend, and the console backend is the default one.

A backend is a bit more complicated than a formatter. It needs to implement Erlang's gen_event behaviour. But when you do that, the sky is the limit. You can send the logs to some API, save them in your database or... just inspect what comes, to learn more about how this even works. We are going to do the last one here.

defmodule InspectBackend do @behaviour :gen_event def init(_), do: {:ok, []} def handle_call(message, state) do IO.inspect(message, label: "Message of handle_call") {:ok, state} end def handle_event(message, state) do IO.inspect(message, label: "Message of handle_event") {:ok, state} end def handle_info(message, state) do IO.inspect(message, label: "Message of handle_info") {:ok, state} end def code_change(_, state, _), do: {:ok, state} def terminate(_, _), do: :ok end

In the module above, we have just implemented all the required callbacks of gen_event, but they don't do a lot -- just IO.inspect the incoming argument and don't modify the state.

Let's now add this to our Logger configuration:

config :logger, backends: [InspectBackend]

The config is a list because Logger supports multiple backends within a single application. We do configure just one here, though, for simplicity. After running a test log statement, we will see a result similar to this:

Message of handle_event: {:info, #PID<0.70.0>, {Logger, "this is a test", {{2025, 8, 30}, {0, 18, 57, 243}}, [ erl_level: :info, pid: #PID<0.95.0>, time: 1756505937243940, gl: #PID<0.70.0>, domain: [:elixir] ]}} Message of handle_event: :flush

Again, it's up to you what to do with it. One specific example of using a custom backend is Honeybadger's Elixir integration, which uses a logger backend to send error logs to the Honeybadger API. A nice thing about Honeybadger is that you don't have to set this up yourself—you can install the client library and it will automatically report errors and application events. But if you like, you can put your logs in a message queue for further async processing.

Logs filtering

Some things are not meant to be logged. Some messages might be rejected as a whole, while others need to be modified before reaching our logging services. This is also possible with Elixir (although with a little twist, as we shall soon see).

Filterers can do one of three things:

They can just pass on the intact message to the next filterer, if it exists
Reject the whole message
Modify a message and pass it on

The first option is not interesting, but we will implement something for the remaining two. You can filter on multiple things, often on a domain or on the level, but the most common use case for filterers is to leverage logger metadata.

Detour: What is Logger metadata?

So far, we have been using just a bare form of the Logger, such as Logger.info("message"). However, you can pass a second argument to Logger's function, and it will be the infamous metadata. Let's see this in action with our InspectBackend we defined above. We call:

Logger.warning("this is a warning", %{serious: true, area: "test"})

And this is what we get:

Message of handle_event: {:warn, #PID<0.70.0>, {Logger, "this is a warning", {{2025, 8, 30}, {0, 50, 13, 999}}, [ erl_level: :warning, pid: #PID<0.95.0>, time: 1756507813999091, gl: #PID<0.70.0>, domain: [:elixir], serious: true, area: "test" ]}}

The last part, after the timestamp, is the metadata. You can see that some of it is added by the Logger itself, and it's merged with our custom metadata.

Armed with that knowledge, we can write our filterer, which:

Skips warning messages that are not serious
Adds a screaming prefix to error messages

Implementing our own filterer

Similar to the formatter, the filterer is just a function inside a module.

defmodule Filterer do def filter_out_non_serious(%{level: :warning, meta: metadata}, _) do if metadata[:serious], do: :ignore, else: :stop end def filter_out_non_serious(_, _), do: :ignore end

If the filterer returns :stop, the message is discarded. :ignore passes the message on. Let's produce a bunch of logs and then check what we see in the console.

:logger.add_primary_filter(:non_serious, {&Filterer.filter_out_non_serious/2, []}) Logger.warning("this is a warning", %{serious: true}) Logger.warning("this is a meh", %{serious: false}) Logger.warning("I didn't care enough to set seriousness") Logger.error("there was an error while running this")

This is the expected output:

01:13:06.222 [warning] this is a warning 01:13:06.226 [error] there was an error while running this

Now we know how to reject or allow the log message, but how about altering it? Filter can do that too! We'll add one additional filter.

def mod_error(%{level: :error, msg: {:string, msg}} = event, _) do %{event | msg: {:string, "EPIC FAIL! #{msg}"}} end def mod_error(_, _), do: :ignore

We need to remember to add it as a logger filter. And if you recall that I said there's a twist, this is it. Elixir's Logger itself does not provide any convenience for log filtering. But it's based on Erlang's logger, which means we can configure Erlang's logger directly, like this:

:logger.add_primary_filter(:non_serious, {&Filterer.filter_out_non_serious/2, []}) :logger.add_primary_filter(:fail_mod, {&Filterer.mod_error/2, []})

And the result is as expected:

01:23:15.841 [warning] this is a warning 01:23:15.844 [error] EPIC FAIL! there was an error while running this

The examples above are rather silly, but don't get the wrong idea. The filterer is a powerful concept, with which you can filter out PII, other sensitive data (such as passwords), but sometimes it also formats and truncates messages that are too long for your backend.

Structured logging

So far, we have been logging only strings. However, this is not our only option. Elixir supports other structures as a log message just fine. By default, it will render it as a keyword list, no matter if you log a proper keyword list, a map, or even a struct.

Logger.info(%{test: false, this_is: %{year: 2025}}) Logger.info(test: true, this_is: %{year: 2025}) Logger.info(%Weight{amount: 10, unit: :kg})

The result is

01:32:09.030 [info] [test: false, this_is: %{year: 2025}] 01:32:09.043 [info] [test: true, this_is: %{year: 2025}] 01:32:09.043 [info] [unit: :kg, __struct__: Weight, amount: 10]

We can alter this using the Logger.Translator behaviour. As per documentation, it was designed to translate the raw-ish Erlang logs to more friendly Elixir-land logs, but nothing stops us from using it to our advantage. Let's take the Weight struct example. We will write a super-simple translator:

defmodule WeightTranslator do @behaviour Logger.Translator @impl true def translate(_min_level, _level, _kind, message) do case message do {:logger, %Weight{amount: amount, unit: unit}} -> {:ok, "#{amount} #{unit} of weight"} _ -> :none end end end

Now, if we run the same log operation as above, the result will be different:

23:30:12.761 [info] [test: false, this_is: %{year: 2025}] 23:30:12.767 [info] [test: true, this_is: %{year: 2025}] 23:30:12.768 [info] 10 kg of weight

One could argue that a filterer and a translator could do roughly the same - skip the message, translate its content, or leave it intact. This is true -- technically, they have the same capabilities. The difference lies in their intention: one should mainly decide whether or not to print the message at all, and the other concentrates on modifying the content.

Four levers of an informed logging system for Elixir

I hope this article helped you learn a few things about logging in Elixir:

WHEN to log, using log level, possibly with a runtime and per-module reconfiguration
HOW to log it, using the formatter
WHERE to log it, using different logger backends
WHAT to log, making a decision either with a filterer or with a translator

This will allow you to leverage the Elixir Logger more efficiently when working on your projects. We also learned what Honeybadger uses to get your error logs to their service. If you want to try this out yourself, sign up for a free trial of Honeybadger.

Read Entire Article