Webアプリケーションログ出力の基本
TL;DR
本番環境のアプリケーション側で主に出すログレベルは以下
- INFO
- WARN
- ERROR
ログのフォーマットは概ね以下の情報を出す
[LOG_LEVEL] [timestamp] [request_id] [function_name] message
ログを仕込む位置、出力情報は概ね以下
- APIが叩かれた時、対象の処理が走った時
- 必要なリソースを読み込み終わった時
- 目的の処理を開始する前
- 目的の処理を終了した後
ログの出し方に迷ったらチームのメンバーに相談しよう！
概要
ログを出す目的
ログとは「システムのその時の状況を読み手に伝えるための記録」です。
ログを出す目的の第一は、障害時調査があります。
他にもユーザーの利用状況分析など、いろいろな箇所で利用可能です。
まずはとにかくログを出すようにしましょう。
ログ設計
ログの用途に応じた役割を果たすために設計します。
システム障害時を想定したログを出す場合、調査に必要な情報な何か？という視点で設計していきます。
ログインの必要なシステムであれば、各アクションを行ったログにはログイン中のユーザーIDが出ているといいでしょう。
Webアプリケーションであれば、バックエンド側の処理が呼ばれた時はまず「どのAPIがいつ呼ばれたか」を最低限出します。
ログ設計前に確認すること
- ログの用途はなにか？
- ログの読者は誰か？
- 満たすべき要件はないか？
ログの用途はなにか？
主な用途
| ログの用途（例） | ログの種類 |
|---|---|
| 障害時の調査 | アプリケーションログ |
| ユーザーの利用状況を分析する | アクセスログ |
| システムの稼働を監視する | エラーログ |
| 不正アクセスの監視、調査 | セキュリティログ |
| セキュリティ基準を満たす | 監査ログ |
作成するアプリケーションごとに、どのような用途でログを使うか確認することが重要。
開発者だけでなく、運用、企画、営業、マーケ、法務の担当者にも必要なログがあります。
ログの読者は誰か？
- 開発者
- 運用担当者
- 自社の社員
- 外部の顧客企業社員
ログの読者によって内容は変えましょう。
システム障害時にログを見る場合、どのような情報があれば運用担当者・開発者は調査しやすいでしょうか？
分析ツールから見るのか、cloudwatchから見るのか、ログフォルダに蓄積されたものを見るのか。見る時を想定した内容を記述しましょう。
社内の活発なリポジトリを見て、フォーマットを真似するところから始めると良いでしょう。
満たすべき要件はないか？
例えばITGC上、社内用システムでは満たす条件が必要かもしれません。
ログイン中のユーザーID、日時、起こしたアクションは必須でしょう。
個人情報を取り扱うものは特に慎重な設計が必要です。
ログ設計の流れ
- フォーマットの決定
- メッセージ内容の決定
- ログレベルの決定
フォーマット
出力する情報の例
| 項目 | 概要 |
|---|---|
| 日時 | ログを出力した時間。年月日時分秒ミリ秒。JST、UTCは要確認。必ず出す。 |
| リクエストID | リクエストごとに付与する識別子。必要なら付ける。 |
| ログレベル | ログのレベル。ログを見る環境によっては付ける。 |
| イベント種類 | どのイベントに関するログか。関数名を入れたり、APIのパス名を入れたりする。 |
| ユーザー情報 | ユーザーの識別子。IDなど。 |
| 関連リソースの情報 | 複数のテーブルを更新する場合、各更新対象のIDなど。 |
| 処理結果 | 成功や失敗 |
| メッセージ | 任意の文章。エラー内容など。 |
メッセージ内容
例えばバグ調査、不具合調査の場合です。
調査するときに助かるメッセージはどのようなものでしょうか？
例として /api/v1/sample?p=1 というAPIを叩いた時に出すアクセスログを設計してみましょう。
[INFO] 2023-01-28 11:00:00.000 [/api/v1/sample] [get_sample_data] query: { p: 1 }
GETで単純なリソースを読み込む場合、上記のフォーマット程度の情報があれば最低限良さそうです。
以降に出すログとしては、関数の引数に与える値・関連するDBから読み込んだIDなど、業務ロジックのどの部分に抵触してエラーの対象となったかがあれば調査が捗りそうです。
逆に出さない情報として、何の役にも立たない情報・必要以上の情報があります。
例として、指定テーブルの情報を取る上でIDが出ているのに、他のカラムの情報も全て出している場合などが挙げられます。
ログレベル
| レベル | 概要 | 説明 | 出力先 | 運用時の対応 |
|---|---|---|---|---|
| FATAL | 致命的なエラー | プログラムの異常終了を伴うようなもの。コンソール等に即時出力することを想定 | コンソール, ファイル | 即時対応が必要 |
| ERROR | エラー | 予期しないその他の実行時エラー。コンソール等に即時出力することを想定 | コンソール, ファイル | 営業時間内のみ対応 |
| WARN | 警告 | 廃要素となったAPIの使用、APIの不適切な使用、エラーに近い事象など。実行時に生じた異常とは言い切れないが正常とも異なる何らかの予期しない問題 | コンソール, ファイル | 次回リリースまでに対応 |
| INFO | 情報 | 実行時の何らかの注目すべき事象（開始や終了など）。メッセージ内容は簡潔に止めるべき | コンソール, ファイル | 対応不要 |
| DEBUG | デバッグ情報 | システムの動作状況に関する詳細な情報 | ファイル | 出力しない |
| TRACE | トレース情報 | デバッグ情報よりも、更に詳細な情報 | ファイル | 出力しない |
一般的に、本番環境においてはINFOレベル以上、開発環境ではDEBUGレベルも含めて出します。
INFOレベル以上で、システムがどのような処理をしたのかが分かるようにすること。これが基本的な考え方になります。
例として、ログインアクションでのログの出し方は以下のように考えましょう。
- ログイン成功時 => INFOでユーザーIDを出力
- 入力間違いにおける失敗 => WARNで日時、IPアドレス、試行回数を出力
- API側の一時的な障害による失敗 => ERRORで日時、APIの情報・返り値を出力
- そもそもの実装ミス、システムとしての致命的なエラー => FATALでキャッチ出来た内容を出力
ERROR以上の深刻なエラーは、起きた時に開発者へ通知が行く仕組みにするといいでしょう。
深刻な問題をINFOレベルで出力するといったことにしないよう、適切なレベルを選んでください。
出してはいけないメッセージ内容
- 機密情報
- 不要な情報
機密情報
当然、情報漏洩につながる情報は出してはいけません。
- 氏名や住所・電話番号など個人情報を構成する要素
- メールアドレスやパスワード、アクセストークン
- クレジットカード番号や有効期限、名義人
ログに出したいときは、マスク処理をするといいでしょう。
使用しているフレームワークによっては、ログに出力する内容を指定出来るので、機密情報の取り扱いには注意しましょう。
不要な情報
第一に、ログサイズの肥大化により、余分なコストがかかります。
cloudwatchなどのサービスでは、従量課金のためローカル以外には不要なログを出さないようにしましょう。
環境変数によってログの出力レベルを変えるといった方法が有効です。
第二に、調査時にノイズとなる情報がおおくなり、必要なログを探し出す邪魔になったりします。
第三に、システムのパフォーマンス低下が挙げられます。ログを出すことも少なからずシステムのパフォーマンスに影響を与えます。
特にSQLの発行ログやロードバランサで出力されるようなログ内容をアプリケーション側で出さないようにしましょう。
Discussion