サービスログは、適切に解析することができれば非常に価値のある「データの宝庫」となります。

多くの開発者はデバッグのために時折ログをスキャンしたり、エラーや警告を探すためにgrepコマンドを使用したりするに留まっているのが現状です。

2012年3月28日、JoyentのTrent Mick氏は、Node.jsサービスにおけるロギングの在り方を根本から変えるライブラリ「Bunyan」を公開しました。

本記事では、なぜ従来のテキスト形式のログからJSON形式の構造化ログへと移行すべきなのか、その理由とBunyanの具体的な活用方法について詳しく解説します。

従来のロギングが抱える課題と限界

解析を困難にするフォーマットの不一致

現在のロギングの多くは、人間が読むことを前提とした「printfスタイル」のテキスト形式で出力されています。

しかし、複数のサービスやノードから出力されるログは、日付フォーマット一つとってもバラバラであることが少なくありません。

ログを解析するためには、まず正規表現を用いて特定のパターンを抽出するという、非常に面倒で壊れやすい作業が必要になります。

「パースのしやすさ」こそがロギングにおいて最も解決すべき課題であり、これまでの20年間、この状況はほとんど改善されてきませんでした。

結果として、多くの開発者はログの高度な分析を諦めるか、あるいは高価なログ分析専用ツールを導入するしか選択肢がありませんでした。

「人間向け」から「マシン向け」へのパラダイムシフト

ロギングの新しい考え方として、「ログの第一の読者は人間ではなく、マシンであるべきだ」という原則が提唱されています。

JSON形式を採用すれば、JSON.parse()を呼び出すだけで、あらゆるログレコードを一瞬でデータ構造として取り出すことが可能になります。

もちろん、従来のUnix的な「小さなツールを組み合わせる」という手法において、JSONは標準的なテキスト形式よりも扱いづらいと感じるかもしれません。

しかし、それはJSONそのものが問題なのではなく、既存のツールが古いロギング手法に最適化されているために生じる違和感です。

マシンが読みやすい形式で記録し、人間が読むときは専用のフィルタを通すという分離が、現代の複雑なシステムには不可欠です。

Bunyanによる構造化ロギングの導入

Bunyanの基本機能とインストール

Bunyanは、Node.js向けに設計されたJSONロギングライブラリであり、ログの出力をプログラムの状態を含んだJSONオブジェクトとして扱います。

シンプルなAPIを備えており、名前の指定、ログレベルの設定、そして出力先となるストリームの定義を簡単に行うことができます。

Bunyanをプロジェクトに導入するには、npmを使用して以下のコマンドを実行します。

Shell
npm install bunyan

基本的な使用例

実際にBunyanを使用してログを出力するコードは以下のようになります。

JavaScript
var bunyan = require('bunyan');
// ロガーの作成
var log = bunyan.createLogger({name: "myapp"});
// インフォメーションレベルのログ出力
log.info("hello bunyan");
// オブジェクトを含めたログ出力
log.info({lang: "js"}, "learning bunyan");

上記のコードを実行すると、標準出力には以下のようなJSONレコードが1行ずつ書き出されます。

実行結果
{"name":"myapp","hostname":"local","pid":12345,"level":30,"msg":"hello bunyan","time":"2012-03-28T10:00:00.000Z","v":0}
{"name":"myapp","hostname":"local","pid":12345,"level":30,"lang":"js","msg":"learning bunyan","time":"2012-03-28T10:00:05.000Z","v":0}

CLIツールによる可読性の確保

JSON形式のログは、そのままターミナルで見ると視認性が低いという欠点がありますが、Bunyanには強力なCLIツールが付属しています。

ログファイルをbunyanコマンドにパイプで渡すだけで、人間が読みやすい形式に整形して表示することが可能です。

Shell
node server.js | ./node_modules/.bin/bunyan

これにより、デバッグ時には人間が快適にログを確認し、本番環境ではマシンが効率的にログを処理するという両立が実現します。

APIサービスにおける実践的なロギング

Restifyとの統合とシリアライザの活用

Joyentが開発しているAPIフレームワーク「Restify」は、Bunyanとの親和性が非常に高く、デフォルトでJSONロギングをサポートしています。

Bunyanの強力な機能の一つに「シリアライザ」があり、これは特定のオブジェクトをJSONに変換するための変換関数を事前に登録できる機能です。

例えば、HTTPのリクエストオブジェクト(req)をログに含める際、必要な情報(メソッド、URL、ヘッダー)だけを抽出して記録することができます。

JavaScript
var bunyan = require('bunyan');
var restify = require('restify');

var log = bunyan.createLogger({
    name: 'helloapi',
    serializers: {
        req: bunyan.stdSerializers.req, // 標準のリクエストシリアライザ
        res: bunyan.stdSerializers.res  // 標準のレスポンスシリアライザ
    }
});

var server = restify.createServer({
    log: log
});

server.get('/hello', function (req, res, next) {
    req.log.debug('helloハンドラが呼ばれました');
    res.send(200, {message: 'world'});
    return next();
});

リクエストIDによるトレーサビリティの向上

マイクロサービスのような複数のサービスが連携するシステムにおいて、特定の処理を追跡することは極めて困難です。

BunyanとRestifyを組み合わせると、各リクエストに対して一意の「req_id」を自動的に付与することができます。

全てのログレコードにこのIDが含まれるため、複数のログファイルから特定のユーザー操作に関連する記録だけを抽出することが容易になります。

この手法をSOA(サービス指向アーキテクチャ)全体に適用し、HTTPヘッダーを通じてIDを伝播させることで、システム全体の可視性が飛躍的に高まります。

将来的な展望とツールチェーンの広がり

ログからメトリクスへの転換

ログがJSON構造化されているということは、そのデータはそのまま分析ツールに投入できることを意味します。

特定のフィールドに実行時間を含めておけば、ログから直接統計データを作成し、システムのパフォーマンスを監視することが可能です。

また、アドホックなフィールドを追加して「特定のフラグが立っている場合のみ外部サービスに転送する」といった柔軟な運用も現実的になります。

他のライブラリとの比較

Node.jsのエコシステムには、Bunyanの他にも「Winston」や「Logmagic」といったJSONロギングをサポートするライブラリが存在します。

Winstonは柔軟な多機能性が魅力ですが、Bunyanは「JSON出力に特化し、シンプルさとパフォーマンスを重視する」という明確な思想を持っています。

プロジェクトの規模や用途に応じて適切なツールを選択すべきですが、Joyentのクラウド運用で培われたBunyanの設計思想は、多くのWebサービスにとって有益な知見を提供しています。

まとめ

2012年に登場したBunyanは、単なるロギングライブラリではなく、「ログは構造化されたデータである」という重要なパラダイムをNode.js界隈にもたらしました。

JSON形式でのロギングを採用することで、正規表現に頼った危うい解析から解放され、より高度なモニタリングとデバッグが可能になります。

日付フォーマットの不一致や、コンテキスト情報の欠落に悩まされる時代は終わりました。

Bunyanのようなツールを活用し、マシンと人間の両方にとって最適なロギング戦略を構築することが、信頼性の高いサービス運用の第一歩となります。