James君!〜Avalon Logger の基礎知識

ロガーの構成

さて、ここでは James が使うロガーとその設定について述べる。何かドキュメント類が全然ないものなので、ホントにハックである...が、まあ、Log4j とか判ってりゃ、それほど難解なものではない。まあ、プロで Log4j も知らないというのは今時異常かな?という気もしないわけではないが、もし知らなければ筆者の「Log4J 徹底解説」でも読んでぜひぜひ身につけてくれたまえ。

とはいえ、Avalon のロガーはクラス構成の上からは3段構えだ。簡単にいうと、

  1. org.apache.avalon.framework.loggerパッケージ(avalon-framework-*.jar)。実際に Phoenix 上からロガーを使う(ログ出力する)時に使うインターフェイス。要するに「アプリ上からログする時のインターフェイス」の役割りがこのパッケージである。
  2. org.apache.avalon.excalibur.loggerパッケージ(excalibur-ylogger-*.jar)。これは environment.xml などで指定する Excalibur のインターフェイス。ノリは commons-loggin に近いようで、Log4j のラッパーみたいなこともできるようだ。このパッケージは「environment.xml を読んでロガーを構築する」のが役割りだ。
  3. org.apache.logパッケージ(logkit-*.jar)。こっちはロガーの実装。実際に「具体的にログ出力がどうなるか?」はこのクラスが実装し、他のクラスはそのインターフェイスに過ぎない。

となっていてややこしいが、ここでは excalibur-logger のインターフェイス側を中心に解説する。

environment.xml

今さら言うまでもなくロガーの設定ファイルは SAR-INF/environment.xml である。これの構造は、

<server>
  <logs version="1.1">
     <factories>
       <factory type="aaa" class="***" />
       <factory type="bbb" class="***" />
     </factories>

     <categories>
        <category name="***" log-level="INFO">
            <log-target-id id-ref="XXXX" />
            <log-target-id id-ref="YYYY" />
        </category>
        <category name="***" log-level="INFO">
            <log-target-id id-ref="YYYY" />
        </category>
     </category>

     <targets>
        <aaa id="XXXX">
          <!-- type(aaa) に応じたオプション -->
        </aaa>
        <bbb id="YYYY">
          <!-- type(bbb) に応じたオプション -->
        </bbb>
      </targets>
   </logs>
</server>

という格好のものである。要するに三段構えで、

factories
ターゲット(ロガー実装)とシンボルとを結び付ける
categories
ロガーが呼ばれるカテゴリー(=assembly.xml で定義されたサービス名)に対して、処理(target)を指定する。
targes
ターゲット(ロガー実装)の種別に応じて具体的な処理を指定する

という風な構成になっている。

ターゲットの種別

じゃあ関心があるのは、どういう「ターゲット=ロガー実装」があるのか?ということになろう。以前のページでは「ファイル出力をする org.apache.avalon.excalibur.logger.factory.FileTargetFactory」しか使ってなかったが、これは org.apache.avalon.excalibur.logger.LogTargetFactory インターフェイスを implements した実装クラスなら何でも良い。これには、(すべて org.apache.avalon.excalibur.logger.factory パッケージ内)

AsyncTargetFactory
非同期出力をする。Log4j の AsyncAppender と同様のものである。AsyncAppender 同様、子持のターゲットにする。
ConsoleTargetFactory
標準出力に出力する。Log4j の ConsoleAppender みたいだが、もっと制限されていて System.out にしか出さない。またこれは James 同梱の excalibur-logger-1.0.jar には入っていないので、StreamTargetFactory を使えば十分だ。対象外
DatagramTargetFactory
Log4j 1.3 で追加予定のLog4j の UDPAppender と同様のものである。要するに UDP でネットワーク越しにログを配信する。
FileTargetFactory
ファイルに出力する。どっちか言うと Log4j の DailyRollingFileAppender と同様な日付ベースのログローテーションもすれば、サイズベースのローテーションもする。
JDBCTargetFactory
DBに出力する。Log4j の JDBCAppender に近いが、これは設定ファイルの記述で具体的なDB仕様を決めて出す。
JMSTargetFactory
JMS サーバと通信してログを送る。Log4j の JMSAppender に近いが、Log4j だとTopic にしか出せなかったが、こいつは Queue にも出せる。
LF5TargetFactory
LogFactor5 という Swing ベースのGUIログビューアに出力する。Log4j の LF5Appender と同様のものであるが、最近追加されてたようで、James 同梱の excalibur-logger-1.0.jar には入っていない。対象外
PriorityFileterTargetFactory
Log4j のような Threshold がないので、その代わりにロガーのレベル出力の制限をする。雰囲気は AsyncTargetFactory のような子持ターゲットである。
ServletTargetFactory
これはサーブレット環境で、サーブレットが出すログに従って(javax.servlet.ServletContext#log メソッドを使って)、ログを出すものである。対象外
SMTPTargetFactory
メールで配信する。Log4j の SMTPAppender と同様のものであるが、リングバッファで特に WARN 以上でないと送らない..とかいう仕様はない。
SocketTargetFactory
Log4j の SocketAppender とほぼ同様で、ソケットを通じて TCP で LogEvent オブジェクトを流す。
StreamTargetFactory
Log4j の ConsoleAppender に近いのはこっちの方だ。これは標準出力と標準エラー出力のどっちかを選択できる。

の12種類(うち James で使える/使って意味があるのは9種類)がある。結構 Log4j 並だな。で、これらのターゲットを設定して使うわけだ。

factories タグ

で、これらのロガーを使うためには、当然 environment.xml の factories タグの中で、実装を結び付ける必要がある。たとえば、こんな風だ。

<server>
  <logs version="1.1">
     <factories>
       <factory type="console" 
            class="org.apache.avalon.excalibur.logger.factory.StreamTargetFactory" />
       <factory type="file" 
            class="org.apache.avalon.excalibur.logger.factory.FileTargetFactory" />
     </factories>

でここで factory タグの class 属性は説明不要だが、type 属性は勝手なものを選んで全然問題はない。要するに type 属性は、targets タグ内部の要素としてあらかじめ宣言しておく、というノリである。今 StreamTargetFactory のtype 属性を「console」としたが、それで全然問題はない。

categoriesタグ

では次は categories タグだ。カテゴリーは Log4j よりも不自由で、特に「クラス名ベースで階層カテゴリーにする(べき)」という話は少なくとも Phoenix からの利用では関係ない。Phoenix が勝手に「サービス名」(assembly.xml の block名)から、個々のサービスに対してカテゴリーを設定する。もし、サブカテゴリーを作りたいのならば、

org/apache/james/James.java 865行
    private Logger getMailetLogger() {
        if (mailetLogger == null) {
            mailetLogger = getLogger().getChildLogger("Mailet");
        }
        return mailetLogger;
    }

のように、getLogger()(これはコンテキストの上から「James」のロガー)に対して、ChildLogger() を付け加えなければならない。だから、James の environment.xml では、

      <category name="James.Mailet" log-level="INFO">
        <log-target id-ref="James-Mailet-target"/>
      </category>

のような書き方ができるわけである。

あと、「標準出力とファイルとダブって出力したい...」と思うのは当然だ。これは、単に log-target タグを並べて書けばいいだけだ。

      <category name="SugEcho" log-level="INFO">
        <log-target id-ref="SugEcho-file"/>
        <log-target id-ref="SugEcho-console"/>
      </category>

id-ref 属性は、当然 targets タグの中の各エレメントの id属性と対応させることになる。

targes タグの概要

では、最後のブロックである targes タグの内部はどうなるか?というと、これは factory タグの type 属性で使った名前が、そのまま target タグのエレメント名になる。で、各エレメントには id 属性があって、これが log-target タグの id-ref 属性と対応して、両者を紐づけることになる。

<console id="SugEcho-console">
  <stream>System.out</stream>
  <format>%{xxx:dd/MM/yy HH:mm:ss} %5.5{priority} %{category}: %{message}\n%{throwable}</format>
</console> 

で、各エレメントの中には、実際のターゲット・クラスが要求するプロパティのタグがなくてはならない。それは実装クラスによって全部異なる。各ターゲットに対応したプロパティ・エレメントの説明は次ページ以降で解説する。

フォーマット

とはいえ、多くのターゲットは共通したターゲットのオプションとして、「format」タグを使うのでまずこれはここで説明しよう。フォーマットはLog4j のレイアウトと同様なもので、出力フォーマットを指定する。たとえばこんな風だ。

<console id="echoservice-stdout">
  <stream>System.out</stream>
  <format>%{time:dd/MM/yy HH:mm:ss} %5.5{priority} %{category}: %{message}\n%{throwable}</format>
 

そうすると出力結果は、

12/12/05 15:40:21 INFO  EchoService: SugTest initialize...
12/12/05 15:40:21 INFO  EchoService: SugTest port=2599 connect 1-30

みたいな感じになる。要するに「%{xxx}」の部分がログの要素に展開されるわけである。じゃあ、どういうログ要素があるのか、というのを一覧しよう。これは実はログ実装の方なので、org.apache.log.format.PatternFormatter に記述がある。一般形は、

%[+|-][#[.#]]{field:subformat}

ということになり、

+|-
「+」=左寄せ、「-」=右寄せ
#[.#]
最小桁数.最大桁数
field
各ログ要素指定
subformat
ログ要素ごとのサブフォーマット指定

というかたちになる。ログ要素には次のものがある。実際のログのクラスは org.apache.log.LogEvent クラスで、以下の要素に対応したゲッタ/セッタが用意されている。

category
カテゴリー名
message
メッセージ
time
ログ発生時間。サブフォーマットとして Date 出力のフォーマットがある。
rtime
ログが発生した、起動時点からの相対時間(ミリ秒)
throwable
例外を引数として与えていれば、スタックトレース
priority
ログレベル
thread
発生スレッド
context
これはどうやら MDC みたいな Map 形式のもののようだ。「マップされた診断コンテキスト」というロギング・デザインパターンである。サブフォーマットとしてマップのキーを指定できる...が、どうも avalon-framework が提供するラッパー(James/Phoenix アプリが使う)では、context を設定するインターフェイスが用意されていないようである。

まあ、これらについての細かい説明は不要だろう。実際に使ってみて確認してほしい。

ロガー・インターフェイス

では、具体的なターゲットの説明に入る前に、Phoenix ベースのシステムのアプリ上からどうロガーを呼び出すのか、という話をしておこう。実際には Avalon には org.apache.avalon.framework.logger.AbstractLogEnabled という「ロガーを利用するための基底クラス」がある。だから、これを任意の Avalon コンポーネントの基底クラスとして使っているケースが多いようだ。AbstractLogEnabled 継承クラスからは、

public org.apache.avalon.framework.logger.Logger getLogger();

で適切なロガーを取得できる(通常 org.apache.avalon.framework.logger.LogKitLogger。これはorg.apache.log.Logger のラッパー)。で、これに対して、ログ取りのメソッドを呼び出す。ログ取りメソッドはログレベルに対応して5レベル(debug, info, warn, error, fatalError)あり、それぞれ String だけを引数に取るログ取りメソッドと、例外を渡せる2引数のログ取りメソッド、加えて「ログレベル的に利用可能か」どうかを問い合わせるメソッドが定義されている。ただし、log( String level, String message ); といった汎用的なログ取りメソッドは用意されていない。

void debug(String message);
void debug(String message, Throwable throwable);
boolean isDebugEnabled();

void info(String message);
void info(String message, Throwable throwable);
boolean isInfoEnabled();

void warn(String message);
void warn(String message, Throwable throwable);
boolean isWarnEnabled();

void error(String message);
void error(String message, Throwable throwable);
boolean isErrorEnabled();

void fatalError(String message);
void fatalError(String message, Throwable throwable);
boolean isFatalErrorEnabled();

で、こいつらを適切に呼べばいいわけだ。...まあ、そんな設計ということは、どこかいじると LogKit じゃなくて Log4j とか JDK14Logger とかを使えるようになりそうだが、これは実際にはかなり厄介だ。後で Log4j をロガーとして使うやり方を説明する。



copyright by K.Sugiura, 1996-2006