Java のロギング API ちょっと不思議

以前から Java のロギング API、java.util.logging で不思議に思ってた挙動。

確認

普通に使う分にはこんな感じにします（コードは Groovy）：

import java.util.logging.*

def log = Logger.getLogger('logging')

log.warning('warning')
log.info('info')
log.config('config')
log.fine('fine')
log.finer('finer')
log.finest('finest')

これを実行すると、標準出力に

9 13, 2011 5:38:35 午前 java_util_logging_Logger$warning call
警告: warning
9 13, 2011 5:38:37 午前 java_util_logging_Logger$info call
情報: info

のように出力されます（ロギング API の簡単な使い方はこちら参照）。

ログレベルを設定して実行

で、他のレベルのログも出力したい場合に

import java.util.logging.*

def log = Logger.getLogger('logging')

log.level = Level.FINER    // ログレベルの設定

log.warning('warning')
log.info('info')
log.config('config')
log.fine('fine')
log.finer('finer')
log.finest('finest')

のようにログレベルを設定して実行しても出力が変更されず、「config」以下のログが標準出力に表示されません。　どうもこれは、デフォルトで設定されているハンドラが、（setLevel() によって設定されている）ログレベルとは関係なくログを出力してるのが原因のようです。　ハッキリ言って、この実装の意味が全く理解できないんですけど・・・

設定されているログレベルに準じた出力に

少々手間がかかりますが、設定されたログレベルに準じたログ出力を行わせることももちろんできます。　まず、準備として以下のように Handler 実装クラスを作成します：

import java.util.logging.Handler
import java.util.logging.LogRecord

class MyHandler extends Handler{

    @Override
    void publish(LogRecord record) {
        System.err.println "${new Date(record.millis)} $record.sourceClassName call"
        System.err.println "$record.level: $record.message"
    }

    @Override
    void flush() {}

    @Override
    void close() {}
}

ここでの publish() メソッドが、出力するログの形式を決めます。　パラメータの LogRecord オブジェクトはアクセス可能なログ情報を保持したオブジェクトです。　どのような情報が取得できるのかは API ドキュメントを参照してください。

このクラスが用意できたら、以下のようにログを設定して使用します：

import java.util.logging.Level
import java.util.logging.Logger

def log = Logger.getLogger('logging')

log.level = Level.FINER    // ログレベルの設定
log.useParentHandlers = false
log.addHandler(new MyHandler())    // 作成した Handler を設定

log.warning('warning')
log.info('info')
log.config('config')
log.fine('fine')
log.finer('finer')
log.finest('finest')

出力は

Tue Sep 13 05:54:41 JST 2011 java_util_logging_Logger$warning call
WARNING: warning
Tue Sep 13 05:54:41 JST 2011 java_util_logging_Logger$info call
INFO: info
Tue Sep 13 05:54:41 JST 2011 java_util_logging_Logger$config call
CONFIG: config
Tue Sep 13 05:54:41 JST 2011 java_util_logging_Logger$fine call
FINE: fine
Tue Sep 13 05:54:41 JST 2011 java_util_logging_Logger$finer call
FINER: finer