はじめに
ログを追加する時に、「調査しやすいように」「運用で役に立つように」ということは理解しているのだが、今回他の方がログを追加してくださり、実際にどういうことかとても勉強になったので、こういうことを出力すればよいのかとわかったことをメモしておく。
ERRORログ
エラーの発生内容がわかるようにする。
- どこで起きたエラーか
- 内容（外部API呼び出しの場合は、エラーのステータスコードやエラーメッセージなど。内部でのエラーの場合もエラーメッセージなど）
- 外部API呼び出し時はエラー時に渡したリクエスト
上2つは今までもやっていたけど、3つ目もあると便利。
WARNログ
致命的ではないが注意すべきこと、今後問題になるかもしれないこと。
- 通常時でも発生しうるエラー（リトライなどで回復可能）が発生したという記録
エラーだからといって全部ERRORログにする必要はない。でもリトライで復帰可能なエラーでも発生したことは追えるようにしておいた方がよい。
INFOログ
担当システムでは、INFOレベルまで通常ログを出しているので、常に出力されることになるログ。
- リクエスト内容
- 調査の時にあると助かる。
- リトライの記録・リトライ回数・リトライ待ち時間
- API全体としては正常終了しているが、リトライが発生している時に、どれくらいリトライが発生しているか調べられる。API正常終了なのに内部的にはリトライが頻発している状況に気がついたりしやすくなる。（待ち時間は少し時間を置いてからリトライする設定にしている場合）
- 特に時間がかかりがちな外部API呼び出しのレスポンスタイム
どれくらい細かく出すかはログの保存容量や価格とも相談になるかもしれない。
今回入れてもらったログは結構細かめな気がする。
DEBUGログ
本番環境では通常は出力されないログだが、エラー発生時やテスト時などにログレベルを変更して調査に使えるようにする。
-
外部APIのリクエスト・レスポンス内容
- 普段から全て出すと膨大な量になってしまうが、当該APIのエラー時の調査に役立つ。実際レスポンス内容はとても役に立った。エラーになる前から仕込んであるとログレベルを変更するだけで調査できて便利。
-
エラーに関して怪しい部分
- 今回は他のログの出力状況から序盤に落ちている可能性が高かったため、序盤の処理１行１行にログを仕込み、ログがどこまで出ているかで落ちている箇所を特定していた。
- 今回どこかの処理に時間がかかりタイムアウトエラーが発生していたため、外部APIのメソッドそれぞれにかかった時間を出力していた。
たまにしか発生しないエラーに関して、１行１行ログを出して、エラーが出たタイミングでリクエストID（も出していた）で絞って状況を特定するがとてもよかった。
その他（共通）
- 配列などの場合は、対象のデータがどれかわかるidなど。
- リクエストのIDなどリクエスト全体でログを追えるようにするデータ。（ログライブラリで自動で出してくれる場合が多そう。）
- どのクラスで出力されているログか。（これもログライブラリに引数で渡すと記録してくれる場合が多そう。）