logger_json icon indicating copy to clipboard operation
logger_json copied to clipboard

[feature request] Support special metadata keys

Open benjreinhart opened this issue 2 months ago • 6 comments

Hello and thank you for this library! However, it seems that logger_json does not support the special metadata keys (or maybe a bug, not sure):

There are two special metadata keys, :module and :function, which extract the relevant bits from :mfa.

We would like to make use of the special module key, but it does not seem to work when using the Basic formatter. This is useful to us as we can use this to key off of in our observability tools with an exact match, rather than e.g. supply it manually or use :mfa and then match on starts_with/contains (less exact, can capture submodules).

🙏🏻 🙏🏻

Example

If I have a module MyApp.Foo.Bar with some calls to eg Logger.info and I use this configuration:

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

Then I see my logs contain a module=MyApp.Foo.Bar.

If I use this configuration:

config :logger,
  default_handler: [
    formatter: {LoggerJSON.Formatters.Basic, metadata: [:request_id, :module]}
  ]

I do not.

update

One other thing to note using the same configs above: If I explicitly add module metadata, the logger_json formatter will use the fully qualified module (ie Elixir.) whereas the other one will not.

defmodule MyApp.Foo.Bar do
  require Logger
  def log do
    Logger.info("log", module: __MODULE__)
  end
end
iex(6)> MyApp.Foo.Bar.log
{"message":"log","time":"2025-10-09T17:52:36.027Z","metadata":{"module":"Elixir.MyApp.Foo.Bar"},"severity":"info"}

vs

iex(2)> MyApp.Foo.Bar.log
[info] module=MyApp.Foo.Bar  log

It would be great if the behavior of logger_json could match that

benjreinhart avatar Oct 08 '25 23:10 benjreinhart

Hello @benjreinhart, you can simply use Logger.info("log", module: inspect(__MODULE__)) to get a proper module name.

As for not having a module in the default configuration, can you try this one and see what is logged?

config :logger,
  default_handler: [
    formatter: {LoggerJSON.Formatters.Basic, metadata: :all}
  ]

AndrewDryga avatar Oct 10 '25 17:10 AndrewDryga

you can simply use Logger.info("log", module: inspect(MODULE)) to get a proper module name

For sure, but that's something I only have to do when using LoggerJSON.Formatters.Basic. Ideally, the behavior would be the same between logger_json formatters and Elixir's built in formatters.

can you try this one and see what is logged?

Yep looks like it's there, so perhaps a bug when explicitly setting :module?

iex(2)> MyApp.Foo.Bar.log
{"message":"log","time":"2025-10-10T17:54:21.502Z","metadata":{"line":4,"module":"Elixir.MyApp.Foo.Bar","file":"iex","domain":["elixir"],"mfa":"Elixir.MyApp.Foo.Bar.log/0"},"severity":"info"}

benjreinhart avatar Oct 10 '25 17:10 benjreinhart

For sure, but that's something I only have to do when using LoggerJSON.Formatters.Basic. Ideally, the behavior would be the same between logger_json formatters and Elixir's built in formatters.

It depends on how you use the standard formatter. Previously, you would also get a string prefixed with Elixir.:

iex(3)> Logger.info(Kernel)
warning: passing Kernel to Logger is deprecated, expected a map, a keyword list, a string, a list of strings, or a zero-arity anonymous function
  (logger 1.18.3) lib/logger.ex:977: Logger.__do_log__/4
  (elixir 1.18.3) src/elixir.erl:386: :elixir.eval_external_handler/3
  (stdlib 6.2.2) erl_eval.erl:919: :erl_eval.do_apply/7
  (elixir 1.18.3) src/elixir.erl:364: :elixir.eval_forms/4
  (elixir 1.18.3) lib/module/parallel_checker.ex:120: Module.ParallelChecker.verify/1
  (iex 1.18.3) lib/iex/evaluator.ex:336: IEx.Evaluator.eval_and_inspect/3

13:42:05.788 [info] Elixir.Kernel
:ok
iex(4)> Logger.info(module: Kernel)

13:42:19.691 [info] [module: Kernel]
:ok

This comes from different ways in which an atom module name is encoded:

iex(11)> to_string(Kernel)
"Elixir.Kernel"
iex(12)> inspect(Kernel)
"Kernel"

Changing this will be a breaking change, and we will have to keep a deprecation warning for a while before doing a change like that, because some people may actually use that name as a filter today. So I think it's just not worth the effort. The outputs of the standard Logger and LoggerJSON are not compatible anyway.

Yep looks like it's there, so perhaps a bug when explicitly setting :module?

It's not a bug. There is no goal to be option-compatible with the standard logger; we don't do :module and :function extraction or anything like that, instead we just read/ignore the keys that are already there. You can change the default behaviour, just copy-paste the BasicFormatter and modify it's behaviour for your application.

AndrewDryga avatar Oct 10 '25 20:10 AndrewDryga

I am surprised by "There is no goal to be option-compatible with the standard logger" as I would think that's a worthy goal, but I hear you

benjreinhart avatar Oct 10 '25 20:10 benjreinhart

@AndrewDryga We've been adding module manually in two ways:

  1. Explicitly in some Logger.info/error/etc calls
  2. Logger.metadata() for some genserver processes.

However, those have the following drawbacks:

  1. Adding it in all the Logger.info/error/warng calls is of course tedious
  2. Logger.metadata tags logs by process, not module, which isn't necessarily the same
  3. Writing a wrapper around Logger means we change all our code and diverge from the standard logger

Whether or not you have a "goal to be option-compatible with the standard logger", the desired behavior documented by this issue is valuable. A bonus is that it's also the same behavior the standard logger provides. Implementation-wise, it seems low cost to write and maintain and without runtime drawbacks (that I'm aware of). Lastly, there's a PR that aims to solve this in #165.

Given all that, I'm struggling to see why this isn't something worth checking in?

benjreinhart avatar Oct 16 '25 22:10 benjreinhart

@benjreinhart I was not suggesting adding a wrapper. I would literally copy-paste this file into the project (it's just 100 LOC) and then edit it to produce any format you want; it still will depend on the hex package (eg. for safe encoding), and you will need to change formatter settings in the config. Rest will remain the same. Does that sound reasonable?

AndrewDryga avatar Oct 17 '25 16:10 AndrewDryga