Structured Logging

[Hermanlangner]

Structured Logging

For Zexbox one of the big pieces we are missing is structured logging.
There's a better definition available here
Essentially it's passing context to your logger so that it can key your logs for you so that they are easier to find in log aggregators like Kibana or Splunk.

Generally what this means

Different platforms and libraries have different flavours but the general gist of it is that with raw log messages, you need to scan and slice strings to extract context and most platforms suck at it (i.e. the ones that do it like Splunk consumes all the performance).
What I mean by this, with standard logging you can loosely enforce an indexing pattern, but your context is not well defined.
say you have the context of user_id: 52, country: 'ZA'
With standard logging you'd interpolate your string like this

Logger.info("A user of user_id: #{user_id} logged in from country - #{country}")
output: A user of user_id: 52 logged in from country - ZA

I deliberately brought in inconsistent indexing to highlight the point, for a log aggregator to be able to index your log it would need to extract the patterns of "word: value" and "word - value".

With structured logging, you rather pass the context to the logger and let it handle the rest.
This is where a lot of implementations differ and we will need to find one that feels the best in elixir and zappi.

Generally it looks something like this

Logger.info("A user of user_id: #{user_id} logged in from country - #{country}", context: %{user_id: 52, country: "ZA"})
output: json { "message": "A user of user_id: 52 logged in from country - ZA", "user_id": 52, "country": "ZA"}

Depending on the logging implementation, the outputs could vary.

Collectors

In our environment, we use a grok collector, the scans IO output for certain keys. We can use a log formatter on non-dev environments to match the output expected.
Example implementation for our ruby friends in opxbox - https://github.com/Intellection/opsbox/blob/master/lib/opsbox/loggers/grok_formatter.rb
Where our output must match the format json: <json_blob>

Formatters

Formatting for collectors, ends up being a really shitty developer experience. Since it's optimised for collection and parsing by a log aggregator, the human readability goes to 0.
For local dev we either want to discard context or merge it into the message, or keep the default logger.
For opsbox we provided an experience that was better than the default logger through
https://github.com/Intellection/opsbox/blob/master/lib/opsbox/loggers/pretty_log_formatter.rb

Elixir structured loggers

For opsbox we wrote our own logger because when we wrote it (and still not sure if there is) there wasn't a ruby equivalent that did what we wanted.
Whichever route we go, A painful thing we did that we learnt from

• Don't extend the default logging behaviour to be library specific (We built logger.audit and the likes, which coupled you to the logger and had weird behaviours switching formatters)

When I looked into it previously, I thought it was possible that we could get most of the way with formatters on the elixir logger, and just providing the formatter, but I did not get too far with it