JSON logging in Elixir using a Custom Formatter
Tags: elixir, json, logging, plug
Published: 2021-09-13 16:06:29

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 :muscle: 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  :sunglasses: plug_json_logger FTW.

{% github bleacherreport/plug_logger_json %}

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.

{% gist https://gist.github.com/ahsandar/5e38031b494730658b8d9f1d3271d7f2 %}


`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