java.util.loggingの闇

Javaの1.4からjava.util.logging(以下JULと表記)というロギングパッケージが標準で使えるようになって、ログ出力のためにlog4jなどのサードパーティライブラリをいちいち導入したりする必要がなくなりみんな幸せになりました。

と言いたいところですこいつが超不便なAPIをしていてとてもとてもとっっっても使い辛い。ふざけんな。

まずさらっと使ってみましょう。Java 7です。

Logger.getGlobal().info("log")
Logger.getLogger("foo").info("log")

出力はこうなります。

Jan 15, 2015 5:11:41 PM JUL main
INFO: log
Jan 15, 2015 5:11:41 PM JUL main
INFO: log

はい、キモイですね。軽くつっこむと

なんで2行なんだよ
日時AM/PM表記かよ、ミリ秒なしかよ
ロガー名どこだよ

JULの酷さ談義で一晩酒が飲めそうですが、JULの特徴を簡潔にまとめます。

ログ出力設定ファイルはシステムプロパティで指定 -Djava.util.logging.config.file=logging.properties
- 引数はURLは受け付けずファイルパスのみ
- 間違ってると一切ログ出さない
デフォルトフォーマッタはjava.util.logging.SimpleFormatter
- ミリ秒やロガー名を出さないなど出力項目少ない
- なぜか2行に分けてログ出力する
- しかもsynchronizedされててマルチスレッドでログフォーマットできないため超遅い
- Java標準に含まれる他のフォーマッタはXMLFormatterしかない
- 継承してカスタマイズできるように作成されていない
- Java 7から出力フォーマットは変更できる
- 本番で使うつもりならFormatter自作必須
ログメッセージのフォーマットは {0}, {1} のようなjava.text.MessageFormat形式
logメソッドで可変長引数の関連でパラメータとExceptionを同時に受け取れないのでLogRecordを使う必要があり、シンプルなログ出力に数行を要する
ログレベル名微妙にダサイ感 (ERRORではなくSEVERE。シビアのスペルを覚える機会なんて滅多になさそう)

ログ設定ファイルはこんな感じ。最後の一行の呪文があるとフォーマットは多少マシになります。フォーマットだけは。

handlers=java.util.logging.ConsoleHandler
.level=INFO
java.util.logging.ConsoleHandler.level=INFO
java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter
java.util.logging.SimpleFormatter.format=%1$tY-%1$tm-%1$td %1$tH:%1$tM:%1$tS.%1$tL %4$s [%3$s] %5$s (%2$s) %6$s%n

handlersと.levelの書き方が異なるのが気になると思いますが、これは読み込まれ方が異なります。前者はトップレベルの設定、後者はロガー名が先頭につく形式ですが、ルートなので空文字でこのような表記になっています。

例外とメッセージパラメータの両方がある場合は以下のようにLogRecordを使って4行も書かなければいけません。これはJava メソッドシグネチャの制約によるもので、可変長引数が出現するとその後には引数を宣言できないため、最終引数となるThrowableの行き場がなくなった、という理由からです。さらにトドメで、LogRecordのパラメータは可変長引数に対応してません。

Logger logger = Logger.getLogger("foo");
String message = "{0} failed";
Exception ex = new Exception();

LogRecord lc = new LogRecord(SEVERE, message);
lc.setParameters(new String[]{"JUL"});
lc.setThrown(ex);
logger.log(lc);

ちなみにSLF4Jでは可変長引数の最終引数が例外であれば特別視して例外として別に扱う、というそれはそれでキモいAPIになっています。でも便利です。

LogRecordは冗長なので、Loggerに渡す前にString.format()でメッセージを組み立てるという方法をよく使います。String.format()はsprintfフォーマットなので、Loggerのjava.text.MessageFormatとは形式が異なります。こちらのほうが一般的に好まれるフォーマットでしょう。

String message = String.format("%s sucks", "JUL");
logger.log(SEVERE, message, new Exception());

依存なしでログ出したいという局面はそこそこあるんですが、JULのAPIがこんな感じなのでいつもがっかりしながら使っているのでした。

依存が許容される場合はJBoss Logging + JBoss LogManagerか、SLF4J + Logbackのどちらかの組み合わせを使えばいいと思います。

nekop's blog

OpenShift / JBoss / WildFly / Infinispanの中の人 http://twitter.com/nekop

java.util.loggingの闇