JSON logging in Elixir using a Custom Formatter

Elixir logging is awesome and extensible. You can write your own backend or a Formatter and make endless combinations with unlimited possibilities. JSON logs are the norm nowadays and there are plenty of ways to get JSON logs in #elixir. Ink 💪 is an awesome hex package to make that happen. Add it to your project and all your logs will become JSON. There were 2 shortcomings though for me

1. It only writes to stdout, though that would work in most cases but when you have to write to file it hits a wall.
2. Is not an Ink issue per se but a Plug "feature" where it logs 2 entries, first of the endpoint invoked and second of the repsonse and execution time.

The 2nd issue makes it difficult to have all the information to a request on a single object and also it repeats data such as request-id and process. Also it doesn't even adds the user-agent to the request. To do that you need to add it your self in the metadata.

Fret not there is a solution to the logging of plug request 😎 plug_json_logger FTW.

bleacherreport / plug_logger_json

Elixir Plug that formats http request logs as json

PlugLoggerJson

A comprehensive JSON logger Plug.

Dependencies

• Plug
• Poison

Elixir & Erlang Support

The support policy is to support the last 2 major versions of Erlang and the three last minor versions of Elixir.

Installation

1. add plug_logger_json to your list of dependencies in mix.exs:

   def deps do
     [{:plug_logger_json, "~> 0.7.0"}]
   end

2. ensure plug_logger_json is started before your application (Skip if using Elixir 1.4 or greater):

   def application do
     [applications: [:plug_logger_json]]
   end

3. Replace Plug.Logger with either:

   • Plug.LoggerJSON, log: Logger.level,
   • Plug.LoggerJSON, log: Logger.level, extra_attributes_fn: &MyPlug.extra_attributes/1 in your plug pipeline (in endpoint.ex for Phoenix apps),

Recommended Setup

Configure plug_logger_json

Add to your config/config.exs or config/env_name.exs if you want to filter params or headers or suppress any logged keys:

config :plug_logger_json
  filtered_keys: ["password", "authorization"],
  suppressed_keys: ["api_version", "log_type"]

Configure the

…

View on GitHub

plug_json_logger solves the 2nd issue as it combines both Plug requests and even adds user agent to it and even solves the 2nd one as well almost, as it works as a formatter so it can be integrated with any backend and can be used with LoggerFileBackend for output to file.

Almost to good but there is a catch and it ain't that it uses Poison 😅 but that if log message is not from Plug it get printed out as plain text with no formatting , no JSON 😱. Once again fret not this is where Logger's custom formatter power comes to play.

You can define a formatter that can help you format your non JSON-ish messages before they output to your backend here is a quick and dirty formatter to make it happen I hacked after reading timber.io blog, link on the gist.

plug request log

{"function":"log_message/4","level":"info","line":119,"message":{"client_ip":"X.X.X.X","client_version":"okhttp/4.8.1","date_time":"2021-09-13T11:26:15Z","duration":0.251,"handler":"N/A","method":"POST","params":{"glob":[]},"path":"/query","request_id":null,"status":200},"module":"Elixir.Plug.LoggerJSON","timestamp":"2021-09-13T11:26:15.794Z"}

non plug log

{"function":"ip/0","level":"info","line":17,"message":{"msg":"Ipify detected IP: X.X.X.X"},"module":"Elixir.Services.Ipify.Api","timestamp":"2021-09-13T11:27:49.324Z"}

and just make this all happen with adding config as below

 use Mix.Config

 config :plug_logger_json,
   filtered_keys: ["password", "authorization"],
   suppressed_keys: ["api_version", "log_type"]

 config :logger,
   backends: [{LoggerFileBackend, :info_log}],
   utc_log: true,
   handle_otp_reports: true

 # configuration for the {LoggerFileBackend, :info_log} backend
 config :logger, :info_log,
   format: {Formatter.Log, :format},
   metadata: :all,
   path: "/src/log/app.log",
   level: :info

Elixir Logger is just amazing and super flexible with tons of formatters and backends available and if you don't find something satisfying your needs just hack one out. Hope this gave you enough info to hack your solution

Comments

[Zeke Dou]

In 2022:

• Ink supports option - :io_device which can use IO devices created from file, such as File.open/3.
• Phoenix uses Telemetry for generating logs. We can disable the default logger, and create a custom logger.