このページでは、大体 使い方（1,2)でやったのに準じて、Logback の使い方を解説する。
目次まあ、抽象論よりも、具体的なコードを見ようじゃないか。サンプルコードはこんなものだ。
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Test {
protected static Logger log = LoggerFactory.getLogger( TestLogback.class );
public static void main( String [] args ) {
new SimpleTest();
}
SimpleTest( ) {
try {
BufferedReader br = new BufferedReader( new InputStreamReader( System.in ) );
while( true ) {
String line = br.readLine();
if( line == null ) {
break;
}
int at = line.indexOf( "," );
if( at == -1 ) {
break;
}
String cat = line.substring( 0, at );
String body = line.substring( at + 1 );
if( cat.equals( "error" ) ) {
log.error( body );
} else if( cat.equals( "warn" ) ) {
log.warn( body );
} else if( cat.equals( "info" ) ) {
log.info( body );
} else if( cat.equals( "debug" ) ) {
log.debug( body );
} else if( cat.equals( "trace" ) ) {
log.trace( body );
} else if( cat.equals( "quit" ) ) {
break;
}
}
} catch( IOException e ) {
e.printStackTrace();
}
}
}
これだと、コードを見てお分かりのように、標準入力から、
info,Hello my Log4J world! warn,This is WARNING!!!
というような入力をいれてやると、
2004-09-10 17:13:09,754 INFO SimpleTest - Hello my Log4J world! 2004-09-10 17:13:33,261 WARN SimpleTest - This is WARNING!!!
というようなログ出力が出る、という寸法だ。error(), warn(), info(), debug() と言った Logger クラスのメソッドは、言うまでもなく「ログレベル」（ログの重要度）である。この順でキッツイ方から並べてある。
Log4j と比較すると、fatal がなくなって、Log4j では最近登場したばかりの trace がちゃんと最初から入っている。ここで注意すべきは、Log4j の場合、org.apache.log4j.Logger のLog4j 内のクラスで、ロガーを得て使っていたのだが、Logback の場合、slf4j という commons-logging 相当のパッケージ経由で使うのが、普通のやり方になってる。だから、
import org.slf4j.Logger; import org.slf4j.LoggerFactory;
がロガーを使う側のクラスでの import 宣言になって、基本的に logback 自体のパッケージである ch.qos.logback.* は出てこない...ということになる。こうやって守備範囲を明確に分けているのは良い点と言えると思う。だから、本質的にログ取りメソッド以外何もない commons-logging と違い、MDC（NDCは廃止して MDC に統合した雰囲気）が slf4j の担当になっている。あと、新概念として、Marker というものがやはり slf4j に新設されているが、どっちか言えばこれ application プロパティみたいなかたちで使うもののようである。
で、ログ取りメソッドが異常に強化されている。基本的にこういうかたちでログ取りメソッドを呼び出す。
public boolean isInfoEnabled(); public boolean isInfoEnabled(Marker marker); public void info(String msg); public void info(String format, Object arg); public void info(String format, Object arg1, Object arg2); public void info(String format, Object[] argArray); public void info(String msg, Throwable t); public void info(Marker marker, String msg); public void info(Marker marker, String format, Object arg); public void info(Marker marker, String format, Object arg1, Object arg2); public void info(Marker marker, String format, Object[] argArray); public void info(Marker marker, String msg, Throwable t);
やたらと増えたが、これ要するに、
の２つのフィーチャーに整理できる。まず、フォーマット展開は、こんな感じですればいい。
String name = "安倍";
Integer score = new Integer(30);
String result = "赤点";
Object [] arg = { name, score, result };
logger.info( "{} くんの成績は {} 点で{}でした", arg );
単に 「{}」を引数に展開するだけである。Java5 で可変長引数定義が加わって、ここらへん何も考えなくてできるわけだ。あ、一つだけ超重要なポイントがある。
Logback は、JDKのバージョンに応じて、パッケージがある...
実際、デフォルトのパッケージは、汎用ライブラリとしては珍しいが、ほんと内部的には Generics とか使い倒しで書いてあるので、Java 4 以前ではまともに動くものではない。だから、logback-*.jar は Java5 以降専用、logback-*-jdk14.jar は Java 1.4 用というかたちになっている。使うにあたっては、これだけ気をつけてね。
で、Marker だが、これ要するに、MDCでカバーしきれない「メタな情報」を渡したい時に、これを使うのがいい。だから、SocketAppender などで対応しかけている Application プロパティは、slf4j+logback だったらこの Marker で対応した方がいいだろう。つまり、割とグローバルにアプリ上で使うような識別情報（アプリ名とかサブパッケージとか）を、この Marker のかたちで管理できる。たとえば、こんな感じだ。
package jp.or.nurs.sug.logback.test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.Marker;
import org.slf4j.MarkerFactory;
import org.slf4j.MDC;
public class TestSlf4j {
protected static Logger log = LoggerFactory.getLogger( TestLogback.class );
protected static Marker marker = MarkerFactory.getMarker( "test" );
public static void main( String [] args ) {
log.info( "ENTER: TestSlf4j" );
if( args.length > 0 ) {
MDC.put( "arg1", args[0] );
}
String name = "安倍";
Integer score = new Integer(30);
String result = "赤点";
Object [] arg = { name, score, result };
log.info( marker, "{}くんの成績は{}点で{}です", arg );
MDC.remove( "arg1" );
log.info( "EXIT: TestSlf4j" );
}
}
まあ、こういう風に、アプリ側で出てきそうなインターフェイスは、Logback の側じゃなくて、全部抽象層の Slf4j にさせちゃっているわけである。それゆえ、Logback を使う...と言っても、アプリ側では Logback 固有のクラスをまったく使わない（これが狙い）ので、後から他のロガーに差し替えるとか、簡単なのである。このこと自体は commons-logging が狙ってたことだが、Log4j の多機能に馴れちゃうと、ついつい Log4j 依存の NDC とか使いたくなっちゃうが、NDC は commons-logging の知ったことじゃない。そういうわけで、
Log4j の刺激によって進化した commons-logging（logback対応）
くらいのノリでこれを理解するのがいいだろう。
しかし、今のサンプル、適当なlogback設定ファイル(logback.xml)を使ってやると、単にクラスパスに、
を含めただけで、きっちりログを出してくれちゃうんである。....あれ、何か間違ってません？
となるのは、「slf4j-api-1.4.3.jar は抽象的なAPI記述に過ぎないのに、何で logback が使えることが、slf4j API に分かるんだろう？？？」という謎があるからだ。commons-logging だったら、commons-logging.properties ファイルがあって、そこからログ実装クラスを探す...というような仕様が、「どこから実装クラスを探すのか？」と絡んでいろいろややこしく存在している。が....どこをどう見ても、そういう「優先順位」っぽいコードがないのだ。困ったなぁ....（というのは白々しい）
実はこれ、かなり原始的だがラジカルなやり方で解決しているんである。要するに、ここらへんのロガー実装になるのは、slf4j API の中で、
の３クラスであり、slf4j-api-1.4.3.jar のソースではこれら３クラスがあって、コンパイルができるのだが、jar で固める際に、この３つの impl クラスは積極的に排除して slf4j-api-1.4.3.jar を作っている。だから、この Jar は中途半端で自己完結していない Jar ファイルのわけである。だから、ホントにこれを実装したクラスが、クラスパスの通った Jarファイル（でなくてもいいが）の中になければならない。
で要するにLogback を使う場合だと、logback-classic-0.9.8.jar の中にこの impl ３クラスがあって、これに解決されるわけである。だから、ロガー実装を切替えるには、設定ファイルがとか全然不要で、単に
クラスパスに適切なライブラリを含ませる
で済むことになる。とはいえ、Log4j が後発（でライバルの息のかかった）の slf4j のことなんて知らないので、Slf4j を Log4j で使いたいのならば、クラスパスには
をセットしてやればいい、ということになる。こんな感じで、そういうimpl 実装が
というかたちで配布パッケージ中に並んでる。ここから好きなの選んでクラスパスに入れろ、というノリだ。あと、jcl104-over-slf4j.jar は commons-logging 用の slf4j の実装で、commons-logging のインターフェイスで slf4j の実装を呼ぶようになっている。で、log4j-over-slf4j は過激なことに、Log4j のインターフェイスで slf4j の実装を呼ぶようになっている....だから、内部的にロガーをいじるとかしてないならば、これを使えば Log4j 用に書いたコードを何も修正せずに slf4j 経由でたとえば logback を使うなんてできてしまう。
設定ファイルは、クラスパスの通ったディレクトリに存在する「logback.xml」だけを利用する。Log4j だといろいろと System プロパティを参照してややこしくやってるが、Logback はここらへんシンプルだ。後で触れるコンテキストセレクタを別にすれば、単に
....これだけである。まあ、logback-test.xml はテスト用っぽい名前だから、あまりこれに依存してアプリを作らない方が良いように感じる。だから、単純に「クラスパス上の logback.xml」という、極めてクリアな世界だ。勿論、log4j.properties に相当するプロパティ形式設定ファイルなぞ、時代遅れとして排除され跡形もない。
じゃあ、簡単な logback.xml はこうだ。
<configuration>
<appender name="STDOUT"
class="ch.qos.logback.core.ConsoleAppender">
<Target>System.out</Target>
<layout class="ch.qos.logback.classic.PatternLayout">
<Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n</Pattern>
</layout>
</appender>
<logger name="jp.or.nurs.sug">
<level value="DEBUG" />
</logger>
<root>
<level value="INFO" />
<appender-ref ref="STDOUT" />
</root>
</configuration>
という格好になる。まあ、階層構造自体は log4j.xml と大差があるわけではない...が、これ DTD は使わない...という今風の考え方で、JoranConfigurator という強烈な XML 解析のやり方をしているために、実際エレメント名に特別な制限がなく、特にパラメータを渡すのに log4j.xml のように、
<param name="Target" value="System.out" />
のように、param エレメントの name 属性で示唆される名前の setter を value 属性値で呼ぶ...とかきっちり固定されているわけではない（一応 param の古い書き方も通る）。そうではなくて、ここらへんエレメント名を見て、特別な役割りを与えられた名前じゃない限り、その親エレメントの属性名として扱う...というやり方になっている。で、この時、特にさらに入れ子に出来る／出来ないというのを、エレメント名で制御する、ということにはなっておらず、実際にそのエレメントによって生成されたオブジェクトの型（class属性）から、単純にリフレクトして動的に解決している。比喩的に言えば、すべてのエレメントが、Layout のような振舞をする、と考えてもいいのでは...とも思う。
だから、単に「set○○」「add○○」という名前のメソッドが、生成されたオブジェクトにあれば、それでプロパティ値がセット（追加）される、という格好である。ここらへん今風で、小規模な Spring みたいな雰囲気だ。
じゃあ、このデフォルトのルールに従わない特殊な名前は何か...というと、
があるので、これらはまたページを改めてきっちり解説する。
で、あといわゆるデバッグフラグと、診断ログだけど、
<configuration debug="true">
で診断ログが出る。設定などで「あれ？」と悩んだら、出してみるのがいいな。こんな出力になる。
|-INFO in ch.qos.logback.core.joran.action.AppenderAction -
About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
|-INFO in ch.qos.logback.core.joran.action.AppenderAction -
Naming appender as [STDOUT]
|-INFO in ch.qos.logback.core.joran.action.AppenderAction -
Popping appender named [STDOUT] from the object stack
|-INFO in ch.qos.logback.classic.joran.action.LevelAction -
root level set to TRACE
|-INFO in ch.qos.logback.core.joran.action.AppenderRefAction -
Attaching appender named [STDOUT] to Logger[root]
|-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction -
End of configuration.
17:41:23 [] INFO j.o.n.sug.logback.test.TestLogback - ENTER: TestLogback
17:41:48 [] INFO j.o.n.sug.logback.test.TestLogback - EXIT: TestLogback
みたいな感じで、頭に「|-」が付くのが診断ログだ。
じゃあ、ログの要素、というかどんな内容がログとして出力されるんだろう？ ログの要素として、こういうものを Logback は扱っている。ますは通常の classic パッケージは log4j 同様に ch.qos.logback.classic.spi.LoggingEvent である。log4j の LoggingEvent と比較すると、結構整理された感じである。(〜内は、LoggingEvent クラスでそのメンバを取得するための公開メソッド)
あとは、上記のログ出力要素を具体的に出力するための「レイアウト」である。Appender 毎に個別に設定可能な要素である「レイアウト」は、具体的な出力のパターンであり、これがいじれないんじゃ意味がない...となるが、当然 layout 要素によってこれを勝手に変えることが可能である。
一応、これもいろいろなレイアウトがある。用意されているパターンは次のものである。
INFO] ENTER: TestLog4j WARN] Test WARNING!! INFO] EXIT: TestLog4j
<!DOCTYPE HTML PUBLIC "-//W3C//DTD XHTML 1.0 Strict//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-strict.dtd">
<html>
<head>
<title>Logback Log Messages</title>
<STYLE type="text/css">
table { margin-left: 2em; margin-right: 2em; border-left: 2px solid #AAA; }
TR.even { background: #FFFFFF; }
TR.odd { background: #EAEAEA; }
TR.warn TD.Level, TR.error TD.Level, TR.fatal TD.Level {font-weight: bold; color: #FF4040 }
TD { padding-right: 1ex; padding-left: 1ex; border-right: 2px solid #AAA; }
TD.Time, TD.Date { text-align: right; font-family: courier, monospace; font-size: smaller; }
TD.Thread { text-align: left; }
TD.Level { text-align: right; }
TD.Logger { text-align: left; }
TR.header { background: #596ED5; color: #FFF; font-weight: bold; font-size: larger; }
TD.Exception { background: #A2AEE8; font-family: courier, monospace;}
</STYLE>
</head>
<body>
<hr size="1" noshade="true" width="50%" align="left" />
Log session start time Sun Sep 30 19:36:28 GMT+09:00 2007<br />
<br />
<table cellspacing="0">
<tr class="header">
<td class="Date">Date</td>
<td class="Thread">Thread</td>
<td class="Level">Level</td>
<td class="Logger">Logger</td>
<td class="MDC">MDC</td>
<td class="Message">Message</td>
</tr>
<tr class="info even">
<td class="Date">2007-09-30 19:36:28,834</td>
<td class="Thread">main</td>
<td class="Level">INFO</td>
<td class="Logger">jp.or.nurs.sug.logback.test.TestLogback</td>
<td class="MDC"></td>
<td class="Message">ENTER: TestLogback</td>
</tr>
<tr class="warn odd">
<td class="Date">2007-09-30 19:36:35,987</td>
<td class="Thread">main</td>
<td class="Level">WARN</td>
<td class="Logger">jp.or.nurs.sug.logback.test.child.TestChild</td>
<td class="MDC"></td>
<td class="Message">test</td>
</tr>
<tr class="error even">
<td class="Date">2007-09-30 19:36:35,991</td>
<td class="Thread">main</td>
<td class="Level">ERROR</td>
<td class="Logger">jp.or.nurs.sug.logback.test.child.TestChild</td>
<td class="MDC"></td>
<td class="Message">test</td>
</tr>
<tr><td class="Exception" colspan="6">java.io.IOException: test Exception
<br /> jp.or.nurs.sug.logback.test.child.TestChild.doSomething(TestChild.java:37)
<br /> jp.or.nurs.sug.logback.test.TestLogback.main(TestLogback.java:14)
</td></tr>
である。これだとテキトーにファイルの最後を、
</table></body></html>で閉じないといけない。
| %c,%lo,%logger | カテゴリー名。これは %c{1} という風に書けて、%c{1} だと一番「下の」 レベル、jp.or.nurs.sug.log4j.test.child.TestChild なら、「TestChild」のみになる。 |
| %C,%class | ログを生成したクラス名（≠カテゴリー名）。これも %C{2} という風に書けて、 %C{2} だと一番「下の」レベルから２つ上にたどる。 jp.or.nurs.sug.log4j.test.child.TestChild クラスなら、「child.TestChild」になるわけだ。 |
| %d, %date | 日付。これは %d{yyyy-MMM-dd HH:mm:ss,SSS} みたいに細かく書けるし、 また、TTCCLayout で使ったシンボルを使って、 %d{ISO8601} みたいに書いても良い。 |
| %l | 以下３つはいわゆる「LocationInfo」と呼ばれる、「ソース上どこでログイベントが発生したか？」についてのレイアウト指定である。これらの情報は有益だが、通信系Appenderの場合は「いらない情報をわざわざネット越しに送る」ことになるとか、スタックフレームを参照するのでJVMによってはうまく動かないケースがないわけではないとか、そもそもスピードが遅いとか、いろいろと問題を抱えているログ要素である。だから、これらは独立して「出す／出さない」の設定が可能なことが多い。で、この「%l」は３つの「LocationInfo」をまとめて出すオプション指定である。たとえば、「jp.or.nurs.sug.log4j.test.TestLog4j.main(TestLog4j.java:18)」のような出力になる。 |
| %F,%file | ログを生成したソースファイル名。遅いぞ！と警告されている |
| %L,%line | ログを生成した箇所のソースの行番号。遅いぞ！と警告されている |
| %M,%method | ログを生成したメソッドの名前。遅いぞ！と警告されている |
| %m,%msg,%message | ログメッセージ |
| %X{key},%mdc{key} | その MDC に保存された key の値 |
| %n | 改行コードを生成する。\nじゃないわけである。 |
| %p,%le,%level | ログレベル（FATALとかINFOとか） |
| %r,%relative | アプリケーションが開始してからの通算時間（ミリ秒） |
| %t,%thread | ログを生成したスレッド名 |
| %throwable{short} | 1.3で追加。これはレイアウト要素というよりも一種のスイッチである。例外をログメソッドに渡して Log4j を呼ぶと、デフォルトでは例外スタックトレースをすべて出力することになる。とはいえ、これは鬱陶しいケースも多い。なので、この「%throwable{short}」という表現をログフォーマットの末尾につけてやると、例外スタックトレースの最初の行だけを表示することになる。ちょっと動作が例外的なのが気になるが... |
| %nopex,%noexception | スイッチとして動作し、例外出力を抑止する |
| %caller | CallerData を出すが.... |
| %marker | マーカーを出力する。 |
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d %5p %c{1} - %m%n
そうすると出力は、
2004-09-10 17:13:09,754 INFO TestLog4j - Hello my Log4J world! 2004-09-10 17:13:33,261 WARN TestLog4j - This is WARNING!!!