第6章 レイアウト

レイアウトとは何か

レイアウトといってもフロリダ州の大規模集合住宅とは何の関係もありません。レイアウトはlogbackのコンポーネントであり、受け取ったロギングイベントを文字列に変換する役割を担っています。Layoutインターフェイスのformat()メソッドは、引数としてロギングイベントとみなされる（任意の型の）オブジェクトを受け取り、文字列を返します。Layoutインターフェイスの概要を次に示します。

public interface Layout<E> extends ContextAware, LifeCycle {

  String doLayout(E event);
  String getFileHeader();
  String getPresentationHeader();
  String getFileFooter();
  String getPresentationFooter();
  String getContentType();
}

このインターフェイスは簡潔ですが、あらゆる書式化のニーズを十分に満たしています。Catch-22に登場するテキサス育ちの開拓者であるジョセフ・ヘラーならこう叫んでいるところです。「レイアウトを実装しようにもたったの5つしかメソッドがない！！？ナンデ？！」

Logback-classic モジュール

logback-classic モジュールはch.qos.logback.classic.spi.ILoggingEventだけを扱うようになっています。この節を読み進めていけば理由が明らかになります。

レイアウトを自作する

logback-classic モジュールで使うために、簡潔で十分な機能性のあるレイアウトを自作してみましょう。出力したいのは次のようなものです。アプリケーションが起動してから経過した時間、ロギングイベントのログレベル、ブラケットで囲んだ呼び出しスレッド名、ロガー名、ダッシュ（-のこと）とそれに続くロギングイベントのメッセージ、最後に改行文字も加えておきましょう。

出力例は次のようになります。

テキサスの開拓者が実装したレイアウトのコードを見てましょう。

例：自作レイアウトのサンプル実装（logback-examples/src/main/java/chapters/layouts/MySampleLayout.java）

package chapters.layouts;

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.LayoutBase;

public class MySampleLayout extends LayoutBase<ILoggingEvent> {

  public String doLayout(ILoggingEvent event) {
    StringBuffer sbuf = new StringBuffer(128);
    sbuf.append(event.getTimeStamp() - event.getLoggingContextVO.getBirthTime());
    sbuf.append(" ");
    sbuf.append(event.getLevel());
    sbuf.append(" [");
    sbuf.append(event.getThreadName());
    sbuf.append("] ");
    sbuf.append(event.getLoggerName();
    sbuf.append(" - ");
    sbuf.append(event.getFormattedMessage());
    sbuf.append(CoreConstants.LINE_SEP);
    return sbuf.toString();
  }
}

MySampleLayoutはLayoutBaseを継承しているのに気付きましたか。このクラスは全てのレイアウトのインスタンスに共通する内部状態を管理するものです。例えば、レイアウトが開始しているか、停止しているか、ヘッダーはあるか、フッターはあるか、コンテンツタイプはあるか、といったものです。おかげで、開発者は書式化の方法にだけ集中することができるのです。LayoutBaseはジェネリッククラスです。上記のコードでは、MySampleLayoutはLayoutBase<ILoggingEvent>を継承しています。

doLayout(ILoggingEvent event)メソッド（MySampleLayoutの実装する唯一のメソッドです）では、最初に空のStringBufferを生成して、ロギングイベントのパラメータを付け足していきます。開拓者らしく、慎重に書式化したようです。ロギング要求で1つ以上のパラメータが渡されることを考えればこれは大事なことです。

doLayout()メソッドでは、StringBufferにいろいろな文字列を追加したあとで1つの文字列に変換して、その文字列を呼び出し元に返します。

上記のdoLayoutメソッドでは、ロギングイベントに含まれる可能性のあるあらゆる例外を無視します。実際のレイアウトの実装では、ほぼ確実に例外の内容を出力したいはずです。

自作レイアウトの設定

自作レイアウトは、他のコンポーネントと同じように設定されます。前述したようにFileAppenderとその派生クラスにはエンコーダーが必要です。FileAppenderのニーズを満たすため、LayoutWrappingEncoderに自作したMySampleLayoutをラップしてみましょう。次のような設定になります。

例：MySampleLayoutの設定（logback-examples/src/main/java/chapters/layouts/sampleLayoutConfig.xml）

<configuration>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
      <layout class="chapters.layouts.MySampleLayout" />
    </encoder>
  </appender>

  <root level="DEBUG">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

サンプルアプリケーションのchapters.layouts.SampleLoggingは、一つ目の引数で指定された設定ファイルを使ってlogbackを設定します。そして、デバッグメッセージとエラーメッセージを1つづつロギングします。

logback-examplesディレクトリに移動して、次のコマンドを実行してみましょう。

java chapters.layouts.SampleLogging src/main/java/chapters/layouts/sampleLayoutConfig.xml

コンソールには次のように出力されます。

0 DEBUG [main] chapters.layouts.SampleLogging - Everything's going well
0 ERROR [main] chapters.layouts.SampleLogging - maybe not quite...

簡単でしょう？エレア派の懐疑論者ピュロンは、それ自体が不確実であるということ以外に確実なことは無い、と主張しました。つまり、確かなことなど何もないというのです。彼はきっとこう質問するでしょう。「それでレイアウトのオプションについてはどうなっているの？」上記の自作レイアウトを少し変更したバージョンがMySampleLayout2.javaです。このマニュアル全体を通じて言えることですが、レイアウトでもlogbackの他のコンポーネントでも、単にセッターメソッドを設定するだけでプロパティを指定できるようになります。

MySampleLayout2クラスには、2つのプロパティがあります。一つ目は、出力されるメッセージの先頭に追加する接頭辞です。二つ目は、ロギング要求を送信したスレッドの名前を表示するかどうかを選択する真偽値です。

MySampleLayout2のコードを見てみましょう。

package chapters.layouts;

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.LayoutBase;

public class MySampleLayout2 extends LayoutBase<ILoggingEvent> {

  String prefix = null;
  boolean printThreadName = true;

  public void setPrefix(String prefix) {
    this.prefix = prefix;
  }

  public void setPrintThreadName(boolean printThreadName) {
    this.printThreadName = printThreadName;
  }

  public String doLayout(ILoggingEvent event) {
    StringBuffer sbuf = new StringBuffer(128);
    if (prefix != null) {
      sbuf.append(prefix + ": ");
    }
    sbuf.append(event.getTimeStamp() - event.getLoggerContextVO().getBirthTime());
    sbuf.append(" ");
    sbuf.append(event.getLevel());
    if (printThreadName) {
      sbuf.append(" [");
      sbuf.append(event.getThreadName());
      sbuf.append("] ");
    } else {
      sbuf.append(" ");
    }
    sbuf.append(event.getLoggerName());
    sbuf.append(" - ");
    sbuf.append(event.getFormattedMessage());
    sbuf.append(LINE_SEP);
    return sbuf.toString();
  }
}

プロパティのセッターメソッドを追加すれば設定ファイルから指定できるようになります。printThreadNameプロパティの型は真偽値（boolean）であって文字列（String）ではないので注意してください。logbackのコンポーネントの設定については、設定に関する章で詳しく説明しています。Joranの章にはより詳細な説明があります。MySampleLayout2のために特別に誂えた設定ファイルは次のとおりです。

<configuration>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
      <layout class="chapters.layouts.MySampleLayout2">
        <prefix>MyPrefix</prefix>
        <printThreadName>false</printThreadName>
      </layout>
    </encoder>
  </appender>

  <root level="DEBUG">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

PatternLayout

logback-classic の配布物には、PatternLayoutと呼ばれる柔軟性のあるレイアウトが含まれています。他のレイアウトと同じく、PatternLayoutはロギングイベントを受け取って文字列を返します。文字列は、変換パターン文字列を調整してカスタマイズすることができます。

PatternLayoutの変換パターン文字列はC言語のprintf()関数と非常によく似たもので、文字列リテラルと変換指定と呼ばれる書式制御式で構成されています。変換パターン文字列には、どんな文字列リテラルでも入れることができます。変換指定はパーセント記号"%"で始まり、オプションの書式修飾子、変換指定子、括弧で囲まれたパラメータが続いたものです。変換指定子には変換したいデータフィールドを指定します。例えばロガー名、レベル、日付、スレッド名などです。書式修飾子には、フィールド幅、パディング、左揃えや右揃えを指定します。

既に何度か述べたとおり、FileAppenderとその派生クラスにはエンコーダーが必要です。結局、FileAppenderやその派生クラスとPatternLayoutを一緒に使うには、エンコーダーでラップしなければなりません。FileAppenderとPatternLayoutを組み合わせることがあまりにも一般的になってしまったことを考慮して、logback の配布物にはPatternLayoutEncoderを含めるようになりました。これは単にPatternLayoutをラップするだけのエンコーダーなので、エンコーダーであるにも関わらずPatternLayoutのように扱えるようになっています。プログラム的にConsoleAppenderとPatternLayoutEncoderを設定する例を示します。

例：PatternLayoutの使用例（logback-examples/src/main/java/chapters/layouts/PatternSample.java）

package chapters.layouts;

import org.slf4j.LoggerFactory;

import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.ConsoleAppender;

public class PatternSample {

  static public void main(String[] args) throws Exception {
    Logger rootLogger = (Logger)LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
    LoggerContext loggerContext = rootLogger.getLoggerContext();
    // we are not interested in auto-configuration
    loggerContext.reset();

    PatternLayoutEncoder encoder = new PatternLayoutEncoder();
    encoder.setContext(loggerContext);
    encoder.setPattern("%-5level [%thread]: %message%n");
    encoder.start();

    ConsoleAppender<ILoggingEvent> appender = new ConsoleAppender<ILoggingEvent>();
    appender.setContext(loggerContext);
    appender.setEncoder(encoder);
    appender.start();

    rootLogger.addAppender(appender);

    rootLogger.debug("Message 1");
    rootLogger.warn("Message 2");
  }
}

この例では、変換パターン文字列として"％-5level [％thread] %msg％n"が設定されています。logbackに組み込みの変換指定子については後で簡単に説明します。PatternSampleアプリケーションを実行してみましょう。

java java chapters.layouts.PatternSample

コンソールにに次のように出力されます。

DEBUG [main]: Message 1 WARN [main]: Message 2

変換パターン文字列の"%-5level [％thread] %msg%n"には、文字列リテラルと変換指定子を明示的に区切る文字が無いことに気付きましたか。変換パターン文字列を解析する際、PatternLayoutは文字列リテラル（空白文字、括弧、コロンなど）と変換指定を分離することができます。上記の例では、変換指定"％-5level"は、ロギングイベントのレベルを5文字の幅に左揃えすることを意味します。書式指定子については後で説明します。

PatternLayoutは変換パターン文字列をグループ化するために括弧を使います。つまり '（'と '）'には特別な意味があるので、リテラル文字列として使うときはエスケープしなければならないということです。 括弧の特殊な性質について詳しくは後で説明します。

前述のとおり、変換指定によっては括弧で囲んでオプションの引数を指定することができます。例えばこういう書き方です。%logger{10}"logger" が変換指定子で、10が引数です。オプションの指定の仕方について詳しくは後で説明します。

利用できる変換指定とオプションを表にまとめました。1つのセルに複数の変換指定子が登場する場合、それらは別名という意味です。

0    [main] DEBUG - logging statement
Caller+0   at mainPackage.sub.sample.Bar.sampleMethodName(Bar.java:22)
Caller+1   at mainPackage.sub.sample.Bar.createLoggingRequest(Bar.java:17)

16   [main] DEBUG - logging statement
Caller+0   at mainPackage.sub.sample.Bar.sampleMethodName(Bar.java:22)
Caller+1   at mainPackage.sub.sample.Bar.createLoggingRequest(Bar.java:17)
Caller+2   at mainPackage.ConfigTester.main(ConfigTester.java:38)

mainPackage.foo.bar.TestException: Houston we have a problem
  at mainPackage.foo.bar.TestThrower.fire(TestThrower.java:22)
  at mainPackage.foo.bar.TestThrower.readyToLaunch(TestThrower.java:17)
  at mainPackage.ExceptionLauncher.main(ExceptionLauncher.java:38)

mainPackage.foo.bar.TestException: Houston we have a problem
  at mainPackage.foo.bar.TestThrower.fire(TestThrower.java:22)

mainPackage.foo.bar.TestException: Houston we have a problem
  at mainPackage.foo.bar.TestThrower.fire(TestThrower.java:22)
  at mainPackage.foo.bar.TestThrower.readyToLaunch(TestThrower.java:17)
  at mainPackage.ExceptionLauncher.main(ExceptionLauncher.java:38)

mainPackage.foo.bar.TestException: Houston we have a problem
  at mainPackage.foo.bar.TestThrower.fire(TestThrower.java:22)
  at mainPackage.foo.bar.TestThrower.readyToLaunch(TestThrower.java:17)

java.lang.NullPointerException
  at com.xyz.Wombat(Wombat.java:57) ~[wombat-1.3.jar:1.3]
  at com.xyz.Wombat(Wombat.java:76) ~[wombat-1.3.jar:1.3]
Wrapped by: org.springframework.BeanCreationException: Error creating bean with name 'wombat':
  at org.springframework.AbstractBeanFactory.getBean(AbstractBeanFactory.java:248) [spring-2.0.jar:2.0]
  at org.springframework.AbstractBeanFactory.getBean(AbstractBeanFactory.java:170) [spring-2.0.jar:2.0]
  at org.apache.catalina.StandardContext.listenerStart(StandardContext.java:3934) [tomcat-6.0.26.jar:6.0.26]

%文字の特別な意味

変換パターン文字列というコンテキストにおいて、%文字には特別な意味があります。文字列リテラルとして使用するにはバックスラッシュ（\）を前につけてエスケープしなければなりません。たとえば "%d %p \%%m%n" といったようにします。

変換指定子の直後の文字列リテラルの制限

ほとんどの場合文字列リテラルにはスペースや他の区切り文字が含まれるので、変換指定子と混同されることはありません。例えば、変換パターン文字列"%level [%thread] - %mmessage%n" には文字列リテラル " ["と"] - "が含まれています。しかし、Javaの識別子に使える文字リテラルが変換指定子の直後に現れると、logbackの文字列パターン解析器はその文字リテラルも変換指定子の一部だと勘違いしてしまいます。例えば、変換パターン文字列 "%date%nHello" は、%date と %nHello という二つの変換指定子として解釈されてしまいます。もちろん、%nHello は変換指定子に存在しないため、logback は %PARSER_ERROR[nHello] というエラーを出力するでしょう。%nのすぐ後に文字列リテラル "Hello" を出したければ、%nに空の引数リストを指定すればよいでしょう。たとえば、"%date%n{}Hello" とすれば、%date %n 文字列リテラル "Hello" という順に解釈させることができるでしょう。

書式修飾子

デフォルトでは、関連する情報はそのまま出力されます。しかし、書式修飾子を使えばそれぞれのデータを出力する幅の最小値と最大値、それに文字揃えを変えることが出来ます。

書式修飾子のオプションは%記号と修飾文字の間に入れます。

最初に紹介する書式修飾子のオプションは左揃えです。これはただのマイナス（-）を指定します。次は最小幅です。整数値で出力する文字数を指定します。出力する文字列長が指定した文字数より小さい時は、最小幅を全てうめるまで右側か左側のどちらかをパディングします。デフォルトは右揃えなので左側にパディングしますが、左揃えにして右側にパディングさせることもできます。パディング文字は半角スペースです。出力する文字列長が指定した文字数より大きい時は、全て出力できるように幅を広げます。後ろを切り捨てることはありません。

この振る舞いは最大幅を指定すれば変えられます。最大幅はドット（.）の後に整数値で指定します。出力する文字列長が指定した文字数より大きい時は、溢れた分だけ出力する文字列の先頭から削除されます。たとえば、最大幅を8にしたとき、出力する文字列長が10だったら、先頭の2文字が削除されることになります。C言語のprintf関数なら文字列の後ろのほうが削除されるので、逆の振る舞いをすることになります。

ドット（.）に続けてマイナス文字（-）を指定すれば、後ろから削除することもできます。その場合、最大幅が8として、出力する文字列長が10だったら、末尾の2文字が削除されることになります。

書式修飾子の例をいくつか見ていきましょう。

書式修飾子による文字列の切り捨ての例を表にまとめました。角括弧"[]"は出力される文字列ではなく、出力幅を示しているだけなので注意してください。

[           main.Name]

[main.Name           ]

[o.bar.Name]

[main.foo.f]

レベルを1文字で出力する

ロギングレベルをTRACE、DEBUG、WARN、INFO、ERRORのような文字列として出力するのではなく、T、D、W、I、Eのように一文字だけ出力したい場合もあるでしょう。カスタムコンバーターを実装してもできるでしょうし、書式修飾子を使うこともできます。書式修飾子を使うなら"%.-1level"とすればよいでしょう。

変換指定子のオプション

変換指定子にはオプションを指定することができます。オプションは必ず中括弧で囲むようにします。オプションで何ができるのか、すでに目にしてきたものがあります。たとえば、％mdc{someKey}のようにMDC変換指定子と組み合わせることができます。

変換指定子のオプションは複数になるかもしれません。たとえば、評価器を使う変換指定子があります。すぐ後で説明しますが、こんな風に評価器の名前を複数並べることがあるかもしれません。

<pattern>%-4relative [%thread] %-5level - %msg%n \
  %caller{2, DISP_CALLER_EVAL, OTHER_EVAL_NAME, THIRD_EVAL_NAME}</pattern>

指定するオプションに括弧、スペース、カンマなどの特別な文字が含まれるときは、シングルクォートやダブルクォートで囲みます。たとえば、次のような変換パターン文字列になります。

<pattern>%-5level - %replace(%msg){'\d{14,16}', 'XXXX'}%n</pattern>

この例では、replace変換指定子にオプションとして\d{14,16}とXXXXを指定しています。これは、メッセージ中に14桁から16桁の数字文字列があったらそれをXXXXで置き換えるものです。クレジットカード番号をマスクするのに役立ちます。"\d"は一桁の数字を表す正規表現の省略形です。後ろに"{14,16}"をつけているので、一つ前の文字、つまり一桁の数字が14個から16個繰り返される場合にマッチすることになります。

括弧は特別扱い

logbackでは、パターン文字列の中の括弧は、トークンをグループ化するものとして扱います。それぞれのグループはそれ自体を1つのパターン文字列として扱うことができます。logback0.9.27から、%replaceのような変換指定子を組み合わせて部分パターン文字列を作れるようになりました。

こんなパターン文字列があるとします。

%-30(%d{HH:mm:ss.SSS} [%thread]) %-5level %logger{32} - %msg%n

これは、部分パターン文字列"%d{HH:mm:ss.SSS} [%thread]" によって生成された出力をグループ化します。つまり、この部分パターン文字列によって生成された出力が30文字未満の文字列だった場合、右側にパディングされるのです。

グループ化しなかった場合はこういう出力になります。

13:09:30 [main] DEBUG c.q.logback.demo.ContextListener - Classload hashcode is 13995234 13:09:30 [main] DEBUG c.q.logback.demo.ContextListener - Initializing for ServletContext 13:09:30 [main] DEBUG c.q.logback.demo.ContextListener - Trying platform Mbean server 13:09:30 [pool-1-thread-1] INFO ch.qos.logback.demo.LoggingTask - Howdydy-diddly-ho - 0 13:09:38 [btpool0-7] INFO c.q.l.demo.lottery.LotteryAction - Number: 50 was tried. 13:09:40 [btpool0-7] INFO c.q.l.d.prime.NumberCruncherImpl - Beginning to factor. 13:09:40 [btpool0-7] DEBUG c.q.l.d.prime.NumberCruncherImpl - Trying 2 as a factor. 13:09:40 [btpool0-7] INFO c.q.l.d.prime.NumberCruncherImpl - Found factor 2

"％-30()" でグループ化するとこうなります。

13:09:30 [main] DEBUG c.q.logback.demo.ContextListener - Classload hashcode is 13995234 13:09:30 [main] DEBUG c.q.logback.demo.ContextListener - Initializing for ServletContext 13:09:30 [main] DEBUG c.q.logback.demo.ContextListener - Trying platform Mbean server 13:09:30 [pool-1-thread-1] INFO ch.qos.logback.demo.LoggingTask - Howdydy-diddly-ho - 0 13:09:38 [btpool0-7] INFO c.q.l.demo.lottery.LotteryAction - Number: 50 was tried. 13:09:40 [btpool0-7] INFO c.q.l.d.prime.NumberCruncherImpl - Beginning to factor. 13:09:40 [btpool0-7] DEBUG c.q.l.d.prime.NumberCruncherImpl - Trying 2 as a factor. 13:09:40 [btpool0-7] INFO c.q.l.d.prime.NumberCruncherImpl - Found factor 2

後者のほうが読みやすいんじゃないでしょうか。

括弧を文字列リテラルとして扱いたいときは、バックスラッシュ（\）でエスケープしなければなりません。こんな感じです。 "\(%d{HH:mm:ss.SSS} [%thread]\)"

カラー化

括弧でグループ化した部分パターン文字列には色を指定することができます。logback1.0.5からPatternLayoutで指定できるようになった色付け用の変換指定子は次のとおりです。

• "%black"
• "%red"
• "%green"
• "%yellow"
• "%blue"
• "%magenta"
• "%cyan"
• "%white"
• "%gray"
• "%boldRed"
• "%boldGreen"
• "%boldYellow"
• "%boldBlue"
• "%boldMagenta"
• "%boldCyan"
• "%boldWhite"
• "%highlight"

色付けをわかりやすく説明する設定ファイルを次に示します。%cyan変換指定子には部分パターン文字列として"%logger{15}"を指定してあるのがわかりますか。こうすると、ロガー名は15文字に短縮されるだけでなく、文字色がシアンになります。%highlight変換指定子を使うと、部分パターン文字列の文字色が、ログレベルがERRORなら赤太字、ログレベルがWARNなら赤字、ログレベルがINFOなら青字、それ以外のログレベルならデフォルトの色になります。

例：ログレベルに応じた強調表示（logback-examples/src/main/java/chapters/layouts/highlighed.xml）

<configuration debug="true">
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <!-- On Windows machines setting withJansi to true enables ANSI
         color code interpretation by the Jansi library. This requires
         org.fusesource.jansi:jansi:1.8 on the class path.  Note that
         Unix-based operating systems such as Linux and Mac OS X
         support ANSI color codes by default. -->
    <withJansi>true</withJansi>
    <encoder>
      <pattern>[%thread] %highlight(%-5level) %cyan(%logger{15}) - %msg %n</pattern>
    </encoder>
  </appender>
  <root level="DEBUG">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

この設定ファイルを使うと次のように出力されます。

[main] WARN  c.l.TrivialMain - a warning message 0
[main] DEBUG c.l.TrivialMain - hello world number1
[main] DEBUG c.l.TrivialMain - hello world number2
[main] INFO  c.l.TrivialMain - hello world number3
[main] DEBUG c.l.TrivialMain - hello world number4
[main] WARN  c.l.TrivialMain - a warning message 5
[main] ERROR c.l.TrivialMain - Finish off with fireworks

色付け用変換指定子を使うとパターン文字列が複数行になってしまうこともあります。変換指定を自作するでは設定ファイルで使用できる変換指定子を登録する手順について議論しています。

評価器

前述したように、オプションをリストで指定できると、変換指定子にEventEvaluatorに基づく動的な振る舞いを複数指定できる必要があるときは便利です。 EventEvaluatorの役割は、ロギングイベントが基準に合致するかどうかを判定することです。

早速EventEvaluatorの例を見てみましょう。次の設定ファイルは、ロギングイベントの日付、スレッド、レベル、メッセージと送信者情報をコンソールに出力するものです。ロギングイベントの送信者情報を抽出するのはとてもコストが高いので、特定のロガーが生成したロギング要求の場合だけに限定しています。さらに、メッセージに特定の文字列が含まれている場合だけにしています。ですので、特定のロギングイベントについてだけ、送信者情報の生成と出力を行うことになります。そうすれば、送信者情報のいらないケースではアプリケーションの性能ペナルティが発生しません。

評価器と具体的な評価式については、フィルタの章の独立したセクションで紹介しています。もし評価器を実戦投入しようとしているなら必ず読んでおいてください。この後で紹介する例では、明示的に書いていませんがJaninoEventEvaluatorを使用しています。ですので実行するにはJainoライブラリが必要になります。設定方法をまとめたドキュメントの該当するセクションを読んでください。

例：EventEvaluatorsの使用例（logback-examples/src/main/java/chapters/callerEvaluatorConfig.xml）

<configuration>
  <evaluator name="DISP_CALLER_EVAL">
    <expression>logger.contains("chapters.layouts") &amp;&amp; \
      message.contains("who calls thee")</expression>
  </evaluator>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>
        %-4relative [%thread] %-5level - %msg%n%caller{2, DISP_CALLER_EVAL}
      </pattern>
    </encoder>
  </appender>

  <root level="DEBUG">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

この設定ファイル中の評価式は、ロガー名に"chapters.layouts" が含まれており、かつ、メッセージに"who clals thee" が含まれているロギングイベントにマッチするものです。XMLのエンコーディングルールに従うため、&文字は&のようにエスケープしなければなりません。

この設定ファイルを使用するクラスを見てみましょう。

例：EventEvaluatorsの使用例（logback-examples/src/main/java/chapters/CallerEvaluatorExample.java）

package chapters.layouts;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.joran.JoranConfigurator;
import ch.qos.logback.core.joran.spi.JoranException;
import ch.qos.logback.core.util.StatusPrinter;

public class CallerEvaluatorExample {

  public static void main(String[] args)  {
    Logger logger = LoggerFactory.getLogger(CallerEvaluatorExample.class);
    LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();

    try {
      JoranConfigurator configurator = new JoranConfigurator();
      configurator.setContext(lc);
      configurator.doConfigure(args[0]);
    } catch (JoranException je) {
      // StatusPrinter will handle this
    }
    StatusPrinter.printInCaseOfErrorsOrWarnings(lc);

    for (int i = 0; i < 5; i++) {
      if (i == 3) {
        logger.debug("who calls thee?");
      } else {
        logger.debug("I know me " + i);
      }
    }
  }
}

このアプリケーションは特別何もしません。forループでロギング要求を5回生成します。三回目だけ "who calls thee?" というメッセージを出力します。

次のコマンドで実行します。

java chapters.layouts.CallerEvaluatorExample src/main/java/chapters/layouts/callerEvaluatorConfig.xml

そうすると、コンソールに次のように出力されます。

0    [main] DEBUG - I know me 0
0    [main] DEBUG - I know me 1
0    [main] DEBUG - I know me 2
0    [main] DEBUG - who calls thee?
Caller+0   at chapters.layouts.CallerEvaluatorExample.main(CallerEvaluatorExample.java:28)
0    [main] DEBUG - I know me 4

ロギング要求が生成されたら、そのロギングイベントが評価されます。三回目のロギングイベントだけが評価条件にマッチするので、送信者情報が出力されます。他のロギングイベントは評価基準とマッチしないので送信者情報が出力されていません。

現実世界のシナリオに対応できるように評価式を変更することにしましょう。例えばロガー名とロギング要求のレベルを組み合わせることもできます。そうすれば、ロギング要求のレベルがWARNより高くて、かつ、アプリケーションの重要部品、例えばお金に絡むトランザクションを処理するモジュールで生成された場合にだけ送信者情報を出力する、といったことができるでしょう。

重要： caller変換指定によって送信者情報が出力されるのは、評価式がtrueと評価されたときだけです。

別の状況を考えてみましょう。ロギング要求に例外オブジェクトが設定されていると、スタックトレースも出力されます。しかし、特定の例外オブジェクトのスタックトレースは出力したくないこともあります。

次のコードでは、例外オブジェクトを指定したロギング要求を3つ生成しています。二つ目の例外オブジェクトは他のものと違ってメッセージに "do not display this" という文字列が含まれていますし、例外クラスが chapters.layouts.TestExceptionになっています。このメッセージを指示とみなして、二つ目の例外オブジェクトのスタックトレースが出力されないようにしてみましょう。

例：ExceptionEventEvaluatorsの使用例（logback-examples/src/main/java/chapters/ExceptionEvaluatorExample.java）

package chapters.layouts;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.joran.JoranConfigurator;
import ch.qos.logback.core.joran.spi.JoranException;
import ch.qos.logback.core.util.StatusPrinter;

public class ExceptionEvaluatorExample {

  public static void main(String[] args) {
    Logger logger = LoggerFactory.getLogger(ExceptionEvaluatorExample.class);
    LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();

    try {
      JoranConfigurator configurator = new JoranConfigurator();
      configurator.setContext(lc);
      lc.reset();
      configurator.doConfigure(args[0]);
    } catch (JoranException je) {
       // StatusPrinter will handle this
    }
    StatusPrinter.printInCaseOfErrorsOrWarnings(lc);

    for (int i = 0; i < 3; i++) {
      if (i == 1) {
        logger.debug("logging statement " + i, new TestException(
            "do not display this"));
      } else {
        logger.debug("logging statement " + i, new Exception("display"));
      }
    }
  }
}

次の設定ファイルで指定した評価式は、chapters.layouts.TextExceptionの例外オブジェクトが設定されたロギングイベントにマッチします。この例外型はスタックトレースの出力を抑止したい型そのものです。

例：ExceptionEventEvaluatorsの使用例（logback-examples/src/main/java/chapters/exceptionEvaluatorConfig.xml）

<configuration>

  <evaluator name="DISPLAY_EX_EVAL">
    <expression>throwable != null &amp;&amp; throwable instanceof  \
      chapters.layouts.TestException</expression>
  </evaluator>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%msg%n%ex{full, DISPLAY_EX_EVAL}</pattern>
    </encoder>
  </appender>

  <root level="debug">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

この設定は、chapters.layouts.TestExceptionのインスタンスが設定されたロギング要求については、常にスタックトレースの出力を抑止します。

実行してみましょう。

java chapters.layouts.ExceptionEvaluatorExample src/main/java/chapters/layouts/exceptionEvaluatorConfig.xml

そうすると、次のような出力になります。

logging statement 0 java.lang.Exception: display at chapters.layouts.ExceptionEvaluatorExample.main(ExceptionEvaluatorExample.java:43) [logback-examples-0.9.19.jar:na] logging statement 1 logging statement 2 java.lang.Exception: display at chapters.layouts.ExceptionEvaluatorExample.main(ExceptionEvaluatorExample.java:43) [logback-examples-0.9.19.jar:na]

二つ目のロギング要求による出力にはスタックトレースが含まれていないことがわかりますか。うまくTestExceptionのスタックトレースを出力しないようにできました。スタックトレースの各行の最後にある角括弧で囲まれた部分はパッケージング情報です。

%ex変換指定があるので、評価式の結果がfalseになったときだけスタックトレースが出力されるようになっています。

変換指定子を自作する

ここまでに、PatternLayoutに組み込みの変換指定子を見てきました。ですが、変換指定子を自作することもできるのです。

カスタム変換指定子を作るには2つの手順を踏みます。

ステップ1

まず、ClassicConverterを継承したクラスを作ります。ClassicConverterの役割は、ILoggingEventから情報を抽出して出力する文字列を生成することです。たとえば、 %logger変換指定子を実装したLoggerConverterは、ILoggingEventから抽出したロガーの名前を文字列として返します。ロガー名の省略はこの手順で行います。

アプリケーションが起動してからの経過時間をナノ秒単位で返すカスタム変換指定子の実装を見てみましょう。

例：自作コンバーターの例（logback-examples/src/main/java/chapters/MySampleConverter.java）

public class MySampleConverter extends ClassicConverter {

  long start = System.nanoTime();

  @Override
  public String convert(ILoggingEvent event) {
    long nowInNanos = System.nanoTime();
    return Long.toString(nowInNanos-start);
  }
}

この実装は非常に簡単です。MySampleConverterクラスはClassicConverterを継承しており、convert(ILoggingEvent)メソッドはアプリケーションが起動してからの経過時間をナノ秒単位で計算して、それを文字列化しているだけです。

ステップ2

logback に自作したConverterのことを教えなければいけません。そのためには、設定ファイルで新しい変換指定子を宣言する必要があります。

例：自作コンバーターの設定例（logback-examples/src/main/java/chapters/mySampleConverterConfig.xml）

<configuration>

  <conversionRule conversionWord="nanos"
                  converterClass="chapters.layouts.MySampleConverter" />

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%-6nanos [%thread] - %msg%n</pattern>
    </encoder>
  </appender>

  <root level="DEBUG">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

設定ファイルで宣言した新しい変換指定子は、PatternLayoutに指定する変換パターン文字列の中で他の変換指定と同じように使うことが出来ます。

実行してみましょう。

次のような出力になるはずです。

4868695 [main] DEBUG - Everything's going well
5758748 [main] ERROR - maybe not quite...

オプションの扱い方や、もっと複雑な振る舞いをさせるやり方を知りたければ、MDCConverterなどの既存のConverter実装を見てみるとよいでしょう。独自の色付けをしたければHighlightingCompositeConverterを参考にするとよいでしょう。

HTMLLayout

HTMLLayoutはHTML形式のログを出力します（logback-classicに含まれています）。HTMLLayoutはHTMLのテーブルを出力します。それぞれの行がロギングイベントに対応しています。

デフォルトのCSSを使ったHTMLLayoutの出力例を見てください。

テーブルの列は変換パターン文字列で指定します。PatternLayoutのドキュメントに書かれた変換パターン文字列の説明を見てください。テーブルの形も内容も全て制御することができます。PatternLayoutで使えるあらゆるコンバーターを使うことができます。

自由に使えるとはいえ一つだけ例外的な制限があります。PatternLayoutとHTMLLayoutを使うときは、変換パターン文字列中で変換指定を半角スペースで区切ってはいけません。もっというと文字列リテラルを使わないようにしてください。変換パターン文字列中の変換指定はそれぞれがテーブルの列になるからです。同様に、変換指定を区切るつもりの文字列リテラルはそれぞれが列になってしまいます。下手をすると、横に超長いテーブルが出力されてしまうかもしれません。

HTMLLayoutの使い方を説明する設定ファイルを見てください。

例：HTMLLayoutの設定例（logback-examples/src/main/java/chapters/htmlLayoutConfig1.xml）

<configuration debug="true">
  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
      <layout class="ch.qos.logback.classic.html.HTMLLayout">
        <pattern>%relative%thread%mdc%level%logger%msg</pattern>
      </layout>
    </encoder>
    <file>test.html</file>
  </appender>

  <root level="DEBUG">
    <appender-ref ref="FILE" />
  </root>
</configuration>

TrivialMainアプリケーションは、いくつかログを出力してから最後に例外オブジェクトを指定したログを出力します。実行してみましょう。

java chapters.layouts.TrivialMain src/main/java/chapters/layouts/htmlLayoutConfig1.xml

すると、カレントフォルダにtest.htmlというファイルが作成されます。test.htmlをブラウザで見ると次のようになっているでしょう。

スタックトレース

スタックトレースを出力するには%ex変換指定を指定します。そうすると専用の列が追加されます。ほとんどの場合スタックトレースの列は空なので、無駄に画面を専有することでしょう。さらに、スタックトレースを専用の列に出力したところで読みやすくはならないです。なお、スタックトレースを出力するには、%ex変換指定を指定する以外の方法があります。

よりよい解決策は、自分でIThrowableRendererインターフェイスを実装することです。実装したクラスは、例外オブジェクトに関係する情報を出力するため、HTMLLayoutに割り当てることができます。デフォルトでは、HTMLLayoutインスタンスにDefaultThrowableRendererが割り当てられています。これは例外オブジェクトのスタックトレースを新しい行に出力します。前の図を見るとわかりますが多少読みやすいです。

それでも理由があって%exを使いたいときは、設定ファイルにNOPThrowableRendererを指定すればスタックトレースを別々の行に出力しないようにできます。あなたの望み通りに全てが上手くいくようなアイデアはありません。それでも、こうしたいという気持ちがあればきっと実現できます。

CSS

HTMLLayoutで生成したHTMLの見た目はCSSで調整することができます。特別な指定がなければ、HTMLLayoutは組み込みのCSSを使います。しかし、外部のCSSを使うようにも指定できます。そのためには、layout要素にcssBuilder要素をネストさせればよいです。

<layout class="ch.qos.logback.classic.html.HTMLLayout">
  <pattern>%relative...%msg</pattern>
  <cssBuilder class="ch.qos.logback.classic.html.UrlCssBuilder">
    <!-- url where the css file is located -->
    <url>http://...</url>
  </cssBuilder>
</layout>

HTMLLayoutはSMTPAppenderと組み合わせて使われることがあります。そうするとメールの内容がHTMLで綺麗に飾られたものになります。

Log4jのXMLLayout

XMLLayout （logback-classicに含まれています）を使うとlog4j.dtdに準拠した書式で出力できるようになります。つまり、ChainsawやVigilogなどの、log4jのXML書式を入力とするツールと相互運用できるのです。

オリジナルのXMLLayoutはlog4j1.2.15で導入されたものです。logback-classic の XMLLayoutにはlocationInfoとpropertiesという二つのプロパティが指定できます。locationInfoプロパティにtrueを指定すると、ロギングイベントの位置情報（送信者情報）を含められるようになります。propertyプロパティにtrueを指定すると、MDCの情報を含められるようになります。どちらのプロパティもデフォルトはfalseです。

設定例を見てみましょう。

例：Log4jXMLLayoutの例（logback-examples/src/main/java/chapters/log4jXMLLayout.xml）

<configuration>
  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>test.xml</file>
    <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
      <layout class="ch.qos.logback.classic.log4j.XMLLayout">
        <locationInfo>true</locationInfo>
      </layout>
    </encoder>
  </appender>

  <root level="DEBUG">
    <appender-ref ref="FILE" />
  </root>
</configuration> 

logback access モジュール

logback-access モジュールのほとんどのレイアウトは、logback-classic モジュールのレイアウトをそのまま移植しただけです。logback-classic モジュールと logback-access モジュールは用途が違うのですが、だいたい同じ機能を提供しています。

レイアウトを自作する

logback-access 用のレイアウトを自作するのは、logback-classic のレイアウトを自作するのとほとんど変わりありません。

PatternLayout

logback-access のPatternLayoutは、logback-classic とほとんど同じように設定することができます。ですが、HTTPリクエストやHTTPレスポンスにしか無い、ロギングに適した情報のための変換指定が追加されています。

logback-accessのPatternLayoutで使える変換指定を表にまとめました。

logback-accessのPatternLayoutではさらに3つのキーワードが利用できます。これはいわゆるショートカットです。

キーワードcommonは変換文字列パターン'%h %l %u [%t] "%r" %s %b'と同じ意味になります。先頭から順番に、クライアントホスト、リモートログ名、ユーザー名、日時、リクエストURL、ステータスコード、レスポンスのコンテンツ長が出力されます。

キーワードcombinedは変換文字列パターン'%h %l %u [%t] "%r" %s %b "%i{Referer}" "%i{User-Agent}"'のショートカットです。先頭はcommonキーワードの変換パターン文字列とほとんど代わりませんが、referer、user-agent というリクエストヘッダが追加されているのが違います。

HTMLLayout

logback-accessモジュールのHTMLLayoutは、logback-classicモジュールのHTMLLayoutとほとんど変わりません。

デフォルトでは次の項目を含む表を作ります。

• リモートIP
• 日付
• リクエストURL
• レスポンスのステータスコード
• コンテンツ長

logack-accessのHTMLLayoutによる出力例を見てください。

実際に使うと上でもっと良くするにはどうしたらいいでしょうか？log4j.properties for logback translatorは、logback-access のRollingFileAppenderとHTMLLayoutを使ってリアルタイム出力をするようになっています。

Webアプリケーションのtranslatorに対するユーザーからのリクエストに対して、都度新しいアクセスログが出力されます。このリンク先でそれを見ることが出来ます。