logger_formatter_json

This is a formatter for the Erlang logger application that outputs JSON.

When logging text messages, it outputs the text message under the msg key along with logger metadata such as OpenTelemetry trace ids.

It also supports "structured" logging of maps, e.g. logger:info(#{foo => bar}). Metadata values can also be maps.

You can control the order of output keys to put the message first, avoiding having to read a big mess of JSON to find the important parts.

You can configure the names of output keys to support naming conventions from services such as Datadog and Google Cloud

It implements the formatter API for the high-performance logger application introduced in OTP 21.

It is written in Erlang with no dependencies except for the Erlang JSON library thoas. It can be used by pure Erlang projects as well as other BEAM languages such as Elixir.

Installation

Erlang:

Add logger_formatter_json to the list of dependencies in rebar.config:

{deps, [logger_formatter_json]}.

Elixir:

Add logger_formatter_json to the list of dependencies in mix.exs:

def deps do
  [
    {:logger_formatter_json, "~> 0.8"},
  ]
end

Configuration

JSON output is useful for production, as it allows you parse and query log records to, e.g., match on a particular user. It can be excessively verbose for development, however, so we stick with the normal Elixir logger for development. For Erlang, flatlog is a similar user-friendly library.

In order to make all log output in consistent JSON format, including system messages, we configure the formatter as the default for all applications running on the VM.

Erlang:

Configure the kernel default handler in the sys.config file for the release:

[
 {kernel, [
    {logger, [
        {handler, default, logger_std_h,
         #{formatter => {logger_formatter_json, #{}}}
        }
    ]},
    {logger_level, info}
 ]}
].

Elixir:

As of Elixir 15, we can override the formatter for the default log handler easily. In config/prod.exs configure :default_handler:

config :logger, :default_handler,
  formatter: {:logger_formatter_json, %{}}

Or, with options (see below):

config :logger, :default_handler,
  formatter: {
    :logger_formatter_json,
    %{
      template: [
        :msg,
        :time,
        :level,
        :file,
        :line,
        # :mfa,
        :pid,
        :request_id,
        :otel_trace_id,
        :otel_span_id,
        :otel_trace_flags
      ]
    }
  }

In older Elixir versions, it was tricky to configure the default handler from Elixir. Instead, we would reconfigure the default handler in the app startup.

In config/prod.exs or config/runtime.exs, define the formatter config:

config :foo, :logger_formatter_config, {:logger_formatter_json, %{}}

Or, with options (see below):

config :foo, :logger_formatter_config, {:logger_formatter_json,
 %{
   template: [
     :msg,
     :time,
     :level,
     :file,
     :line,
     # :mfa,
     :pid,
     :request_id,
     :otel_trace_id,
     :otel_span_id,
     :otel_trace_flags
   ]
 }}

Next, in in your application startup file, e.g., lib/foo/application.ex, add a call to reconfigure the logger:

def start(_type, _args) do
  logger_formatter_config = Application.get_env(:foo, :logger_formatter_config)

  if logger_formatter_config do
    :logger.update_handler_config(:default, :formatter, logger_formatter_config)
  end

If you want all the messages from the initial startup in JSON as well, you have to configure the logger as a VM arg for the release.

In rel/vm.args.eex, set up the logger:

-kernel logger '[{handler, default, logger_std_h, #{formatter => {logger_formatter_json, #{}}}}]'

or, with options:

-kernel logger '[{handler, default, logger_std_h, #{formatter => {logger_formatter_json, #{template => [msg, time, level, file, line, mfa, pid, otel_trace_id, otel_span_id, otel_trace_flags]}}}}]'

There used to be a way of doing this in Elixir, but it seems to have stopped working. In config/prod.exs or config/runtime.exs, define the formatter config:

if System.get_env("RELEASE_MODE") do
  config :kernel, :logger, [
    {:handler, :default, :logger_std_h, %{
       formatter: {:logger_formatter_json, %{}}
    }}
  ]
end

The check for the RELEASE_MODE environment variable makes the code only run when building a release.

Usage

The formatter accepts a map of options, e.g.:

config :foo, :logger, [
  {:handler, :default, :logger_std_h, %{
     formatter: {:logger_formatter_json, %{
          names: %{
            time: "date",
            level: "status",
            msg: "message"
          }
     }}
  }}
]

names is a map of keys in the metadata map to string keys in the JSON output.

The module has predefined sets of keys for datadog and gcp.

config :foo, :logger, [
  {:handler, :default, :logger_std_h, %{formatter: {:logger_formatter_json, %{names: :datadog}}}}
]

You can also specify a list to add your own tags to the predefined ones, e.g. of options, e.g. names: [datadog, %{foo: "bar"}].

types is a map which identifies keys with a special format that the module understands (level, system_time, mfa).

template is a list of metadata to format. This lets you put keys in specific order to make them easier to read in the output.

For example:

template: [
  :msg,
  :time,
  :level,
  :file,
  :line,
  :mfa,
  :pid,
  :otel_trace_id,
  :otel_span_id,
  :otel_trace_flags
]

List elements are metadata key names, with a few special keys:

• msg represents the text message, if any.

If you call logger:info("the message"), then it would be rendered in the JSON as {"msg": "the message", ...}. You can map the key msg to e.g. message via the names config option.

• all represents all the metadata keys.
• rest represents all the metadata keys which have not been handled explicitly.

You can specify a group of keys as a tuple like {group, <name>, [<list of metadata keys>]}, and they will be collected into a map in the output.

For example:

{group, source_location, [file, line, mfa]},
{group, tags, [rest]}

This would result in a log message like:

{
    ...
    "source_location": {"file": "mymodule.ex", "line": 17, "mfa": "mymodule:thefunction/1"},
    "tags": {"foo": "bar", "biz": "baz"}
}

The default template is [msg, rest].

You can also use a tuple to specify a standard set of keys to be used:

{keys, basic}: [time, level, msg]

{keys, trace}: [trace_id, span_id]

{keys, otel}: [otel_trace_id, otel_span_id, otel_trace_flags]

{keys, gcp}:

[
    msg,
    time,
    level,
    otel_trace_id,
    otel_span_id,
    {group, source_location, [file, line, mfa]},
    {group, tags, [rest]}
]

You can specify multiple templates, so you can add your own metadata keys to one of the standard templates, e.g., [{keys, basic}, request_id, trace_id, span_id].

When logging maps, default (embed) puts the map under the msg key. If you set the config option map_msg to merge, then the keys of the map will be merged into the metadata.

So logger:info(#{hi => there}} is logged as {"level":"info","hi":"there"}. This lets you control how the fields appear in the output with the template, e.g., a template of [level, biz] would result in output of {"level":"info","biz":"baz"} for the message logger:info(#{foo => bar, biz => baz}}.

Acknowledgements

Much thanks to Fred Hebert, as always. His flatlog library was a significant inspiration.

Links

• Erlang/OTP 21's new logger
• Canonical log lines