Structured logging

The structured logging is to make a log that is easy to process mechanically.

Comparison of usual logs and structured logs

The usual logs are basically just timestamps, level, and message strings. Information to be the context of events (events) to be kept as logs is appropriately embedded in messages. It is easy for human to read on a console.

In the structured log, information which becomes the context embedded in the message is independently given to the field of the log structure. Therefore, it is easier to analyze later. And the output logs are often text based JSON.

Let's compare this. The log of normal Ruby Logger and my own Ougai will be as follows. It is a log that "user created article" (articles shaved).

logger.info "User created article  (user_id=#{user.id} article_id=#{article.id}"

I, [2018-05-13T17:51:08.772542 #6253]  INFO -- : User created article  (user_id=123 article_id=45)

logger.info "User created article", user_id: user.id, article_id: article.id

{"pid":6253,"level":20,"time":"2018-05-13T17:52:25.147+09:00","msg":"User created article","user_id":123,"article_id":45}"

※ It differs from the default format

As you can see, you have to embed the normal logs and convert the incidental information into strings. On the other hand, structured logs are longer by JSON effect, so it is difficult to read in the console. However, it is not a problem if you use log viewer with switchover in the operating environment of the formatter or parse mechanism.

Structured logs are easier to analyze is that, for example, if you want to extract only the logs of certain users, simply grep "user_id=10" will cause to hook entries whose user_id is like 101 in normal logs. On the other hand structured logs (mainly using JSONPath) can be easily and reliably filtered by like a $.user_id = 10.

Log management service and structured log

SaaS for log management and analysis such as AWS CloudWatch Logs, Stackdriver Logging on Google Cloud and Loggly, Logentries all support structured logs, or you can not make use of those services unless you do. However, since the library itself provided by each service does not correspond to the structured output, I think that it is best to relay by Fluentd and send it by present situation best.

The reason for making Ougai

Originally I wrote the front API server in Node.js and participated frequently in the project to create backend management service with Ruby / Rails. Node.js had a famous JSON logger named Bunyan, and I liked it. But Ruby has libraries that handle several structured logs, but each library was as a framework. Node.js itself has functions for console output like console.info, but Ruby has its own Logger, though. In another micro service, each service is often implemented in multiple languages, but if possible, I wanted to unify the format in order to analyze the log cross-sectionally.

With these backgrounds, I built my own logger based on Ruby's original Logger, which is a logger that has the Bunyan compatible log output format described above. That is Ougai. (I named Ougai from a Japanese literary person after Bunyan was named from the English literary.)

GitHub: tilfin/Ougai - A Ruby structured logging is capable of handling a message, custom data or an exception easily and generates JSON or human readable logs.

Since it is an extension of Ruby's original Logger class, even if it is introduced suddenly, it does not crash simply by appearing in the message field. You can gradually move the context to an independent field. The format is standard, for JSON output it is Pino compatible with Bunyan of Node.js, Readable which is colorfully easy to read at the terminal using awesome_print is included. Of course for JSON you can browse with dedicated log viewer commands owned by Bunyan and Pino respectively. There is also a function to make common information easy to put in by hook.

https://github.com/tilfin/ougai/wiki

The wiki also contains examples of settings to use it in combination with Rails, Sidekiq, Fluentd etc.

https://rubygems.org/gems/ougai