ロギング設計大全
アプリケーション設計者視点で、どうログ設計するか? についてまとめます。
使途別
異なる用途で使われるので、それ毎にファイルやトップカテゴリで分類する。
トレーシング
世の中のロギングライブラリの主な想定用途はこれである。必要な箇所やレベルに応じて出力制御をするために、ログカテゴリやログレベルが存在する。
目的
アプリケーションの性能をモニタリングする
トラブル時に何のメソッドが呼ばれたかを追跡する
必要項目
タイムスタンプ
リクエストID
Microservicesのようにインスタンスをまたいでトレーシングしたい場合は、上流で発行されたリクエストIDを引き渡して、それをログに出力する。
メソッド名
手段
AOPでメソッドのEnter/Exitで自動的にロギングされるように設定する。
code:出力例
2023-11-13T10:00:00.123Z TRACEID1 Entering functionA
2023-11-13T10:00:00.125Z TRACEID2 Entering functionB
2023-11-13T10:00:00.130Z TRACEID2 Exiting functionB
2023-11-13T10:00:00.135Z TRACEID2 Entering functionC
2023-11-13T10:00:00.140Z TRACEID2 Exiting functionC
2023-11-13T10:00:00.145Z TRACEID1 Exiting functionA
モニタリング
メトリクスAPIやヘルスチェック用のエンドポイントを用意するのが当たり前になった現代では、システム監視のためのログ出力少なくなった。が、バッチ処理のような長くかかるプロセスは、モニタリングのためのログを出力するのがお手軽で、まだまだ使われる機会は多い。
目的
システムの監視のため
必要項目
タイムスタンプ
メトリクス(の元となるデータ)
手段
画一的にログ出力することが難しいので、取得したいメトリクス毎にフレームワーク側で実装したり、アプリケーションコードで明示的に出力したりすることになる。
code:出力例
2023-11-13T10:00:00.123Z - Auction 1001 - New participant joined - UserID: 501 - Total Participants: 1
2023-11-13T10:05:00.456Z - Auction 1001 - New participant joined - UserID: 502 - Total Participants: 2
2023-11-13T10:10:00.789Z - Auction 1001 - Participant left - UserID: 501 - Total Participants: 1
2023-11-13T10:15:00.321Z - Auction 1001 - New participant joined - UserID: 503 - Total Participants: 2
2023-11-13T10:20:00.654Z - Auction 1002 - New participant joined - UserID: 504 - Total Participants: 1
2023-11-13T10:25:00.987Z - Auction 1001 - Auction ended - Final Participants: 2
2023-11-13T10:30:00.123Z - Auction 1002 - Participant left - UserID: 504 - Total Participants: 0
2023-11-13T10:35:00.456Z - Auction 1002 - Auction ended - Final Participants: 0
リモート呼び出し
特に開発や運用の主体の異なるサービスを呼び出したり、呼び出されたりする箇所においては、問題発生時の責任範囲切り分けのために、ログを出力しておくことが求められる。
目的
リモートAPIコールの問題発生時の責任範囲分析
必要項目
タイムスタンプ (リクエストとレスポンスそれぞれに)
リクエストID (トレーシングと同じもの)
リクエストのRawデータ
レスポンスのRawデータ
手段
リモート呼び出しのライブラリで、リクエストとレスポンスを自動的に記録する。
生データをそのまま吐き出す。が、カード番号やパスワードなどの機微な情報はマスクする。
監査
目的
セキュリティや内部統制のためにシステムの不正な利用がないかを後で調査するため
必要項目
タイムスタンプ (When)
ユーザID (Who)
IPアドレス/マシンID (Where)
参照データのID、範囲 (What)
手段
アプリケーションコードで明示的にLoggerを使って出力する。
業務イベント
目的
業務上のイベントを記録する。のでログと呼ぶのは憚られる場合も多い。
ただし、以下の条件に合致するものは高価なRDBMSに書き込む必要がないため、ファイルに書くこともある。
定型業務として、記録したデータを読み込むことはない。
統計処理にしか使わない
必要項目
タイムスタンプ
その他、RDBのテーブルを設計するのと同じようにスキーマ設計し、Semantic Loggingで出力する
手段
アプリケーションコードのの中で明示的にロガーを使って出力する。
ストレージが将来的に変わることも想定し、ロガーのAppenderで出力先を切り替えることができるようにしておく。
Appenderの切り替えによって、DynamoDBのような書き込みが高速なストレージにしたり、Kafkaのような分散キューイングを介してDWHに流し込んだりする。
システム利用状況の統計
目的
システムの利用状況を集計し、サービス改善などに利用する。
必要項目
ユーザID (非ログイン機能でも、ユーザ追跡のためのIDを発行する)
タイムスタンプ
手段
画面だけでよければ、Google Analytics等の外部ツールを使う。ので、ログという形で明示的に出力しないことが多い。
サーバサイドでしか記録できないものも、GAでまとめて見たいので、結局GAのAPIを叩くなどの実装にする。
障害追跡
例外を、業務上「予期するもの」「予期しないもの」に分類し、予期しない例外についてログを出力する。
目的
開発チームが対応しなくてはならない障害を解析するため
必要項目
タイムスタンプ
スタックトレース
手段
アプリケーションコードではハンドリングしない。
フィルタやAOPを使って、ロガーの通常の機能を使って出力する。たいていのロギングライブラリではExceptionオブジェクトを渡せばスタックトレースは出力される。
Exceptionではコンテキストが十分でない場合があるので、MDCを使って例外発生時の状況把握に必要な情報も同時に出力されるようにする。
自前でログ出力する以外にも、Sentryに送るなどの実装手段がある。
「予期しない例外」にもレベルがあり、サービス停止レベルのものから、急ぎの対応は不要なものまで分類できる。これを設計して、ログレベルを使い分けておく。
code:出力例
Stack Trace:
com.example.OrderNotFoundException: Order ID 12345 not found.
at com.example.OrderService.getOrder(OrderService.java:50)
at com.example.OrderController.getOrder(OrderController.java:25)
...
障害検知
障害追跡ログが出まくってアラートストーミングを起こす場合に、緊急を要するイベントのみをフィルタして検知するために別のログを出力する。特にバッチ処理で役に立つ。
プログレスログ
目的
時間のかかるジョブに対して、現在の実行状況がわかるようにする。
必要項目
トータル処理件数
現在完了した処理件数
手段
専用のProgressLoggerを用いて出力する。
code:出力例
2015-11-17T160041.793 売上データ取り込み処理を開始します
2015-11-17T160041.806 総処理対象は500000件で、終了予想時刻は16:10です。
2015-11-17T160052.954 10000件(2.0%)処理しました。現時点での終了予想時刻は16:09:51です。
2015-11-17T160104.124 20000件(4.0%)処理しました。現時点での終了予想時刻は16:09:52です。
2015-11-17T160115.268 30000件(6.0%)処理しました。現時点での終了予想時刻は16:09:52です。
2015-11-17T160126.275 40000件(8.0%)処理しました。現時点での終了予想時刻は16:09:52です。
デバッグ
目的
開発時のデバッグの助けになる情報を出力する。
将来メンテする人のことを考慮し、他人が見てもそのログの意図やメッセージの内容が分かるようにする。
必要項目
特になし
手段
アプリケーションコードで、トレーシングと同じロガーを使っても構わない。
ロギングパターン
トレースID
コンテキスト
1つのクライアントリクエストに対してレスポンスするまでに、複数のプロセスが介在する。
ソリューション
リクエストを受け付ける箇所でトレースIDを生成し、それを各プロセスに渡していき、それをログにも出力する。
実装
Jaeger
ZipKin
マスキング
コンテキスト
センシティブなデータをログに出力すると、ログの参照権限は運用者の広範囲に及ぶことが多いので、漏洩リスクが高まる。
ソリューション
ログエントリ間の同一性まで含めて、センシティブなデータ(パスワードや誕生日など)であれば、「****」などの単純な文字列に置き換えるか、エントリ自体から削ってしまう。
そうでなければ、ハッシュ化して出力するでもよい。
実装
MDC
コンテキスト
ログに出力したいデータを持つレイヤと、実際にログを出力するレイヤが異なる。
ソリューション
スレッド毎のグローバルエリアがあればそこにデータをもたせる。
構造化ログ
コンテキスト
ログの集約ツールで解析しやすい形式で出力する(通常JSON)
マシンリーダブルであることが、ヒューマンリーダブルよりも優先される(ヒューマンリーダブルであることは最低限は保証する)
ソリューション
ログメッセージを自由文ではなく、キーと値のペイロード（例：JSONオブジェクト）として出力する
各ログエントリに共通のメタデータ（タイムスタンプ、サービス名、ホスト名、トレースIDなど）を付与する
集約サーバ（Logstash、FluentD、Fluent Bit など）で受信後、インデックス／加工して検索可能にする
実装
Logback + logstash-logback-encoder
SLF4J の StructuredArguments（net.logstash.logback.argument.StructuredArguments）
参考
ローテーション
コンテキスト
ディスク容量が限られており、ログファイルが肥大化すると運用に支障をきたす
長期間にわたりログを蓄積しつつ、古いログを自動的に削除・アーカイブしたい
法規制や内部ポリシーでログ保存期間が定められており、期限切れログの破棄を自動化したい
ソリューション
一定期間（例：日次、週次）またはファイルサイズ（例：100MB）ごとに新規ログファイルを生成
ログ世代数を定義し、最新 N 世代を保持、古い世代は削除または圧縮アーカイブ
圧縮形式（gzip, zip など）でアーカイブし、ストレージ使用量を最適化する
アーカイブ先のストレージ（オンサイト／クラウド）を分離し、検索要件に応じて復元可能にする
保持ポリシー（例：７世代保持、30日保持）とアーカイブ後の自動削除を組み合わせる
その他
参考資料