fujiike.jp

いろいろあるので、いろいろ書いていく。

ログ設計 2020-08-20

この記事ではログの設計について整理・検討していく。

ログの利用目的

ログは主に以下のような目的で使われる。

  • バグ調査
  • 事実確認
  • 異常検知
  • 行動傾向の調査
  • メトリクスの算出
  • 記録からの結果の復元
  • 開発中の動作状況の確認

サービスのデータベースに記録されるようなデータはBIツール[^1]などを用いて集計・分析することができるが、エラーの調査やデータベースに記録する必要性の薄いデータに関しては、ログという形で管理・保存することが多い。

ログの収集・管理そのものを外部ツール[^2]に頼ることもあるが、生データは自社サービスで保持するようなケースを想定して検討する。
外部ツールを用いる場合においても、どのようなデータが外部ツールに対して提供されているかを整理し、把握することは運用において正しく判断するための素材となる。

この種類のデータが活躍するのは、そもそもデータベースに記録する前に失敗するようなケースや、リクエスト情報など日常的にデータベースに書き込み処理をするには負荷が大きすぎるようなケース。

またログは保存できなくても本来のサービス運営に支障のないデータであることが求められる。
(逆に言えば、必ず保存できなければならない場合、ログとして記録するのではなく、サービスの必要なデータとして主たるデータベースに記録するのが望ましいと思う。)

ログに求められる要件

ログは上記の目的や要求から、以下のような要件を満たすことが求められる。

  • 書き込みに失敗してもサービス運営に支障をきたさない
  • ユーザーに表示されるべきでない情報が表示されない
  • 検索しやすい
  • 集計しやすい
  • 外部ツールと連携しやすい
  • ソフトウェア開発者が用意に書き込みを行い、確認できる

また、望ましい性能傾向として、主たる要件と相反する以下のような性能が期待される。

  • データの欠損が発生しづらい(なるべく全ての情報を、失敗なく記録できる)
  • 漏洩しても法的に、または社会通念上、問題ないデータである
  • 状況によって異なる構造のデータを記録できる

ログの種類

ログは記録されるときに主目的を意識して記録されることが多い。

そのため、ほとんどのログは以下のいずれかのパターンに分類できる

  • エラーログ
  • アクセスログ
  • 正常動作を示すログ(開発中の動作確認を含む)

また、他に以下のような観点で分類することができる。

  • ログレベル
  • 書き込み元の種類

ログレベルと対応方針

ログにはレベル(重要度)が定義されていることが望ましい。

利用目的の 異常検知 の項目に対応する部分であり、基本的には対応方針及び検知方法とセットで検討されるべき項目になる。

ログレベルには参考になる事例がいくつかある[^3]が、この記事では以下のように段階分けして運用することを推奨したい。

ログレベル 対応方針 検知方法
FATAL 問題が解決するまで全社・チーム全体で対応 slack及びメールで即時に在籍者全員に通知
CRITICAL 問題が解決するまでチーム全体で対応 slackのalert系チャネルに通知
WARNING チームで必ず把握し、対応時期を決めて修正・改善 発生頻度に対し閾値を決めてslackのnotice系チャネルに通知
担当チームが明確にできる場合は担当チームのalertチャネルに通知
INFO 常時把握の必要なし。必要に応じて調査などに利用 メトリクスを管理するダッシュボードなどで、閾値を超えることがないか監視

※ この記事ではslackを利用している企業を前提としています。必要に応じて利用しているチャットツールで読み替えてください。

書き込み元の種類

ログは書き込みを行うアプリケーションの種類や、アプリケーションのライフサイクルの中のどこで書き込まれたか、開発にどのような言語・フレームワークを用いているか、などによって記録できる情報が異なる。

そのため、どこから書き込まれる情報ではどんな情報が取得できるのか、という情報整理を行えることが望ましい。

以下に記載するのは、主要な事例の一部。
そのうちの一部は実装部分で触れる。

  • ブラウザのJavaScript起点で書き込まれるログ
  • iOS/Androidなどネイティブアプリケーションから書き込まれるログ
  • nginxなどWebサーバーから出力されるログ
  • SaaSなどのツールから出力されるログ
  • APIサーバーからレスポンス時に同時に書き込まれるログ
  • APIサーバー内部の処理中で書き込まれるログ
  • バッチサーバーなどの動作開始・動作中・動作終了時に書き込まれるログ

ログ記録におけるリスク

ログに求められる要件の中で、

漏洩しても法的に、または社会通念上、問題ないデータである

と記載したように、ログは流出することを常に警戒して記録されるべきものである。
本来「サービス運営上必要不可欠ではない」データであるにも関わらず、重大なセキュリティインシデントに発展するケースがある。

いくつか著名な事例へのリンクを記載する。

いずれもログやそれに類するデータに含まれるべきでない情報が記録されており、それが漏洩したことによってセキュリティインシデントとして問題になっている。

ログデータの出力項目

ログデータはここまでに整理した情報の通り、パターンや書き込み元の種類・タイミングによって出力可能な項目が異なる。

いくつかのパターンを想定して出力項目の定義の事例を検討する。

※ ちなみにこれが「正解」じゃないので、これさえ入っていれば大丈夫とか思わないでくださいね（念のため・・・）

ログで取ると良さそうな共通項目

項目 用途・説明など(あれば)
アクセス日時・処理日時 何気に揺れるから日付型はフォーマットをサービス単位で固めておいたほうがいいと思う
ログレベル
アプリケーションのバージョン アプリバージョン固有の問題を特定するために使う
カナリアリリースとかやってるとめっちゃ役立つ
実行環境の情報 prdとかstg1とか。地味に便利
コンテナID コンテナ時代ならコンテナIDわかると便利
処理したサーバーのIPアドレス どのサーバーで処理したか知りたいこと多い。コンテナIDと役割は似ている

APIサーバーのエラーログ

項目 用途・説明など(あれば)
stacktrace これがないと本当にデバッグが辛いので絶対に記録したい
エラーメッセージ ちゃんとアプリケーション側で作りましょう
URL・エンドポイント HTTPスキームとかも含む
リクエストパラメータの中身 passwordとか絶対にマスキングしないといけないから気をつけて！
※ セキュリティインシデントの事例参照
HTTPメソッド
エラー発生時点での変数・定数のログ 取れる場合はできるだけ出力したい

「その時点での変数・定数のログ」について補足

stacktraceやエラーメッセージだけだと、再現条件が不明瞭になってしまうケースが多い。 最低限、該当箇所のエラーの再現条件をわかるようにすることが目標となる(これがないと迷宮入りになりやすい)。 そのため、依存している定数と、渡されてきた変数はログに渡しておくこと。

可能であれば、そのエラーを発生させるリクエストの生成条件まで特定したいため、遡れる限りの情報を取りたいのが正直なところ。

ブラウザで実行された処理(JavaScript)のエラーログ

項目 用途・説明など(あれば)
stacktrace これがないと本当にデバッグが辛いので絶対に記録したい(二度目)
エラーメッセージ ちゃんとアプリケーション側で作りましょう(二度目)
エラー発生時点での変数・定数のログ 取れる場合はできるだけ出力したい(二度目)
実行されたページのURL・エンドポイント HTTPスキームとかも含む
クエリストリング 直接参照するケースが多いため
実行されたJSファイル名
依存しているcookieのキーと値 処理がcookieに依存していれば再現に必要
アクセス元端末のOSの種類 OS固有の問題を特定するために使う
アクセス元端末のOSのバージョン OSバージョン固有の問題を特定するために使う
ブラウザの名称 ブラウザ固有の問題を特定するのに使う
ブラウザのバージョン情報 ブラウザバージョン固有の問題を特定するのに使う
UserAgent文字列

「実行されたJSファイル名」の補足

キャッシュクリアなどの目的で、ビルドのタイミングでファイル名にdigestを追加するようなケースが最近は主流だが、こうなってくると純粋にファイル名や該当箇所を拾ってきても、minifyされていてわからんとか、既知のエラーがビルドバージョンごとに別のエラーのように出力されるとかいったことが発生する。

このため、特にReactやVue.jsのようなフレームワークを利用していたり、webpackで独自にビルドしているようなケースでは、stacktraceやエラー発生箇所の情報は、コンパイル前の情報が拾えるようなライブラリを用いてログに書き出す方式が望ましいと思う。

あんまり現実的じゃないけど、調査のためにはほしいよなあ、というもの

ブラウザ上のエラーはサービス規模が大きくなってくると本当に辛くて、再現できないケースが増えてくる。

そのため、ガチで再現してエラーゼロみたいな世界観を目指す場合、とにかくリクエストを再現することに全力を尽くすことになる。
そうなると以下のような情報が必要になる。

項目 用途・説明など(あれば)
そのJSを実行したDOMのネットワーク通信のログ コケる前にそもそも特定のライブラリの読み込みにコケてた、とか割とある
レンダリングしているDOMの情報 Chrome拡張とかでDOMがいじられてるケースがあって再現不可能なバグとかけっこうある
実行時に読み込まれていたChrome拡張などの外部情報 同上

バッチ・ワーカーなどで実行された処理のエラーログ

項目 用途・説明など(あれば)
stacktrace これがないと本当にデバッグが辛いので絶対に記録したい(二度目)
エラーメッセージ ちゃんとアプリケーション側で作りましょう(二度目)
エラー発生時点での変数・定数のログ 取れる場合はできるだけ出力したい(二度目)
外部から受け取った情報 HTTPリクエストでいうところのパラメータ

アクセスログ・HTTPレスポンスのログ

項目 用途・説明など(あれば)
URL・エンドポイント HTTPスキームとかも含む
リクエストパラメータの中身 passwordとか絶対にマスキングしないといけないから気をつけて！
※ セキュリティインシデントの事例参照
HTTPメソッド
HTTPレスポンスステータス
アクセス元IPアドレス DOS攻撃などを弾くためにほしい
GeoIP系の情報とかは分析に便利
※ 情報漏洩気をつけてね
アクセス元端末のOSの種類 OS固有の問題を特定するために使う
アクセス元端末のOSのバージョン OSバージョン固有の問題を特定するために使う
レスポンスタイム パフォーマンス改善、遅いエンドポイントの特定とかに必要
HTTPバージョン 1.1とか2とか

取るケースもあるけど必ずしも推奨しないもの

項目 用途・説明など(あれば)
HTTPレスポンスbody とにかくデータ量がとんでもないことになるし、ユーザー固有の情報含まれてたりするから微妙
HTTPリクエストヘッダ丸ごと 便利だけど漏洩したらヤバい情報いっぱい入ってそう
GeoIP系の情報 分析のときにあると嬉しい。
だんだんUA取れなくなる方向に来ているから微妙
UserAgent 分析のときにあると嬉しい。
だんだんUA取れなくなる方向に来ているから微妙
Referer 分析のときにあると嬉しい。Yahoo!ニュース砲だ！とか解析するのに使える。
だんだんUA取れなくなる方向に来ているから微妙

HTTPリクエストヘッダは丸ごと取っておくと便利そうだけどセキュリティ的にはどうなんだろう。 https://developer.mozilla.org/ja/docs/Web/HTTP/Headers

ぼやき

リクエストヘッダのサイズとかbodyのサイズとかってどうなんだろう。

バッチ・ワーカーなどの実行前ログ

取るといいと思う。実行しようとしたけどコケた、みたいなときに、必ずしもエラーをちゃんと吐いてくれるとは限らない。

項目 用途・説明など(あれば)
実行するタスクの名称 ちゃんと名前つけて記録しておきたい
外部から受け取った情報 HTTPリクエストでいうところのパラメータ

バッチ・ワーカーなどの実行結果ログ

項目 用途・説明など(あれば)
実行するタスクの名称 ちゃんと名前つけて記録しておきたい
外部から受け取った情報 HTTPリクエストでいうところのパラメータ
処理にかかった時間 重いタスクとか抽出できるので記録しておきたい

[^1]: BIツールの例としては、 redash, metabse, looker などが挙げられる。 [^2]: ログ収集まで含めて連携する外部ツールの例としては、 Google Analytics, Amazon CloudWatch, Cloud Logging, sentry, datadog, KARTEなどがある。当然ながら、ツールの目的によってカバーしている範囲が異なる。 [^3]: log4j, PSR3 など参考になる情報は多い。利用するロギングツールによってデフォルトのエラーレベルのパターンはある程度指定されている。どのエラーレベルを、自社・自チームのどの対応方針で扱うかは都度定義する必要がある。