85-冗長なログは眠りを妨げる

「プログラマが知るべき97のこと」の85個目のエピソードは、ロギングに関する話です。ソフトウェア開発をしていく中で何かと面倒で優先度を低くされる事が多いのは、ロギングとエラーハンドリングでしょう。どちらもユースケースにおける基本シナリオを実装するためには、直接の関連はありません。プログラマとしては、まずは動くものを提供したいという気持ちがあるため、どうしても後回しにしがちなのです。しかし、開発が進み気付いた時には大量のTODOが残っている、そんなパターンはよく聞く話です。
このエピソードでは、そんなロギングについて、どの程度行う事が良いかが書かれています。開発現場によっては、ロギングが非常に細かいレベルで求める開発標準を採用しています。例えば、privateを含むすべてのメソッドの入口と出口でデバッグログを出力するといったケースです。これは明らかにログの取りすぎです。このエピソードにも書かれているように、多すぎるログは本当に必要な情報を探しにくくします。余りにも細かすぎて必要な情報を得ることができないのであれば、ロギングを行う価値はありません。ログによって必要な情報が素早く見つけられることが重要なのです。逆にログがほとんど無い場合、必要な情報を得ることができません。Javaであれば例外オブジェクトは大量の情報を持っています。したがって、ほとんどのロギングAPIは次のようにして、例外オブジェクトを渡すことができます。

try {
   // do something
} catch (SomeException e) {
   logger.error("Xxx error", e);
   // error handling
}

ロギングAPIは適切に例外をログに出力し、その中にはスタックトレース情報が含まれるでしょう。スタックトレース情報が確認できれば、例外がどこでどのような理由で発生したかのアタリがつくのです。しかし、ここで例外オブジェクトを無視し、アプリケーション固有のメッセージのみを出力してしまったらどうなるでしょうか？

try {
   // do something
} catch (SomeException e) {
   logger.error("Xxx error, because of ...");
   // error handling
}

確かに例外がキャッチされた事はログに書かれます。しかし、スタックトレースを知るすべはありませんので、原因の分析に時間がかかる、もしくは不可能になってしまいます。業務アプリケーション等を作っていると、上記のような「例外をあえて出力しない」という慣習があるのは残念な話です*1。
多すぎてもダメ、少なすぎてもダメ、ロギングの適切な量は一筋縄ではいかない問題です。アプリケーションの性質にも依存します。また、デバッグログとエラーログは目的が全く異なることも忘れがちな事です。エラーログはシステムに重大な問題が発生した事を伝える目的で作られ、内容はそれを分析するための情報です。本当に必要なとき以外はエラーログを吐かないこと、重大な問題を作り込まないように充分にテストすることが大切です。

プログラマが知るべき97のこと

*1:ユーザにスタックトレースを見せるのはダメという主張からくる