【考察】ログ出力を失敗しないための方法

サービス開発をするうえで、どのように作っていくか迷うものの一つに、ログ出力があります。
機能であれば要件があるため、要件を満たすために考えることはあるものの、ある程度の正解があります。

しかし、ログ出力には正解があまりありません。また、実際に運用や問題が発生した時に初めて、この内容ではダメだった…と気付くことが多いように思います。改善点に気付いた時には、既に何かしらの問題が発生しているため、既に手遅れになっている可能性も・・。

事前に手を打っておくために、考察していきたいと思います。

触れない内容

• ログ設計の書き方
• ログレベルの解説
• ログ出力フォーマット
• ログのローテーション・保存期間

ログの目的

ログ出力をするということは、何か目的があるはずです。
どうすれば良いか迷わないために、まずは大まかに分類してみます。

1. エラーが発生した箇所を知るため
2. エラーが発生した原因を把握するため
3. 処理として最終的にどうなったのかを把握するため
4. 改善できる箇所(ボトルネック)がないか分析するため
5. 利用される頻度などを分析するため

「原因追及」「運用改善」「サービス分析」が主な目的になりそうです。

大事なこと

目的は先に挙げた通りですが、ログ自体にも大事なことがあります。
それは、「ログだけを見て、どういうことが起こったのかが分かりやすいこと」です。

そのためには、「ログの出力を増やしすぎない（無駄な内容を減らす）」こと。また、「ログの出力を減らしすぎない（結局原因特定ができない状態にはしない）」ことが重要だと思います。

意識しておかなければならないこと

「ログを出力する」ということは、その処理が実行されているということです。ですので、「全くログを出力しない場合」と「ログを出力した場合」では、パフォーマンスに差が生まれます。
当然ではありますが、このことも意識しておくべきかと思います。

気を付けたいルール

では、失敗しないためにどういうことに気を付ければ良いか、考察していきます。

⓪ログの鉄則

「原因追及」するためとはいえ、処理内で扱った情報を全て出力することはできません。
当然ではありますが、「個人情報/金銭価値がある情報など、漏洩してはいけない情報」は出力しないように気を付ける必要があります。
項目自体を出力しないと本当にその値が存在しているのかが分からなくなるため、実際にはマスク処理を行うでしょう。

上記に関連して、「個人情報など自由に入力してしまう可能性がある項目」にも気を使う必要があります。
そういった箇所は、入力されないように予め、注意文言を記載する対策も有効かもしれません…。

①エラー原因を特定しやすくするための情報を出力する

当然のことですが、エラー内容が分かる情報を出力する必要があります。
外部サービスを利用しているのであれば尚更ですが、外部サービスから返却されたエラー情報は必ず出力した方が良いと思います。

また、エラーが発生したことに対して、どういった対処を行ったのかが分かる内容を出力する工夫も必要かと思います。

処理コード

管理は大変ですが、「対処ごとの処理コード」を作成することも有効かと思います。

A処理のZパターンなら、Zの処理コード。
B処理のXパターンなら、Xの処理コード。
C処理のZパターンなら、Zの処理コード。
...

上記のパターンですと、Zの処理コードだけを絞り込みたい…という場合や、Zパターンであることをすぐに分かるようにする目的であれば有効です。但し、多くの場合「どの処理で」起こったのかも把握する必要があるかと思います。
その点を踏まえると、 「処理」と「対処内容」ごとに固有 である必要があるかと思いますが、順番に採番していくと、番号が被ったり、検索がし辛い…、この番号って何だっけ…となるリスクがあると思います。ですので、それを阻止するためにどういうルールが良いか考えてみます。

1. 処理コードの桁数は統一させる
2. 「処理ごとのID」は、処理の分類がある場合は、頭文字を統一させる
   • 例. 「共通系 = 0xx」「商品系 = 1xx」「購入系 = 2xx」「アカウント系 = 3xx」「ログイン処理系 = 4xx」
3. 「対処内容ごとのID」は、サービス全体で統一する
   • 例.「共通系 = 0xx」「外部サービス準正常系 = 1xx」「外部サービス異常系 = 2xx」「アプリケーション固有 = 9xx」といったように分類で頭文字を決める
4. 「アプリケーション固有のID(or 採番)」 + 「処理ごとのID(or 採番)」 + 「対処内容ごとのID(or 採番)」 の形式
   • 例. FSD100010
     • 「アプリケーション固有のID」= FSD
     • 「処理ごとのID」= 100
     • 「対処内容ごとのID」= 010

こうすれば、下記のメリットが受けられるのでは…と考えています。

• 『処理コードの桁数を統一』 ⇒ 検索をする際に 正規表現 が使える
• 『「処理ごとのID」は、処理の分類がある場合は、頭文字を統一』 ⇒ 検索をする際に 前方一致 が使える
• 『「対処内容ごとのID」は、サービス全体で統一』 ⇒ 検索をする際に 後方一致 が使える
• 『「対処内容ごとのID」は、サービス全体で統一』 ⇒ 最後の桁数を見れば、どういう対処をしたのかが分かる

②原因箇所を特定しやすくするための情報を出力する

「原因追及」し、不具合の根本対応をするために、原因箇所をすぐに特定する必要があります。
言語にも依りますが、 StackTrace を出力することでどういう経路で発生したのかを出力する場合もあります。

但し、StackTrace は出力している内容が多くなりがちですので、絞っておいた方がログファイルのサイズ削減もできると思います。
「一貫して処理名/API名の出力する」工夫や、「処理の開始となるファイル名を出力する」工夫をすると良いと思います。

また、バッチ処理のような時間がかかりそうなものや、どこまで実行されたのかを知りたい場面などでは、各ステップごとの「処理の開始」と「処理の終了」の情報を出力することで、どこにどのぐらいの時間がかかったのか、どこまで実行されたのか、ログ上から知ることもできると思います。

③共通処理ではログレベルをINFO以下で出力する

共通処理(外部サービス接続処理含む)で WARN や ERROR にすれば検知のすり抜けを防ぐことができます。但し、
機能ごとにどういった内容を WARN とするか ERROR とするか、扱いが変わる可能性が高いものでもあります。
「最終的に結果を返却する場所」もしくは「不整合など処理の終了する場所」でそのエラー内容を判別して、WARN以上のログ出力をすると良いと思います。

※ サービスが止まらないように全体の予期せぬエラーを扱う場面は例外的に ERROR となるかと思います

④一回ですぐに見つけられるような出力をする

上記にまとめておりますので、そちらをご覧ください。

⑤「どういった人」が行った処理が「どういう結果」になったかを出力する

「運用改善」や「サービス分析」をするには、「対象がどういうことをしたのか」を数えられることが望ましいと思います。
もちろん、「原因追及」のために「誰が」という情報を出力することも大事です。それに加え、
「どんな人達(例. 年齢帯, 種別 など)」といった情報を一緒に出力することで、有用な情報にもなると思います。

⑥ログが出力される可能性がある場合、一回の出力内容を踏まえて開発をする

ログ出力自体の話ではないのですが、一回のログ出力のサイズを気にする必要があります。

例えば、共通処理として「リクエスト/レスポンス」のログを出力することも多いでしょう。
複数件データを全て取得するような処理の場合、ネットワークの関係上、リクエスト回数を多くしたくないため取得数(limit)を制限せずに処理を行う場面もあります。

ここで問題になるのは、ログ出力内容を確認するサービスによっては、一回の出力内容が多いため、想定していない表示の仕方をする可能性があることです。極力、取得数を絞るなど、開発時の工夫をすることが望ましいですが、サービスの品質にも依るところだと思いますので、どうしても出力内容が多くなる…という場面では、マスク処理を行い強制的に内容を減らす対応が必要となります。

まとめ

1. ログの内容に気を付ける
   1. 個人情報など、漏洩してはいけない情報は出力しない
   2. 個人情報など、自由に入力してしまう可能性がある箇所は出力しない
   3. 統計したい情報は、保存されているデータを見なくても分かる情報であること
      • 「ログインをした」というログ出力であれば、「どういった人が？」「どのユーザーが？」を合わせて出力する
   4. ログだけを見て 何が起こったのかが分かり、追加調査ができること
      • エラー情報は、そのエラー詳細と合わせて、どういう対処を行ったのかが分かる内容を出力する
2. ログとして出力される文字数が多くなりそうな場合、ログの量を抑える
   • 部分的なマスク処理、全体的なマスク処理を行う
   • マスク処理をした場合、中身が分からなくなるデメリットが大きいため、マスクする箇所が多くならないための実装を心掛ける
3. ライブラリ、共通系で発生したログレベルは、INFO以下とする
   • 「この機能ではERRORではなくINFOにする」といった都合が発生する可能性があるため
   • 共通化した方がログレベルの間違いを防げるが、それはレビューで防げば良い
4. 追跡したい範囲で追跡ができるようにする
   • 複数の検索条件を使っても、1回で取得したい内容が見つかること
   • https://qiita.com/tkts_knr/items/a7b086335f3ddfae433c

最後に

ログ出力に関しては、開発方法は多くまとめられていますが、その中身や具体的な方法までを習うことはあまりないように思います。
初めてログ設計をした時は、「どういう内容が必要なのか」を考えた結果、「原因追及」の視点しか持てていなかったのが正直なところです。間違ってはいないのですが、今思うと、足りていなかったな…と反省しかありません。
また、基盤開発に携わった際に、ログ出力に関する余計なお世話をした結果、とても面倒な状態になってしまったのも事実です(必要最低限で何とかなる暫定的な対応をしました…)。

開発時にログ出力で迷った方、改めてログ出力を勉強し直したい方、基盤開発にこれから携わる方の力になれれば幸いです。