Example of using Logger.metadata

Given the following entry in your config file:

config :logger, :console, format: "[$level] $metadata$message\n",
  metadata: [:module, :function, :my_id]

You can do the following;

iex(1)> require Logger
Logger
iex(2)> Logger.info "test"
[info] module= function= test
:ok
iex(3)> Logger.info "test", [my_id: 123]
[info] module= function= my_id=123 test
:ok
iex(4)> Logger.metadata [my_id: 999]
:ok
iex(5)> Logger.info "another test"
[info] module= function= my_id=999 another test
:ok
iex(6)>

I added the :module and :function into the meta data, as an example of other meta data you might want. However, since I’m running it from iex, the don’t print anything useful.

This is exactly what I was looking for. Thank you!

One thing to note about Logger.metadata is that it is set only for the current process. From the documentation

## Metadata

Metadata to be sent to the Logger can be read and written with the
Logger.metadata/0 and Logger.metadata/1 functions. For example, you can set
Logger.metadata([user_id: 13]) to add user_id metadata to the current process.
The user can configure the backend to chose which metadata it wants to print
and it will replace the $metadata value.

@minhajuddin That is a good point. Glad you emphasis that.

It does, however, lend itself to a model where you have a process for each item in some collection. By setting metadata for that process at startup (presumedly with some id or name) its an easy way to identify the logs for the given item of the collection.

That’s the route I’ve gone thanks to your advice. Very helpful.

Glad I found this, because I was logging like:

[warn] | Elixir.Auth.Csrf Error for :auth_csrf_secret in the session: missing.

and now:

[warn] | module=Auth.Csrf function=valid_session?/1 line=54  | Error for :auth_csrf_secret in the session: missing.

This is way better logging. In my opinion should be the default

To log this I use in runtime.exs:

config :logger, :default_formatter,
# 18:29:12.987 | error | module=MyApp.Some.Module function=some_function/arity line=some_number  | some message here
  format: "$time | $level | $metadata | $message\n",
  metadata: [
    :request_id,
    :module,
    :function,
    :line
  ]

To improve the logger metadata I use this function:

def enhance_metadata(%{} = metadata) do
    context_hash = :crypto.hash(:md5, inspect(metadata)) |> Base.encode16()

    %{
      log_id: UUIDv7.generate(),
      context_hash: context_hash,
      context: metadata
    }
  end

And the updated config:

config :logger, :default_formatter,
  # 22:44:55.512 |> error |> "some good reason" |> log_id=0199e4e5-e458-78d8-b623-31539c4db8b5 context_hash=4C0CAE343D9B60CADC8BD53D5BB84563 module=EmCanvas.Canvas.Items.AllPositions.ListAllItemsPositions function=list/1 line=18
  format: "$time |> $level |> $message |> $metadata\n",
  metadata: [
    :request_id,
    :log_id,
    :context_hash,
    :module,
    :function,
    :line
  ]