構造化ログのススメとRuby向けロガーOugaiを作った理由
構造化ログ
構造化ログ とは、機械的に処理しやすいログのことであり、その機構(ロギング)である。 英語圏では、 Structured Logging と表記される。たとえば Google Cloud の Stackdriver のドキュメントには下記の説明ページがあります。(残念ながら執筆時点で、これの日本語ページがまだできてないので、Google がどう訳すか興味深い)
Structured Logging | Stackdriver Logging | Google Cloud
普通のログと構造化ログの比較
普通のログは、基本的に タイムスタンプ 、レベル 、そして メッセージ の文字列だけである。ログとして残す事象(イベント)のコンテキストになる情報はメッセージに適当に埋め込む。コンソール等で人が読みやすいものである。
構造化ログは、メッセージに埋め込んでいたコンテキストになる情報をそれぞれログ構造のフィールドに独立して持たせる。そのため後から解析がしやすい。そして出力するログはテキストベースで JSON にすることが多い。
では、見比べてみましょう。通常のRubyのLoggerと自作のOugaiでのログは次のようになります。『ユーザが記事を作成した』というログです(冠詞、削ってます)。
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}"
※デフォルトフォーマットとは異なります
見てわかる通り、普通のログは埋め込んで付帯情報を文字列化しつつ書かなくてはなりません。一方、構造化ログの方が JSON にした影響で長くなるのでコンソールでは読みづらいです。しかし読みづらいことはフォーマッタの動作環境での切替やparse機構を持つログビューワを使えば問題になりません。
構造化ログの方が解析しやすいというのは、例えば普通のログでは「あるユーザのログだけ抽出したいとき」に単に grep "user_id=10"
とすると user_id が 101 など他のものまで引っかけてしまいます。構造化ログでは(主に JSONPath を使って)フィルタが $.user_id = 10
のように簡単に確実に絞り込めます。
ログ管理サービスと構造化ログ
AWS CloudWatch Logs, Google Cloud の Stackdriver Logging や Loggly, Logentries といったログ管理や解析向け SaaS はどれも構造化ログをサポートしていますし、むしろそうしないとそれらのサービスの機能を活かし切れません。ただ各サービスが提供するライブラリ自体は、構造化出力に対応してなかったりするので、Fluentd で中継させて送るのが現状ベストと思います。
Ougai を作った理由
元々 フロントAPIサーバを Node.js で書いて、バックエンドの管理サービスを Ruby/Rails で作るというプロジェクトによく参加してました。Node.js には Bunyan という有名な JSON ロガーがあり、これを好んで使っていました。しかしRubyにはいくつかの構造化ログを扱うライブラリはあるものの、各々のライブラリがフレームワークになっていました。Node.js 自体に console.info
のようなコンソール出力向け機能しかないのですが、Ruby にはそれ自体に Logger があるのにも関わらず。もう一つマイクロサービスにおいて複数の言語で各サービスを実装することは多いですが、できれば横断的にログを解析したいためにそのフォーマットも統一したいと思いました。
これらの背景もあり、Ruby のオリジナル Logger ベースで、前述の Bunyan 互換でログ出力するフォーマットを持つロガーを自作しました。それが Ougai です。(Bunyan がイギリスの文学者名が由来だそうなので日本の文学者から名付けました)
Ruby のオリジナルの Logger クラスの拡張なのでいきなり導入しても、メッセージフィールドに出るだけでクラッシュすることはありません。徐々にコンテキストを独立したフィールドに移行することができます。フォーマットは標準で、JSON 出力用は Node.js の Bunyan と Pino 互換のもの、awesome_print を利用してターミナルでカラフルに見やすい Readable が入っています。JSON 用のはそれぞれ Bunyan と Pino が持つ専用ログビューワコマンドでもちろん閲覧できます。フックによって共通情報を入れやすくしたりする機能もあります。
Home · tilfin/ougai Wiki · GitHub
Wiki には Rails, Sidekiq, Fluentd 等と組み合わせた使うための設定例も載せてあります。
ougai | RubyGems.org | your community gem host
なお既にリリースしたから1年以上経っているので、知ってる範囲でも、知らないところでもそこそこ使ってもらえています。