Java : ログレベルの指針 (使い分け)

標準ロギングAPIには、ログレベルという概念があります。
SEVERE, WARNING, INFO, FINEなどなど。

しかし、どんなときにどのレベルを使えばよいか迷ったことはありませんでしょうか?

本記事では、そんなログレベルの指針(使い分け)についてご紹介します。


概要

JavaロギングAPIはjava.util.loggingパッケージに含まれており、エンド・ユーザー、システム管理者、フィールド・サービス・エンジニアおよびソフトウェア開発チームが分析するためのログ・レポートを作成することで、顧客サイトでのソフトウェアのサービスや保守を簡単にできるようにします。

上記はロギングについての公式ドキュメントになります。

ロギングAPIにはログレベルという概念があります。
ログレベルは、それぞれのログがどれだけの優先度 ( 重要度、緊急度 ) なのか?ということを表します。

公式ドキュメントやAPI仕様には、ログレベルについて、そこまで具体的な使い分けについては書かれていないようでした。

そのため、本記事は、あくまで私の主観たっぷりな指針となります。
ログレベルの指針の一例として読んでいただけたら助かります。

指針を決めるうえで大事なこと

ログレベルの指針を決めるうえで大事なことが1つあります。
それはアプリやサービスを開発するチーム全体で、ログレベルの指針を統一することです。

多人数で開発、保守をしていくような大きなアプリやサービスでは特に大事です。
各プログラマが勝手にログレベルをつけてしまうと、アプリやサービスを保守していくときに苦労することになるでしょう。

ログレベルは、発生した問題を切り分けるための重要な情報です。

ログレベルの指針がしっかりしていれば、

  • SEVERE (重大) レベルのログが出力されたから、すぐに担当者に連絡しないと!
  • WARNING (警告) レベルだから急がなくても大丈夫…メールで連絡しておこう。

というように、ログレベルだけ見て素早く次の行動に移れます。

もしログレベルの指針がしっかりしてないと、

  • まずログメッセージの内容を確認
  • 次にどれくらい緊急性があるか判断

というように、問題発生から次の行動までに手間が増えることになります。
ログメッセージから緊急性を判断するのが難しいこともあるかもしれません。

緊急時にも素早く対応できるように、ログレベルの指針をしっかりとチーム全体で統一したいですね。

ログレベル

Levelクラスは、ロギング出力の制御に使用可能な一連の標準ロギング・レベルを定義します。
ロギングLevelオブジェクトは順序付けされており、順序付けされた整数によって指定されます。
あるレベルのロギングを有効にすると、それより高いレベルのロギングもすべて有効になります。

標準ロギングAPIの Level には7つのレベルが用意されています。
SEVERE が一番優先度が高く、FINESTが一番優先度が低くなります。

開発中は FINE までのログを出力させ、リリース版では INFO までのログを出力させる、という想定でいます。

レベル 日本語表記 簡単な説明 出力されたときの対応
SEVERE 重大 アプリケーションがクラッシュしたり、サービスが継続できなくなるような重要な問題が発生。 ただちに対応が必要。
WARNING 警告 想定内のエラーが発生。(復旧可能な問題など) 急ぎではないが、経過の観察が必要。
INFO 情報 正常なケースで出力する情報。(アプリバージョンなど) 対応なし。
CONFIG 構成 設定ファイルの内容など。 対応なし。
FINE 普通 不具合解析の手助けとなるような情報。 対応なし。
FINER 詳細 詳細な、不具合解析のための情報。(メソッドの開始点、終了点の出力など) 対応なし。
FINEST 最も詳細 さらに詳細な、不具合解析のための情報。 対応なし。

個人的には、CONFIGFINEST はあまり使っていません。
他のレベルで代用できたり、そこまで分ける必要性をあまり感じないためです。

もちろん、必要であれば CONFIGFINEST を使うのも全然ありです。
さらに、Level の優先度は単純な数値であるため、独自の Level を定義することもできます。

SEVERE(重大)

もっとも優先度が高く重要なログとなります。
SEVEREのログが出力されたら、ただちに対応が必要となるレベルです。

  • アプリケーションがクラッシュした
  • サービスが継続できないような問題が発生した

というときに使うのがよいかなと思います。

具体的には、非チェック例外である、

が発生したときに、SEVEREでログ出力することをおすすめします。

ログ出力メソッドには Throwable を指定できるものがあるので、それが便利です。
例外メッセージとスタックトレースも出力してくれます。

特にスタックトレースはとてもとても大事です。
どこで問題が発生したか一目でわかるため、問題解析の時間短縮につながります。

SEVEREのログは、アプリケーション開始用のメソッド(メインクラスのmainメソッド)の根元でキャッチして出力するのがよさそうです。

public class AppMain {

    public static void main(String[] args) {
        final var logger = Logger.getLogger("com.example.logging");
        logger.setUseParentHandlers(false);
        logger.addHandler(new ConsoleHandler());

        try {
            String s1 = null;

            // 意図的に NullPointerException を発生させます。
            final var s2 = s1.toUpperCase();

        } catch (RuntimeException | Error e) {
            logger.log(Level.SEVERE, "問題発生!", e);
        }
    }
}

// 結果
// ↓
//10月 11, 2021 9:01:43 午後 com.example.logging.AppMain main
//重大: 問題発生!
//java.lang.NullPointerException: Cannot invoke "String.toUpperCase()" because "<local2>" is null
//        at com.example.logging.AppMain.main(AppMain.java:18)
//        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
//        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
//        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
//        at java.base/java.lang.reflect.Method.invoke(Method.java:567)
//        at jdk.compiler/com.sun.tools.javac.launcher.Main.execute(Main.java:415)
//        at jdk.compiler/com.sun.tools.javac.launcher.Main.run(Main.java:192)
//        at jdk.compiler/com.sun.tools.javac.launcher.Main.main(Main.java:132)

WARNING(警告)

WARNINGは2番目に優先度が高いログとなります。
急いで対応する必要はないかもしれませんが、経過の観察は必要です。

  • 想定内の問題が発生した(復旧可能な問題など)
    • ネットワークが一時的につながらない
    • ファイルの書き込み失敗
    • などなど

というときに使うのがよいかと思います。

復旧可能とは、プログラムの修正なしで問題が解決できることをいいます。
例えば、LANケーブルが抜けかけていたので刺しなおした、ストレージ容量が足りなかったので不要なファイルを削除した、などなど。

具体的には、IOExceptionのようなチェック例外が発生したときに出力させます。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);
logger.addHandler(new ConsoleHandler());

try {
    final var path = Path.of("R:", "java-work", "sample.txt");

    // 意図的に例外を発生させます。
    Files.readString(path);

} catch (IOException e) {
    logger.log(Level.WARNING, "ファイル読み込み失敗", e);
}

// 結果
// ↓
//10月 11, 2021 8:28:16 午後 com.example.logging.LevelGuideline testWarning
//警告: ファイル読み込み失敗
//java.nio.file.NoSuchFileException: R:\java-work\sample.txt
//	at java.base/sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:85)
// ... 省略 ...

もちろん、これらの問題がより重要となるアプリやサービスでは、SEVERE にしてもよいと思います。

INFO(情報)

正常なケースで出力することを想定したログレベルです。

  • アプリケーションが開始した
  • アプリケーションが終了した
  • アプリケーションのバージョン

といった情報を出力させます。

とくにアプリケーションのバージョンは常に出力しておくことをおすすめします。
もしアプリバージョンがないと…

Aさん:不具合が発生したのでログ確認お願いします!
Bさん:了解しました。ふむふむ…あれ、この問題は直したはずだけど再発しちゃったのかな…念のため確認してみよう。

となって、余計な手間がかかるかもしれません。
ログにアプリバージョンがあれば、

Aさん:不具合が発生したのでログ確認お願いします!
Bさん:了解しました。ふむふむ…あれこの問題は修正済みのはず。ログのアプリバージョンも古いな。Aさん、使ってるアプリが古いみたいなので、最新のアプリで再確認お願いします!

と、問題の切り分けがスムーズになります。

アプリバージョン以外にも、環境に依存するような

のデフォルト情報も、INFO で出力しておいてよいかもしれませんね。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);
logger.addHandler(new ConsoleHandler());

logger.info("アプリ開始:version = 1.0.0");
logger.info("Locale : " + Locale.getDefault());
logger.info("Charset : " + Charset.defaultCharset());
logger.info("ZoneId : " + ZoneId.systemDefault());

// 結果
// ↓
//10月 11, 2021 8:31:31 午後 com.example.logging.LevelGuideline testInfo
//情報: アプリ開始:version = 1.0.0
//10月 11, 2021 8:31:31 午後 com.example.logging.LevelGuideline testInfo
//情報: Locale : ja_JP
//10月 11, 2021 8:31:31 午後 com.example.logging.LevelGuideline testInfo
//情報: Charset : UTF-8
//10月 11, 2021 8:31:31 午後 com.example.logging.LevelGuideline testInfo
//情報: ZoneId : Asia/Tokyo

CONFIG(構成)

個人的に、使い道にちょっと困るログレベルです。
名前から推測すると、設定ファイルの内容を出力させる、という感じでしょうか。

INFOFINE で代用するのでもよいかもしれません。

FINE(普通)

開発中は常に出力する想定のログレベルです。
主に、不具合が発生したときの問題解析に有用となる情報を出力させます。

例えば、ユーザが入力した文字列の違いによって問題が発生したり・しなかったりする場合は、

  • ユーザが入力した文字列

をログに出力します。
そうすれば、どのような文字列で問題が発生するのか?が分かることになります。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);
logger.setLevel(Level.ALL);

final var handler = new ConsoleHandler();
handler.setLevel(Level.ALL);
logger.addHandler(handler);

// 例えばユーザが入力した文字列など。
final var userInput = "abcdef";

logger.fine("ユーザ入力 : " + userInput);

// 結果
// ↓
//10月 11, 2021 8:39:50 午後 com.example.logging.LevelGuideline testFine
//普通: ユーザ入力 : abcdef

FINE はリリース版では出力しないことを前提としているため、あまり神経質にならずに手軽に出力させることができるのがよいですね。

ただし、そこまで高頻度で出力はさせないようにしましょう。
あまりに高頻度だと、必要とするログが大量のログに埋もれてしまい、デバッグの効率が悪くなります。

もし高頻度に出力したい情報であれば、より優先度の低い FINERFINEST を使いましょう。

FINER(詳細)

FINERは、2番目に優先度が低いレベルです。
FINEより高頻度で出力したいケースで使います。

実は、FINERを使ったログ出力用のメソッドがあります。

それは Logger.entering と Logger.exiting​ です。
メソッドの開始点と終了点をログとして出力するためのAPIです。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);
logger.setLevel(Level.ALL);

final var handler = new ConsoleHandler();
handler.setLevel(Level.ALL);
logger.addHandler(handler);

class EntryTest {
    public void func() {
        try {
            logger.entering("EntryTest", "func");

            ...なにかいろいろ処理...

        } finally {
            logger.exiting("EntryTest", "func");
        }
    }
}

new EntryTest().func();

// 結果
// ↓
//10月 09, 2021 2:40:37 午後 EntryTest func
//詳細: ENTRY
//10月 09, 2021 2:40:37 午後 EntryTest func
//詳細: RETURN

enteringexiting メソッドにはログレベルを指定していませんが、ログ出力は"詳細"(=FINER)となります。
確かに、多くのメソッドで開始・終了点を FINE で出力すると邪魔になりそうですね…

普段の開発中は FINE までのログを出力。
難解な不具合をじっくり解析するときには FINER まで出力…という感じがよいのかなと思います。

FINEST(最も詳細)

最も優先度が低いレベルです。
FINER よりさらに高頻度、もしくは巨大なメッセージのログを出力させる場合に使います。

とはいえ、個人的にはあまり使っていません…

まとめ

ログレベルの指針 (使い分け)、いかがでしたでしょうか。
一番大事なのはチーム全体指針を統一することです。

もし本記事が、あなたのチームのログレベルの指針の参考になったのなら幸いです。


関連記事

ページの先頭へ