目次
はじめに
- これまで様々な企業でシステムやWebアプリの設計開発や運用・保守を行ってきました。これらの経験を踏まえて思うログの設計・実装ポリシーについて説明します。
個人の感想や愚痴になっている個所も多々あるため、参考程度でご覧いただけると幸いです。 - 多くの現場では主に３つのチームに分かれてプロジェクトを進めていました。私が担当していた業務やアプリ基盤チームの目線での説明になります。
チーム名 担当範囲 システム基盤 クラウド、ネットワーク、ネットワーク機器、サーバ、データベース アプリ基盤 アプリフレームワーク、共通部品、ミドルウェア 業務 顧客向けの画面やページ、処理システム - 他のシリーズの紹介です。
設計ポリシー
- 満たすべき要件の有無を確認
PCI-DSSやマイナンバー安全管理措置などへの対応が必要な場合、ログの取得タイミングや内容、保管期間等のようにログの設計に大きく影響するので早い段階で明確にする必要があります。 - 運用・保守での使用目的に応じたログ種別の決定
使用目的 説明 ログ種別の例(参考) システム監査 機能・画面・データ等に対して、いつ誰がどんな操作を行ったかを開示する。 監査ログ
証跡ログ
操作ログ稼働監視 障害が発生した際にシステム運用・保守担当者にアラートを通知する。 エラーログ セキュリティ調査 不正アクセス時や情報漏洩時の経緯・影響・原因を調査する。 セキュリティログ 運用・保守計画 システムの利用状況やリソース状況に基づいて、システムの改修計画やリソース増強計画を立案・遂行する。 アクセスログ
診断ログ
パフォーマンスカウンタ
統計ログ障害調査 ユーザ操作や処理の過程を追跡して障害原因や影響範囲を特定する。 アプリログ
サーバーログ- ログは数日で数GB、数百MB等のように大量になることがあります。このような巨大なファイルをツールで開くとPCのメモリを圧迫し、個々の編集操作に非常に時間がかかり、作業効率が悪くなります。目的や日付・時間等に応じてログを分割することで、ファイルがコンパクトになり、処理しやすくなります。
- 用途が不明確だったりログ量が少量な場合は、特定のログ種別に纏めて出力しても良いと思います。例えばエラーに関するログは、運用監視や障害調査でも使用するので、エラーログやアプリログ等の複数のログ種別に出力しても良いと思います。
- 一般的なアクセスログは、ロードバランサやリバースプロキシ等のフロントサーバで出力している場合が多いので、アプリで個別に取得する必要はありません。フロントサーバのアクセスログで情報が足りない場合や、フロントサーバで独自にリクエストを加工している場合等では、アプリでアクセスログを取得する場合も考えられます。
- ログの使用用途（想定される操作）を踏まえたログ出力先の決定
- 顧客側の監査目的でシステムの機能・画面の操作履歴を閲覧するような場合、オンラインで検索や絞り込みが可能なデータベース等が出力先の候補となります。稼働監視やSIEM等のログ収集・分析ツールを使用するのであれば、そのツールが対応する出力先が候補になります。
- その他、用途が不明確だったり、使用頻度が低いログ種別は標準的な出力先で良いかもしれません。Windowsであればイベントログ、Unix/Linuxの場合はsyslog、単純なログファイル等。
- クラウド環境の場合、ログの分析や管理が行える包括的なソリューションであるAzure Application InsightsやAmazon CloudWatch Logs等が出力先の候補になります。
- よく使用される重要度（ログレベル）の例
- 一般的なログ管理ツールやログ出力ライブラリでは少なくても次の5段階の重要度に対応しています。
実運用ではエラー・警告・情報が使用されるため、設計書上では主にこれらの重要度の取り扱いが定義されます。デバッグ・トレースは主に開発用途で使用されるため、設計上ではほとんど定義されず、開発者任せになることがほとんどです。重要度 使用ケース 備考 エラー
(Error)想定外のエラー(例外)が発生し、処理が正常に完了しなかった。
運用・保守担当による原因調査や対応が必要。稼働監視の対象(優先度高) 警告
(Warning)処理が正常に完了したが、一部で無視できるエラーや想定外データがある。
運用・担当者の確認が必要。稼働監視の対象(優先度低) 情報
(Information)証跡として残すべき情報
後に参考となる可能性がある情報など。デバッグ
(Debug)問題発生時のデバッグのために使用する。
主に開発環境や試験環境で使用する。本番では出力を抑制される。 トレース
(Trace)難易度の高い問題のデバッグに使用する。
基本的に開発環境や試験環境でも使用しない。 - エラーと警告の使い分けに関して、処理を完了できなかった場合はエラー、処理を完了できたが一部で想定外の処理があった場合は警告、という場合が多いと思います。
- 開発環境では、デバッグしやすいようデバッグ以上のログを出力します。デバッグのログでも問題の切り分けができない場合は、トレース以上のログを出力するようにします。一般的なトレースのログは大量になるので、必要なタイミングで初めて有効にします。
- 一般的なツールやライブラリではデバッグとトレースを使い分けたログが出力されます。残念ですが私の知る限り、ほとんどの開発現場ではデバッグやトレースのログを使う習慣がないので、このような現場の成果物ではデバッグやトレースのログは出力されません。
- 結合試験やシステム試験環境では本番同様に情報以上のログを出力する場合がありますが、不具合対応を効率的に行うためにデバッグ以上のログを出力することが多いようです。
- 本番環境では、最低限の品質は担保されておりデバッグのログは不要なことや、多数のユーザによるアクセスでログが大量になるため、情報以上のログのみを出力します。このようなログから障害原因の特定が難しい場合、期間や対象となる機能・画面・処理を絞ってデバッグやトレースのログを有効にする場合があります。
- 一般的なログ管理ツールやログ出力ライブラリでは少なくても次の5段階の重要度に対応しています。
リンク
ログ出力項目
- 共通項目
- よく使用される共通の項目例を次に示します。
複数ユーザ・複数リクエストが入り乱れるような処理が想定される場合を想定して、処理を追跡できる項目を選定する必要があります。No. 項目 備考 1 日時 少なくてもミリ秒3桁以上は必要 2 送信元IPアドレス 環境によっては実際の送信元IPアドレスを取得できない場合あり。
(後述のXFFを参照)3 リクエストID 4 ユーザID アプリ上で認識しているユーザID
(アプリ依存の情報になるためMDC等の仕組みで出力)5 スレッドID 6 ロガー（ログ送信元） ログ出力するクラス名等 7 ログレベル ERROR, WARN, INFO等 8 メッセージ 任意のテキスト(エラーメッセージやスタックトレース等) - 共通項目は全てのログに出力されるので最小限の項目に限定する必要があります。例えばセッションID等のように非常に長いデータをログに残しておきたい場合、共通項目ではなくセッションID作成時のログ（メッセージ）として一度出力しておけば、分析時にリクエストIDやユーザID等で紐づけることができます。ログを分析する際に、どのような項目があると問題の切り分けがしやすいかを考えても検討が必要です。
- ロードバランサやリバースプロキシ等のフロントサーバが存在する場合、アプリで取得する送信元IPアドレスが全てフロントサーバのIPアドレスになってしまう場合があります。このような問題が発生しないことを事前にシステム基盤側に確認しておく必要があります。
- なお、この問題を解決するポピュラーな方法として、HTTPヘッダのX-Forwarded-Forを使用する方法があります。フロントサーバではXFFヘッダにオリジナルの送信元IPアドレスを設定できるので、アプリ側では当該ヘッダから送信元IPアドレスを取得できます。
（なお、複数のフロントサーバを経由するような場合、XFFヘッダに複数のIPアドレスが含まれる場合があるので、その点を注意した実装が必要です。） - HTTPリクエストのUser-Agentは改ざんされる可能性があるので、ログ解析のヒントにしか使用できません。
- よく使用される共通の項目例を次に示します。
- ログ（メッセージ）に出力すべき情報の例
- 処理対象を識別するキー
- 障害調査時に判断条件や更新対象等の追跡ため。
- リクエストID、レスポンスID、オブジェクトID、テーブルのキー等
- ユーザに通知した情報
- 障害調査やユーザからの問い合わせ時の追跡のため。
- 取引ID、注文番号、チケット番号、問い合わせ番号等
- セキュリティに関わるイベント
セキュリティインシデントが発生した場合の追跡が行えるようにするため。分類 例 備考 認証の成否 認証失敗ユーザID 攻撃の予兆を把握するため セッション サインイン、サインアウト 認証関連の変更 パスワード、2段階認証用のSMSやメールアドレスの変更 権限昇格 管理者モードに切替、ヘルプデスクユーザから顧客ユーザへ切替 認証要素や権限の操作 アカウント作成・編集・削除、権限変更
アクセストークン・クライアント証明書発行 - 複数処理実行時のサマリ
複数の処理対象を繰り返し処理するような場合、個別の処理結果を大量に出されても全体の処理状況をすぐに把握できません。
全ての処理完了時に「対象件数」「成功件数」「失敗件数」「警告件数」等のサマリのログ出力をお薦めします。（サマリは情報レベル、失敗は警告レベルでログ出力することが多い。） - メッセージID
- 製品やパッケージ等のように開発者と運用・保守者が分かれる場合、運用・保守者はログに出力されたメッセージのみで対応内容を決定する必要があります。このような対応の正確性を確保するためにメッセージID（とメッセージIDに紐づくメッセージ）をログに出力する場合があります。運用・保守マニュアルに記載された「メッセージID毎の対処方法」に基づいて行動するイメージです。
- 国際化対応する場合、メッセージIDに紐づくメッセージを実行環境（ロケール）に合わせて英語、日本語等に変更する必要があります。
- 私が経験したほとんどの案件では、自社で運用・保守だったのでメッセージIDは使用せず、都度任意のメッセージを記載していました。）
- 処理対象を識別するキー
- ログ（メッセージ）に出力してはいけない情報の例
不正アクセスは管理者や運用者等の内部犯行の場合が多く、担当者の目に触れる可能性が高いログに機密情報は出力しないようにします。分類 例 認証情報 パスワード、暗証番号 個人情報 氏名、生年月日、住所、電話番号、メールアドレス、マイナンバー
(単独または組み合わせで個人を特定できる)決済情報 クレジットカード番号・有効期限、口座番号・名義人名 機密情報 暗号化・復号化キー、アクセストークン
例外のログ出力
- 想定される例外はログ出力不要
- ユーザの入力間違いで発生する検査例外やエラーは、画面に表示されたエラーメッセージに基づいてユーザ自身でリカバリできるので、基本的にログ出力は不要です。
- 外部からのWebAPI呼び出し時のパラメータ不正で発生する検査例外やエラーは、応答データとしてスタータスコードやエラーメッセージを返却することになります。呼び出し元ではログを確認してでリカバリできるので、基本的にログ出力は不要です。
- セキュリティに関わるユーザの入力間違いやWebAPIパラメータ不正に関しては、攻撃の予兆を把握するためにログに残した方が安全です。不特定多数に公開するWebAPIの場合は、一律ログに残した方が安全です。
- 想定外の例外はスタックトレースの出力が必要
- メモリ枯渇(OutOfMemoryException)、Nullオブジェクト参照(NullPointerException, NullReferenceException)やメソッド実行時の引数不正(IllegalArguementException, ArgumentOutOfRangeException)等の実行時例外はどこで例外が発生するか予想できません。
- このような実行時例外が発生した場合、例外メッセージの他に、例外発生場所や呼び出し順番を把握可能なスタックトレースをログに出力する必要があります。
- 運用・保守担当者向けの想定例外はログ出力が必要
- アプリ起動時に定義されているべき設定値がない（運用・保守時の間違い）、通常到達しえない条件分岐に到達（不正操作やバグ）、等のような場合は当該箇所で例外をスローすることをおすすめします。このようなケースでは、例外の発生条件や発生場所を特定できるのでスタックトレースの出力は不要です。
- ただし、様々な場所から実行されるような場合だと、呼び出し元の特定ができないのでスタックトレースの出力が必要です。
リンク
トレーサビリティの確保
- 追跡可能性（トレーサビリティ）の確保
- 基本的な考えとして、ログで処理を追跡できるようにする必要があります。
- システム・アプリ境界を跨いだトレーサビリティの確保
- サブシステムや外部システムとのデータ連携でステムやアプリの境界を跨いだ処理を行う場合でも、処理の開始から終了までをログで追跡できる必要があります。
- 連携システム間で処理を追跡できるよう、連携元システムではリクエストID等の処理を一意に識別できる情報をリクエストに付与する必要があります。連携システム相互で当該IDをログ等に残しておき、障害発生時に当該IDを使用して相互にログを調査することになります。
（データ連携先で障害発生時に処理対象のリクエストの識別が難しいため、レスポンスではなくリクエストにこのようなIDを含めることを推奨します。）
- 時刻同期の必要性
- システム間で時刻がずれていると追跡が困難になるので、システム間はNTP等で時刻同期されている必要があります。
- これはシステム基盤側で担保している前提になります。
監査ログの用途とログ出力先
- 監査ログの種類と用途
- 複数企業向けのアプリの場合、顧客企業の監査目的でユーザが使用する監査ログ（以後「業務監査ログ」）、システム運営側の監査目的で使用する監査ログ（以後、「システム監査ログ」）が考えられます。それぞれの用途（ログの使われ方）を意識して設計を行う必要があります。
- 業務監査ログ
- 顧客企業の監査時に顧客企業の管理者が各種条件を指定して監査ログの検索やエクスポートしたい場合があります。このような用途ではログ出力先は、データベースのようにオンラインで柔軟にデータの検索が行えるストレージが推奨されますが、データ使用量に対するコストが比較的高いため、保管期間やデータ量を制限する必要があるかもしれません。
- 例えば「ログ保管期間は10年」などのようにコスト上の理由で顧客の運用要件を満たせない場合があります。このような場合は、「定期的に顧客にログをエクスポートしてもらう運用」、「追加料金でデータ量使用上限を引き上げる」、「有償で保守担当者がバックアップストレージから当該顧客の監査ログを抽出する」等の代替案が考えられます。
- システム監査ログ
- 運用・保守担当者が解析できれば良く、必要に応じてバックアップシステム等から必要なログを収集して分析することもできるので、必ずしもデータベースである必要はありません。（データベースに保管する方式は、既存のログ出力の方式に比べ容量や性能の制約が厳しく、結果的にコストが高くなるので避けたい。）
稼働監視システムとの連携
- 稼働監視システムはシステム基盤の担当範囲
ほとんどの場合はシステム構築時に併せて稼働監視システムが導入されます。主に稼働監視システム自体の設計はシステム基盤になります。稼働監視システムでは、システムやアプリから出力されるログを監視し、異常があれば保守担当者にアラートを通知することになります。稼働監視システムの設計では、主にアラート通知の対象となるログの「ログ出力先」「ログ抽出条件」を決定する必要があります。 - システム・アプリの監視内容はシステム基盤では決められない
- アラート通知の条件は、アプリ側の設計や運用・保守に関わる部分であるため、稼働監視システムの担当者側では決められません。アプリ設計者側が主体的に監視システムの担当者と決定していく必要があります。
- 一般的な稼働監視システムは様々なログ出力先や抽出条件をサポートしています。それに比べ、アプリの方が自由度が少ないため、アプリ設計者がログ出力先や抽出条件の候補を提示する場合があります。
- システム基盤やアプリ基盤では過去の事例を提示することはできますが、業務側が決定する必要があると思います。この関係性を間違えて打ち合わせをすると「そちらで決めてください。」と冷たくあしらわれたりします。
- 「ログ出力先」に関して、可能であればWindowsイベントログやsyslogなど実行環境で標準的なログ出力先の使用をお薦めします。アプリ設計者側であまりメリットはありませんが、システム全体としてログの収集・分析・保管方式が統一され最適化できるため。
（逆に、システム全体方針としてWindowsイベントログやAzure Application Insights等への出力が決まっている場合もあります。） - 「ログ抽出条件」に関して、ほとんどの案件では「エラーレベルのログを一律アラート通知（重要度高）」「警告レベルのログを一律アラート通知（重要度低）」になることが多いと思います。この場合は後の設計や実装で、安易にエラー・警告レベルのログを出力しないようガイドやレビューする必要があります。
- 全体方針で決まっている場合もある
採用するプラットフォームや設計によっては、監視対象とするログの出力先やログの出力条件が事前に決まっている場合があります。例えば、マイクロソフト系のソリューションを使うシステムであれば、SCOMやAzure Monitorなどのイベント監視システムでの監視を前提とし、ログの出力先はイベントログに統一される場合があります。この場合、ログレベル（ログ重要度レベル）がError, Warning以上のものが監視対象になります。
SQL文のログ出力
- SQL文のログ出力の有効性
結合試験やシステム試験環境等のようにデバッガの使用が難しい環境で、SQLに起因するバグが発生した場合、実行時のSQL文とパラメータ・検索結果がログに出力されていると、デバッグが非常に楽になります。 - 本番でのログ出力の試行
- 同じ理由で本番でもSQLをログに出力しようとする設計が検討されますが、本番では利用ユーザ数が多くなるので、ログサイズが肥大化するため性能劣化や管理コストの増大、重要な情報を見落とし等が発生する場合もあります。
- 開発環境や結合・システム試験でのSQLのログ出力は問題ありませんが、前述の理由で本番環境での基本的にSQLのログ出力は推奨しません。そもそも、本番環境でSQLをログ出力を求める背景に問題がないかを振り返った方が良いかもしれません。単体・結合・システム試験で、当該機能・画面の品質は十分担保されているのでしょうか？
- ただし、原因の特定が困難な本番障害対応でSQLを確認したい場合は、当該機能・画面等に絞り込んでSQL文をログ出力することを検討してください。この際、当該機能・画面に対するアクセス数等に基づいてログの増加量を把握（見積）しておいた方が安全かと思います。
- SQLのログ出力方法
実行対象となるSQL文やパラメータのログ出力機能はDBアクセスフレームワークやライブラリに実装されている場合が多いので、独自に実装する前にリファレンスを確認することをお薦めします。
その他
- ログ分析の効率化
顧客からの問い合わせや障害発生時、往々にして経緯、原因、対応方針、目途となる時間の報告を求められます。一方で、本番環境へのアクセスの承認、バックアップストレージから対象となるログの収集、複数のログから対象日時やユーザ等の絞り込み等、ログの分析を開始するまでに様々な手間や時間がかかります。
ログの分析や意思決定等の重要な作業により多くの時間を使えるよう、機械的な作業は自動化できるようなツールの検討をおすすめします。（時間の節約の他に人の介在に伴う間違いの低減にも貢献します。） - ログへの日本語の出力
システムエラーやデバッグで使用するメッセージに日本語を使用すると、環境やツールによっては文字化けして正しく処理されなかったり重要な情報が消失する場合があるので、このようなメッセージには日本語ではなく英語（片言の英単語）を使用することをお薦めします。
（製品やパッケージの場合ではエンドユーザがメッセージを見るので日本語を使用するのはやむを得ないと思います。）
実装ポリシー
ログ出力の共通部品化
- アプリ基盤によるログ出力機能の提供
可能な限り業務での個別実装を減らし工数削減や実装のバラツキを低減するために、共通的なログ出力の仕組みや部品はアプリ基盤で提供します。 - ログ出力処理の隠蔽
各機能・画面等で共通のログ出力は、横断的に業務処理前後で独自処理を挿入できる仕組み（インターセプタ、フィルタ、ミドルウェア等）で実現します。 - ログ出力共通部品の提供
業務側のタイミングでログを出力する場合、前述の横断的なログ出力の実装が難しいため、ログ出力の共通部品の開発を検討します。 - 既存のログ出力機能の利用
データアクセスライブラリでは、データ操作前後に独自処理を挿入できることが多いので、その仕組みを使ってログ出力を行うこともできます。 - 共通項目の出力
一般的なログ出力ライブラリでは、マップ化診断コンテキスト(MDC: Mapped Diagnostic Context)等のようにログ出力項目に独自の項目を追加できます。「ユーザID」「XFFを使ったリクエスト元IPアドレス」等の独自の共通項目を出力する場合、このようなライブラリの仕組みを使うことでより簡単に実現できます。
デバッグ・トレースレベルの活用
- ログレベル使用の自由度
- デバッグ・トレースレベルのログ出力は設計書に明記されることは少なく、開発者に一任される場合もあります。これらを使って処理の妥当性や問題切り分けのための情報をログ出力することをお薦めします。
- デバッグ・トレースの使い分け
- デバッグは処理の節目となる場所でのデータや条件の記録（点での記録）、トレースはその節目を結ぶ細かいデータや処理条件を記録（面での記録）するのに使用するイメージです。
- 基本はデバッグのログで確認しますが、それで問題切り分けができない場合はトレースのログを確認します。（基本は点で確認するが、必要なら点・面で確認するイメージ）
- 後のトラブルに対する準備
- アプリフレームワークや共通部品で提供する認証やアクセス制御等の一部機能は処理が複雑になりがちです。プログラムが正常に動作している場合は良いのですが、後でプログラムや実行環境が変わって動作しなくなると原因調査や問題切り分けが非常に難しくなります。このような場合に備えて、条件分岐や処理過程をデバッグ・トレースレベルで出力することをお薦めします。
- Web API、FTP、SCP等の外部連携では、開発環境に連携先サーバを用意できないことがあります。開発環境ではモックの連携先サーバで試験を行い、本番環境構築後に本番の外部連携先サーバと結合試験することがよくあります。本番での結合試験で問題が発生した際の問題の切り分けが簡単に行えるよう、通信内容はトレースレベルで出すことをお薦めします。
- 業務上興味の低い複数処理実行時、個々の処理結果はトレースで出力し、全ての処理完了時に「対象件数」「成功件数」「失敗件数」「警告件数」等のサマリをデバッグで出力する方法もあります。
リンク
ログ出力実装時の注意点
ログ出力の実装方法によって不具合や性能劣化を引き起こす場合がある
- ループ処理内でのログ出力の最小化
- ループ回数が数百、数千回以上になる処理でログを出力すると性能劣化やログが肥大化します。
- ループ処理内でログの出力を検討する場合、おおよその最大ループ回数を想定して、どのような結果になるかを想像することが重要です。ループが2重・3重にネストされているような処理（多重ループ）では、ループ回数が急激に増加する場合があるので特に注意が必要です。
- ログと関係ありませんが、そのような処理ではHashMapやDictionary等を使うことでループを減らせる場合があります。
- ログ出力のための複雑な処理は避ける
- 問題切り分けのためのログ出力が問題を発生されるような本末転倒な事態を避けるため、ログ出力は可能な限り単純にする必要があります。
- ログを出力する共通処理では、本来の業務処理を中断させないよう、安易にエラーや例外を発生させないよう注意が必要です。（本末転倒を避けるため。）
- 「開発環境では正常に動作するが、本番でログレベルを引き上げたら正常に動作しない」等のように不要で初歩的なバグを呼び込む可能性があるので、可能な限りログレベルで条件分岐が変わるような処理は実装しないようにします。この手のバグは本番で発覚すると、品質管理部門から問題を誇張され不毛な作業を強いられる場合もあります。
- ただし、「大量データをそのまま出力するわけにはいかないので簡略化してログ出力する」「リストに含まれるオブジェクトのデータを編集してログ出力する」等のデバッグ目的でしか使用しない処理はログレベルを条件でスキップしても良いと思いますが、必ず単体試験する必要がある。
- 性能を改善するために「デバッグレベルだったらデバッグログを出力」等のようにif文でログレベルを判定する人がいます。ほとんどのログ出力ライブラリでは、不要な処理を避けるために可能な限り早いタイミングでログレベルを判定していると推測されるので、敢えてこのようなコードを追加する必要性はないと考えています。
（筆者の想像だが、我々よりも数段優秀な人たちが同時実行や性能を考慮して考慮してライブラリを開発しているので、このような初歩的なことは考慮されていると信じています。）