java.util.logging.Loggerのログレベルについて


java.util.logging.Loggerとは

Javaの標準API。エラー情報を内容に応じてログ出力する。

使用方法

まずは基本的な使い方です。主な登場実物は以下の3つです。
1. Logger - ログを出力するオブジェクト。
2. Handler - ログの出力先を制御するオブジェクト。
3. Formatter - ログのフォーマットを制御するオブジェクト。

初めにLoggerインスタンスを作成します。

Logger logger = Logger.getLogger("loggerの名前")

次にHandlerインスタンスを作成し、loggerに登録します。Handlerは複数個登録できます。
今回はC:\sample\sample.logを出力先としたHandlerを作成します。ファイルを出力先とする場合はHandlerインターフェースの実装クラスFileHandlerを利用します。

Handler handler = new FileHandler("C:\\sample\\sample.log");
logger.addHandler(handler);

最後にFormatterインスタンスを作成し、Handlerに登録します。
今回は人が読みやすい形にフォーマットするため、SimpleFormatterを利用します。SimpleFormatterはFormatterインターフェースの実装クラスです。

Formatter formatter =  new SimpleFormatter();
handler.setFormatter(formatter);

これで準備は完了です。loggerにメッセージを渡してログを出力します。

ログレベル

ログを出力する際にログレベルを指定します。
以下の要求レベルを設定することができます。

Loggerメソッド 対応する要求レベル 出力される名称
-- Level.ALL --
Logger.finest() Level.FINEST 最も詳細
Logger.finer() Level.FINER 詳細
Logger.fine() Level.FINE 普通
Logger.config() Level.CONFIG 構成
Logger.info() Level.INFO 情報
Logger.warning() Level.WARNING 警告
Logger.severe() Level.SEVERE 重大

例えば、Level.CONFIGを設定するとログとして出力されるのは、「構成」「情報」「警告」「重大」という風に、設定レベル以下が表示されます。
Level.ALLはその名の通り、全てを表示させます。

実装による確認

以下の実装により実際のログ出力を確認します。

Log
public class Log {

    public static Logger getLog(String name) {
        // loggerの生成
        Logger logger = Logger.getLogger(name);

        try {
            // ハンドラーの生成(true:書き込み,false:上書き)
            Handler handler = new FileHandler("/log/sample.log", false);
            // SimpleFormatよるlogフォーマットの指定
            handler.setFormatter(new SimpleFormatter());
            // ログレベルの指定/ハンドラーの設定
            logger.addHandler(handler);
            logger.setLevel(Level.ALL);

            // 標準出力の設定
            ConsoleHandler consoleHandler = new ConsoleHandler();
            consoleHandler.setLevel(Level.CONFIG);
            logger.addHandler(consoleHandler);

            // 親ロガーの設定(true:親ロガーへ送信,false:親ロガーへ送信しない)
            logger.setUseParentHandlers(false);
            // ログ出力
            logger.finest("FNST");
            logger.finer("FNR");
            logger.fine("FN");
            logger.config("CFG");
            logger.info("INF");
            logger.warning("WNG");
            logger.severe("SVR");

            throw new IOException();

        }  catch (FileNotFoundException e) {
            e.printStackTrace();
        } catch (SecurityException e) {
            e.printStackTrace();
        } catch (IOException e) {
            e.printStackTrace();
            logger.log(Level.CONFIG, "エラー発生", e);
            logger.warning("WNG:エラー発生");
        }
        return logger;
    }
}

このクラスはjava.util.logging.Loggerをラップしたクラスになります
クラス名を引数にgetLog()メソッドを呼び出すことによりログの挙動を確認します

1.getLogger()を使用してloggerを生成し、ログレベルの設定

java.util.logging.Logger のgetLoggerメソッドを利用しloggerを生成
setLevelメソッドでログレベルを指定する

2.ファイルで出力する設定(FileHandler)

ログファイルの場所、フォーマット、ログレベルを設定する。
FileHandlerを利用し、第一引数:ファイルパス第二引数:上書き・追記の設定をする
trueが上書き、falseが追記になる。今回は一度実行した場合の挙動を見たいためtrueにする
生成したhandlerにログフォーマットの設定をする
標準ではXML型式にてログが出力されるが、見づらいためSimpleFormatter()で日本語にて出力するように設定する
handlerにログレベルを設定して、loggerに一定のログレベル以上のメッセージのみ出力するように設定することが出来ます。
今回はALLを設定することにより全てのログ出力をファイルに記載します

3.標準出力を設定(ConsoleHandler)

ConsoleHandlerを設定することでログの内容がコンソール上でも確認できるようになる。
設定方法はFileHandler同様にaddHandler() メソッドを使用することでできる
標準出力もログレベルを設定し、CONFIG以上のログが出力されるようにします

4.親ロガーの設定

falseにしてますがtrueにすると、要求レベル未満の標準出力が二重に表示されたりレベルが合わなかったりする様です。
二重に表示されるのは、作成したログは親ロガーに送信されるので、親ロガーに登録されたログが出力されるのでしょう。

5.ログの設定

ログ確認のため各ログレベルの出力をしています。

6.エラー発生時のログ確認

IOExceptionを発生させ、最後のエラー発生時のログにつなげています。

maiinクラスを作成し、呼び出すことで挙動を確認します。

実行結果

Sample.log
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
最も詳細: FNST
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
詳細: FNR
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
普通: FN
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
構成: CFG
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
情報: INF
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
警告: WNG
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
重大: SVR
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
構成: エラー発生
java.io.IOException
    at app.abstractDemo.log.Log.getLog(Log.java:43)
    at app.abstractDemo.MainActivity.main(MainActivity.java:10)

9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
警告: WNG:エラー発生

SimpleFormatter()のおかげで、ログがXML型式ではなく日本語にて出力されるように修正されていることが確認できました。
loggerのログレベルをALLにしていることからすべてのlogが出力されていること

標準出力
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
構成: CFG
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
情報: INF
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
警告: WNG
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
重大: SVR
java.io.IOException
    at app.abstractDemo.log.Log.getLog(Log.java:43)
    at app.abstractDemo.MainActivity.main(MainActivity.java:10)
9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
構成: エラー発生
java.io.IOException
    at app.abstractDemo.log.Log.getLog(Log.java:43)
    at app.abstractDemo.MainActivity.main(MainActivity.java:10)

9 21, 2020 2:18:27 午前 app.abstractDemo.log.Log getLog
警告: WNG:エラー発生

consoleHandlerのログレベルをCONFIGで設定してることからCONFIG以上のログが出力されていることが確認できました

フィルター

ロガーにログレベルを設定して一定のログレベル以上のメッセージのみを出力するように制御する方法を紹介しましたが、より詳細な制御を行いたい場合はFilterクラスを利用します。

Filter filter = new Filter() {
    @Override
    public boolean isLoggable(LogRecord record) {
        return record.getMessage().contains("処理件数=");
    }
};
logger.setFilter(filter);

上記のようにFilterを設定した場合、メッセージに"処理件数="を含むログのみが出力されるようになります。
実装に下記レコードを追加して処理を確認します

Log
            // ロガーにフィルターを設定
            Filter filter1 = new Filter() {
                @Override
                public boolean isLoggable(LogRecord record) {
                    return record.getMessage().contains("処理件数=");
                }
            };
            logger.setFilter(filter1);
            logger.info("サンプルメッセージ");                          // 出力されない
            logger.info("サンプルメッセージ, 処理件数=1");               // 出力される

            // ハンドラーにフィルターを設定
            Filter filter2 = (record) -> record.getMessage().contains("更新件数=");
            handler.setFilter(filter2);
            logger.info("サンプルメッセージ");                          // 出力されない
            logger.info("サンプルメッセージ, 処理件数=1");               // 出力されない
            logger.info("サンプルメッセージ, 処理件数=1, 更新件数=1");    // 出力される

            // ハンドラーにログレベルを設定
            handler.setLevel(Level.WARNING);
            logger.info("サンプルメッセージ");                          // 出力されない
            logger.info("サンプルメッセージ, 処理件数=1");               // 出力されない
            logger.info("サンプルメッセージ, 処理件数=1, 更新件数=1");    // 出力されない
            logger.warning("警告メッセージ, 処理件数=1, 更新件数=1");   // 出力される

フィルターとログレベルによりコメントで出力されると書かれたログのみ出力される想定です。

実行結果

sample.log
9 21, 2020 12:14:03 午後 app.abstractDemo.log.Log getLog
情報: サンプルメッセージ, 処理件数=1
9 21, 2020 12:14:03 午後 app.abstractDemo.log.Log getLog
情報: サンプルメッセージ, 処理件数=1, 更新件数=1
9 21, 2020 12:14:03 午後 app.abstractDemo.log.Log getLog
警告: 警告メッセージ, 処理件数=1, 更新件数=1

想定どおり3つのログが出力されています。

標準出力
9 21, 2020 12:14:03 午後 app.abstractDemo.log.Log getLog
情報: サンプルメッセージ, 処理件数=1
9 21, 2020 12:14:03 午後 app.abstractDemo.log.Log getLog
情報: サンプルメッセージ, 処理件数=1
9 21, 2020 12:14:03 午後 app.abstractDemo.log.Log getLog
情報: サンプルメッセージ, 処理件数=1, 更新件数=1
9 21, 2020 12:14:03 午後 app.abstractDemo.log.Log getLog
情報: サンプルメッセージ, 処理件数=1
9 21, 2020 12:14:03 午後 app.abstractDemo.log.Log getLog
情報: サンプルメッセージ, 処理件数=1, 更新件数=1
9 21, 2020 12:14:03 午後 app.abstractDemo.log.Log getLog
警告: 警告メッセージ, 処理件数=1, 更新件数=1

consoleHandlerにフィルターを設定してないため、loggerに設定したフィルターの設定のみ適用される。
よって、fillter1に設定した「処理件数=」とconsoleHandlerに設定したログレベル「CONFIG」が適用され出力がされていること

Log出力の制御

ロガーへ設定したログレベル・フィルターのチェックは、直接呼び出されたロガーでのみ行われる。
ハンドラーへ設定したログレベル・フィルターのチェックは、親ロガーのハンドラーも含めて全てのハンドラーでチェックされる。
ログ出力のロジックはざっくり言うと以下の図のようになっています。

ロガーへ設定したログレベル・フィルターのチェックは呼び出しを受けた最初のロガーでのみチェックされるのに対して、
ハンドラーへ設定したログレベル・フィルターのチェックは全てのハンドラーで行われています。

ロガーの設定は呼び出し時のみ行われるため親ロガーには伝播されず、ログの出しわけが想定どおりに行かないことがありあます。
例えば親ロガー:WARNING、子ロガー:FINE
ハンドラー:ALL

で設定した場合親ロガーではWARNINGでログレベルを設定しているにもかかわらず、FINEで設定しているログが出力されます。
これはハンドラーの設定が引き継がれチェックされていることから親ロガーの設定がされていないように見えてしまうのです。
以下の設定に変更することより設定を適用できます。
親ロガー・子ロガー:ALL
ハンドラー:WRANING

プロパティファイルの読み込み

ソース上にログの設定を記述していくと煩雑になり読み辛くなってしまいます。

設定ファイルをプログラムから読み込む方法は以下の通りです。今回はサンプルプログラムの同じクラスパスに配置しているlogging.propertiesを読み込むようにしました。
設定ファイルはjava.util.Properties形式で読み込む必要があります。

LogManager.getLogManager().readConfiguration(SettingFileSample.class.getResourceAsStream("logging.properties"));

設定ファイルのサンプルは以下の通りです。詳しい説明は{java.home}\lib\logging.propertiesにも記載されていますのでご参照ください。

logging.properties
# ルートロガーのハンドラー・ログレベルの設定 ConsoleHandlerは標準エラー(System.err)へログを出力します。
handlers=java.util.logging.ConsoleHandler
.level=INFO

# サンプルプログラムで利用するロガー"sample.SettingFileSample"の設定
sample.SettingFileSample.level=FINE
sample.SettingFileSample.handlers=java.util.logging.FileHandler

# ConsoleHandlerの設定
java.util.logging.ConsoleHandler.level=INFO
java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter

# FileHandlerの設定
java.util.logging.FileHandler.pattern=C:/sample/sample.log
java.util.logging.FileHandler.limit=1000
java.util.logging.FileHandler.count=1
java.util.logging.FileHandler.formatter=java.util.logging.SimpleFormatter

上記の設定ファイルを利用したサンプルプログラムを以下に記載します。

SettingFileSample
public class SettingFileSample {

    public static void main(String[] arg) throws SecurityException, IOException {
        LogManager.getLogManager().readConfiguration(SettingFileSample.class.getResourceAsStream("logging.properties"));

        Logger logger = Logger.getLogger("sample.SettingFileSample");
        logger.finer("FINERメッセージ");
        logger.fine("FINEメッセージ");
        logger.info("INFOメッセージ");
    }
}

ロガーやハンドラーの設定がなくなってすっきりしましたね。

参考記事

java.util.loggingの使い方