やっとわかった、java.util.logging

こんばんは。先日ブログの設定をいじっていたら、全てのページ(管理画面も!)でPHPエラーが表示されてかなり気落ちしました。PHPを書くのは久しぶりだったので、どこか書き間違えたんでしょう・・・。

さて、今日はロギングの話をします。

ロギングと言えばlog4jですが、JavaSEにもロギングを扱うための標準APIがあります(1.4から)。それがjava.util.loggingです。標準APIであるにも関わらず、なぜか情報が少ないんですね。簡単なプログラムを書こうとして、ついでだから標準API使ってみるか、と思い立つも、結局設定の仕方がわからずにlog4jに戻ったことが何度かありました。

まず使ってみる

まずは一番簡単な使い方から。

Logger logger = Logger.getLogger(Logger.GLOBAL_LOGGER_NAME);
logger.info("Loggerテストです。info");
logger.severe("Loggerテストです。severe");

これだけです。このコードを実行すると、私のマシンでは以下の出力が得られます。

2011/11/05 23:34:29 Sample1 main
情報: Loggerテストです。info
2011/11/05 23:34:29 Sample1 main
致命的: Loggerテストです。severe

簡単ですね。

標準出力に出力する

実際実行してみるとわかる通り、先ほどのコードでは、ログはエラー出力に出力されます。標準出力に出力するには、ハンドラを定義します。

Logger logger = Logger.getLogger(Logger.GLOBAL_LOGGER_NAME);
logger.addHandler(new StreamHandler(){
    { setOutputStream(System.out); }
});
logger.setUseParentHandlers(false);

logger.info("Loggerテスト2です。");

parentHandlerについては後で説明することにして、このコードを実行すると以下の出力が(標準出力に)得られます。

2011/11/05 23:47:55 Sample2 main
情報: Loggerテスト2です。

ログレベルの変更

では更に出力されるログのレベルを変更してみましょう。「どうせsetLogLevel()だろう?」ほぼ正解です! 以下、コードとその実行結果です。

Logger logger = Logger.getLogger(Logger.GLOBAL_LOGGER_NAME);
logger.addHandler(new StreamHandler(){
  {
    setOutputStream(System.out);
    setLevel(Level.ALL);
  }
});
logger.setUseParentHandlers(false);
logger.setLevel(Level.ALL);

logger.fine("Loggerテスト3です。fine");
logger.info("Loggerテスト3です。info");
logger.severe("Loggerテスト3です。severe");
2011/11/06 0:10:22 Sample3 main
詳細レベル (低): Loggerテスト3です。fine
2011/11/06 0:10:22 Sample3 main
情報: Loggerテスト3です。info
2011/11/06 0:10:22 Sample3 main
致命的: Loggerテスト3です。severe

loggerとhandler、両方にレベルを設定していることに注意してください。

設定ファイルを使用する

loggerインスタンスを作成する度にコード内で設定を書くのはいかにも面倒です。log4jのように設定ファイルを使って設定したいものです。

まずは、先ほど横着してインナークラスにしていた”標準出力へログ出力するハンドラ”を通常のクラスとして定義しておきます。

sample.StdConsoleHandler

package sample;
import java.util.logging.StreamHandler;

public class StdConsoleHandler extends StreamHandler {
  {
    setOutputStream(System.out);
  }
}

次にログ設定ファイルを作成します。

customLogging.properties

handlers= sample.StdConsoleHandler
.level= ALL
sample.StdConsoleHandler.level = ALL

最後にログ出力するためのコードです。

try {
  LogManager.getLogManager().readConfiguration(
        Sample4.class.getResourceAsStream("customLogging.properties"));
} catch (SecurityException e) {
  e.printStackTrace();
} catch (IOException e) {
  e.printStackTrace();
}

Logger logger = Logger.getLogger(Logger.GLOBAL_LOGGER_NAME);

logger.fine("Loggerテスト4です。fine");
logger.info("Loggerテスト4です。info");
logger.severe("Loggerテスト4です。severe");

ログ設定ファイルと実行コードを同じディレクトリに置いて実行してください。すると以下の出力が得られます。

2011/11/06 0:47:32 Sample4 main
詳細レベル (低): Loggerテスト4です。fine
2011/11/06 0:47:32 Sample4 main
情報: Loggerテスト4です。info
2011/11/06 0:47:32 Sample4 main
致命的: Loggerテスト4です。severe

ロガーツリー

getLogger()をコールするときにロガーの名前を指定します。ここまでは簡易的に汎用ロガーを使用してきましたが、実際の開発では幾つものモジュールを開発するので、モジュール毎にログ設定をしたいことも多いでしょう。

ロガーを使い分けるには、以下のようなコードにします。ロガーを3つ使ってみました。

try {
  LogManager.getLogManager().readConfiguration(
        Sample5.class.getResourceAsStream("customLogging.properties"));
} catch (SecurityException e) {
  e.printStackTrace();
} catch (IOException e) {
  e.printStackTrace();
}

Logger loggerX = Logger.getLogger("xxx");
Logger loggerY = Logger.getLogger("xxx.yyy");
Logger loggerZ = Logger.getLogger("xxx.zzz");

loggerX.fine("LoggerXテスト5です。fine");
loggerX.info("LoggerXテスト5です。info");
loggerY.fine("LoggerYテスト5です。fine");
loggerY.info("LoggerYテスト5です。info");
loggerZ.fine("LoggerZテスト5です。fine");
loggerZ.info("LoggerZテスト5です。info");

それから、先ほどのログ設定ファイルを以下のように書き換えましょう。

# custom handler
sample.StdConsoleHandler.level = ALL

# custom logger
xxx.handlers = sample.StdConsoleHandler
xxx.level = INFO
xxx.useParentHandlers = false

xxx.zzz.level = ALL

コードを実行すると、以下の出力が得られます。

2011/11/06 1:32:15 Sample5 main
情報: LoggerXテスト5です。info
2011/11/06 1:32:15 Sample5 main
情報: LoggerYテスト5です。info
2011/11/06 1:32:15 Sample5 main
詳細レベル (低): LoggerZテスト5です。fine
2011/11/06 1:32:15 Sample5 main
情報: LoggerZテスト5です。info

お気づきでしょうか? loggerZではfineのログまで出力されていますが、loggerX、loggerYではinfoまでしか出力されていません。

これがロガーツリーです。Logger.getLogger(“xxx”)で取得したロガーは、Logger.getLogger(“xxx.yyy”)・Logger.getLogger(“xxx.zzz”)で取得したロガーの親ロガーになります。

ここにはポイントが2つあります。

  • ログレベルを設定していないロガーのログレベルは、親ロガーのログレベルと同じになる。
  • ロガーはデフォルトで、自身のハンドラと親ロガーのハンドラへログメッセージを発行する。

デフォルトのログ設定ファイルとルートロガー

実はJREにはデフォルトのログ設定ファイルがあります。通常$JAVA_HOME/lib/logging.propertiesにありますので開いてみてください。”.level”・”handlers”・”ConsoleHandler”・”FileHandler”などの設定がされているのがわかると思います。

先ほど、”xxx”のロガーは”xxx.yyy”のロガーの親ロガーになると言いましたが、実際にはさらに全ての(明示的な親ロガーを持たない)ロガーの親としてルートロガーなるものが存在しています。そしてルートロガーのログレベルは設定ファイルの”.level”、ハンドラは設定ファイルの”handlers”で決定されます。

getLogger(Logger.GLOBAL_LOGGER_NAME)で取得できるロガーの親ロガーもルートロガーです。最初の例でエラー出力に出力されたのはルートロガーのハンドラがConsoleHandlerだったからなんですね。ただConsoleHandlerがなぜエラー出力を使う仕様になっているのかは謎です(笑)。少し不便ですよね。

また、2番目以降の例でsetUseParentHandlers(false)を使用しているのは、ルートロガーのハンドラ(ConsoleHandler)へログメッセージを発行しないようにするためでした。

標準ロギングAPI java.util.logging

ここまでjava.util.loggingを見てきましたが、いかがでしょうか。log4jなどに慣れていると戸惑う部分もありますが、標準でついている機能を「わからないから使わない」のではもったいないと思います。違いを理解した上で使い分けたいものですね。

コメントを残す