➿

ユーザーに迷惑をかけないロギングの設計

に公開
JavaScript
TypeScript
logging
ログ
ロギング
tech

ライブラリにロギングを入れたい。でも、ユーザーのコンソールは不要なログで散らかしたくない——ライブラリ開発者なら誰もが直面するジレンマです。

詳細なログを出せばデバッグには便利ですが、ユーザーが望まないログまで表示されてしまいます。かといって何も出さなければ、問題が起きたときに手がかりがありません。

この記事では、私がFedifyというActivityPubフレームワークを開発する中で直面したこの課題と、LogTapeというロギングライブラリでどう解決したかを紹介します。

既存のライブラリでは解決できなかった

まず、既存のロギングライブラリを検討しました。winstonやPinoを使う場合、以下のどちらかを選ぶことになります。

  • ライブラリ内部でロガーを設定する（ユーザーに設定を押し付けることになる）
  • ユーザーにロガーインスタンスを渡してもらう（ボイラープレートが増える）

debugパッケージはライブラリ向けに設計されていますが、構造化ログやログレベルに対応していません。また環境変数に依存するため、Denoのようにデフォルトで環境変数へのアクセスが制限されているランタイムでは使いづらいという問題もあります。

どれもしっくりこなかったので、ライブラリ作者向けのロギングライブラリとしてLogTapeを開発しました。

LogTapeの基本思想：沈黙がデフォルト

LogTapeの設計で最も重視したのは、アプリケーション開発者が明示的に有効化しない限り、何も表示されないという点です。

ユーザーがLogTapeを設定しなければ、ログ呼び出しはno-op（何もしない）になります。設定不足の警告もなく、デフォルト出力もなく、オーバーヘッドも最小限です。

基本的なログが欲しければ、数行の設定で有効化できます。特定の問題をデバッグするときは、そのサブシステムだけデバッグログを有効化すれば十分です。何が必要かはユーザーが決めることであり、ライブラリが押し付けるものではありません。

Fedifyでの実践：階層的カテゴリ

では、実際のライブラリでどう使うのか。私が開発しているFedifyを例に紹介します。

FedifyはActivityPubプロトコルを使った分散SNSの開発を支援するフレームワークです。HTTP処理、暗号署名、JSON-LD処理、キュー管理など複数のサブシステムで構成されており、問題が起きたときにどこで失敗したかを特定する必要があります。

LogTapeの階層的カテゴリシステムを使って、ユーザーが見たいログだけを細かく制御できるようにしています。カテゴリは以下のように構成されています。

カテゴリ 内容
["fedify"] ライブラリ全体
["fedify", "federation", "inbox"] 受信アクティビティ
["fedify", "federation", "outbox"] 送信アクティビティ
["fedify", "federation", "http"] HTTPリクエスト・レスポンス
["fedify", "sig", "http"] HTTP Signature処理
["fedify", "sig", "ld"] Linked Data Signature処理
["fedify", "sig", "key"] 鍵の生成・取得
["fedify", "runtime", "docloader"] JSON-LDドキュメントの読み込み
["fedify", "webfinger", "lookup"] WebFingerリソースの検索

他にも十数個のカテゴリがあり、各カテゴリは独立したサブシステムに対応しています。

ユーザーは以下のように設定できます。

await configure({
  sinks: { console: getConsoleSink() },
  loggers: [
    // Fedify全体のエラーを表示
    { category: "fedify", sinks: ["console"], lowestLevel: "error" },
    // inbox処理だけデバッグログを表示
    { category: ["fedify", "federation", "inbox"], sinks: ["console"], lowestLevel: "debug" },
  ],
});

受信アクティビティに問題があれば、そのサブシステムだけ詳細なログを確認できます。他のサブシステムは静かなままです。コードを変更する必要はなく、設定だけで対応できます。

暗黙的コンテキストによるリクエストトレーシング

階層的カテゴリでフィルタリングの問題は解決しました。しかし別の課題がありました。非同期処理をまたいだログの相関です。

連合システムでは、ひとつのユーザーアクションが複数の処理を連鎖的に引き起こします。リモートアクターの取得、署名の検証、アクティビティの処理、フォロワーへの配送などです。どこかで失敗したとき、そのリクエストに関するログをすべて追跡する必要があります。

FedifyではLogTapeの暗黙的コンテキスト機能を使って、すべてのログエントリにrequestIdを自動付与しています。

await configure({
  sinks: {
    file: getFileSink("fedify.jsonl", { formatter: jsonLinesFormatter })
  },
  loggers: [
    { category: "fedify", sinks: ["file"], lowestLevel: "info" },
  ],
  contextLocalStorage: new AsyncLocalStorage(),  // 暗黙的コンテキストを有効化
});

この設定により、すべてのログエントリにrequestIdプロパティが含まれます。特定のリクエストをデバッグするときは、以下のようにフィルタできます。

jq 'select(.properties.requestId == "abc-123")' fedify.jsonl

そのリクエストに関するログが、すべてのサブシステムにわたって時系列で表示されます。手動でログを紐付ける必要はありません。

requestIdはX-Request-IdやTraceparentなどの標準ヘッダーから取得されるため、既存のオブザーバビリティ基盤とも自然に連携できます。

本番環境での活用

同じライブラリコードが、開発時の簡易ログから本番環境の本格的なオブザーバビリティまで対応できます。

本番環境で構造化されたJSONログをリクエスト相関付きでモニタリングシステムに送ることも可能です。Node.jsでもDenoでもBunでもエッジ関数でも、追加のポリフィルなしで動作します。

ライブラリ作者として学んだこと

FedifyをLogTapeで運用して、いくつかのことを学びました。

沈黙をデフォルトにする。 ログで内部の詳細を見せすぎることを心配するライブラリ作者もいます。私の経験ではむしろ逆です。必要なときに内部状態を確認できる透明性は、ユーザーに歓迎されます。重要なのは、それをオプトインにすること。ユーザーが求めるまでは静かにしていることです。

カテゴリ設計は早めに行う。 階層構造は、ユーザーが実際にどうフィルタしたいかを反映すべきです。Fedifyでは、独立してデバッグする可能性のあるサブシステムごとにカテゴリを設計しました。

構造化ログを活用する。 requestId、activityId、actorIdなどのプロパティは、文字列補間よりもはるかに便利です。ログをプログラムで分析するときに威力を発揮します。

暗黙的コンテキストは想像以上に便利。 コンテキストを手動で渡さなくても非同期処理をまたいでログを紐付けられるのは、分散処理のデバッグを格段に楽にしてくれました。

まとめ

LogTapeはwinstonやPinoを置き換えるものではありません。アプリケーション開発者がそれらに満足しているなら、そのまま使えばよいでしょう。

LogTapeが埋めるのは別のギャップです。ユーザーに迷惑をかけずにロギングを提供したいライブラリのためのもの——そういうものを探しているなら、ぜひ試してみてください。

Fedifyでの実装例はFedifyのロギングに関するドキュメントで詳しく解説しています。LogTapeの設計思想については、以前書いた記事「If you're building a JavaScript library and need logging, you'll probably love LogTape」もご覧ください。

Discussion