Log4J徹底解説

JDBCAppender

目次

いろいろあるもんだ!

JDBCAppender とは、その名の通り JDBCドライバを使ってデータベースと通信し、データベースにログを保存するという Appender である。しかし、どうやらそもそもこれはコントリビューション出身のようで、作者もメイン作者の Ceki Gülcü 氏ではなくて、Kevin Steppe 氏である(いくつかこういう Appender が他にもある)。ドキュメンテーションの plan.htm によると、2つの JDBCAppender があったが、そのうち Steppe氏のものが採用されたような雰囲気のことが書いてある。が、しかし、どうやら Gulcu 氏は気に入らなかったみたいだね。こんなコメントがソースに入っている。

WARNING: This version of JDBCAppender
is very likely to be completely replaced in the future. Moreoever,
it does not log exceptions.
(警告:このバージョンの JDBCAppender は、将来完全に書き換えられる。なぜならこれは例外をログできない!)

とある(さらに言うと、コメントの入り方が他のソースと比較して手抜きで、JavaDoc API リストの情報が薄いぞ...おいおい!)。で、1.3 で登場したのが org.apache.log4j.db.DBAppender だ。

JDBCAppender が「JDBCドライバを通じてデータベースにアクセスする」ことを目的としていたのに対して、DBAppender は「データベースにログを保存する!」ということに正面から取り組んでいる。言い替えれば、JDBCAppender が「ユーザ定義のテーブルにログを保存する(とはいえ複数行に渡りかねない「例外」は無理)」というノリで書かれた軽量の Appender だったのに対して、DBAppender は「Log4J で決めたフォーマットによる、3つのテーブルに対してログを統一的に保存する!」という重量級のアプローチである。だから、1.3 になっても「JDBCAppender の方が楽だ!」という奴はきっといるようなものだ。その他にも「重量級」なところがいろいろあるが、それは DBAppender の解説の方でじっくりやろう。
(1.3 で登場した他の Appender なんかはこっちだ)

で、1.3-alpha-8 なんだが、JDBCAppender が入っていない....どうもこれは廃止の憂き目にあう予定のようだ。これを使って既存DBがあるようなユーザから文句がでそうな気がするんだが...

jdbc.JDBCAppender

とはいえ 1.3 はまだアルファだ。現行版の 1.2 系で採用されている JDBCAppender をまず解説するのが筋ってもんだろう。こいつはこういうプロパティを持っている。JDBCを使ったことがあれば、大体常識的なものだが、JavaDoc APIリストで拾われるコメントが手抜きなので、ちょっと面食らう。まあ、それでもソースを確認して拾ってみよう。

Driver
使うJDBCドライバを指定する
URL
データベースのURLを指定する
User
データベースを利用するためのアカウント名を指定する
Password
アカウント名に対応するパスワードを指定する
BufferSize
接続を効率化するために、バッファに貯めておいてバッファが満杯になったらデータベースに書き出す、という動作ができる。貯めておく数がこのオプションである。デフォルトは1で、特にキャッシュせずに即刻データベースに書き出す。
Sql
さて、データベースに書き出すと言っても....(後述)
Threshold
(AppenderSkeltonから継承)

ここで Sql オプションがあるんだが、この JDBCAppender が実際にどういう動作をするのか、をちょっと解説しよう。要するにこれは低レベルなクライアントなのである。だから、SQLサーバに接続するところまではこの Appender で面倒を見るが、その後の「どういうテーブルにどんなデータを INSERT して..」という辺りのSQLコマンドは、単に LoggingEvent をフォーマットする PatternLayout を使ってやるのである。そりゃテーブルの構成がどうなってるかなんて、O/Rマッピングツールじゃないんだから、そんなもん知らんぞ。SQLオプションは、Appdender が使う PatternLayout の ConversionPattern に相当する文字列を、このオプションで設定された文字列で置き換えることしかしない。だからこんなオプションを使うよりも、ConversionPattern で指定した方がずっと見通しがよい。設定例はこんなところだ(ここではMySQLでSJIS を使う)。

log4j.appender.jdbc=org.apache.log4j.jdbc.JDBCAppender
log4j.appender.jdbc.URL=jdbc:mysql://127.0.0.1/log4j?useUnicode=true&characterEncoding=SJIS
log4j.appender.jdbc.user=root
log4j.appender.jdbc.password=
log4j.appender.jdbc.driver=org.gjt.mm.mysql.Driver
log4j.appender.jdbc.bufferSize=1
log4j.appender.jdbc.layout=org.apache.log4j.PatternLayout
# ConversionPattern は言うまでもなく1行!
log4j.appender.jdbc.layout.ConversionPattern=INSERT INTO log 
  VALUES ('%d{yyyy-MM-dd HH:mm:ss}', '%-5p', '%c{1}', '%m' )

log4j.rootLogger=debug, stdout, jdbc

まあ当然、MySQL の側でこんな感じであらかじめテーブルを作っておく必要があることは、言うまでもない。

create database log4j;
use log4j;
create table log ( 
  date TIMESTAMP, 
  level VARCHAR(5), 
  category VARCHAR(128), 
  message VARCHAR(255) );

要するにこれは単なる JDBC 使いに過ぎないから、JDBC ドライバがあればどんなデータベースだって利用可能である。まあ、ご利用の際は JDBCドライバをクラスパスに含めることをお忘れなく。

db.DBAppender

さて、DBAppender は重量級アプローチの方だ。まあ、そういうものなので、単に「INSERT文を発行して...」とかじゃ済まない処理がちょっとあったりする。だから、山のように種類があるデータベース、方言も多種多様なデータベースに対応するために、org.apache.log4j.db.dialect.* にデータベースの名前がついたクラスがあるが、それを見ると現在対応しているデータベースが判る。MySQL, PostgreSQL, MsSQL, Oracle, DB2, HSQL とメジャーところは大概対応している。このうち JBoss についてくるのでメジャー化した Pure Java RDBMS である HSQL にまで対応しているあたりが、いじましい。

実は 1.3 では新しく org.apache.log4j.joran.JoranConfigurator という設定ファイルをパースする Configurator が登場し、今までの DOMConfigurator はお払い箱になった模様である。で、この JoranConfigurator でないと、DBAppender用の log4j.xml がパースできない。まあ、この JoranConfigurator はよく出来ていて、 DOM ベースで処理のダサい DOMConfigurator の替りに、SAX ベースで XPath で指定するエレメントに任意のハンドラを加えて、それで設定ファイルをパースしちゃおうというものである。

DBAppender の設定ファイル

Joran の特に面白いのは一種のマクロ展開機能が付与されたことである。つまり、外部のプロパティファイルを拾って、そのプロパティファイルの定義を変数のように使うことができるのである。だから、次のように log4j.xml に準じて、JoranConfigurator().doConfigure() に渡す joran.xml を書くことになる。置換される対象指定の「${プロパティ名}」なんて記法は ant みたいである。

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration>
<log4j:configuration debug="true">
  <substitutionProperty file="mysql.properties"/>
  <appender name="DB" class="org.apache.log4j.db.DBAppender">
   <param name="locationInfo" value="true"/>
   <connectionSource class="org.apache.log4j.db.DriverManagerConnectionSource">
     <param name="driverClass" value="${driverClass}"/>
     <param name="url" value="${url}"/>
     <param name="user" value="${user}"/>
     <param name="password" value="${password}"/>
   </connectionSource>
  </appender>

  <logger name="jp.or.nurs.sug.log4j.test">
    <level value ="debug"/>
    <appender-ref ref="DB" />
  </logger>  
</log4j:configuration>

新しい要素は <connectionSource> である。これは接続ソースクラスを指定して、ここでドライバ名などの接続プロパティを指定する。で、この接続プロパティは、<substitutionProperty> 要素によって指定されるファイル(ここでは mysql.properties)に書かれている、という寸法だ。じゃ、mysql.properties はこんなもんだ。

driverClass=com.mysql.jdbc.Driver
dataSourceClass=com.mysql.jdbc.jdbc2.optional.MysqlDataSource
pooledDataSourceClass=com.mysql.jdbc.jdbc2.optional.MysqlConnectionPoolDataSource
url=jdbc:mysql://127.0.0.1/log4j?useUnicode=true&characterEncoding=SJIS
user=root
password=

ということは、MySQL のドライバも MySQL が提供している新しい奴が要ることになる。「MySQL Connector/J」というシリーズだ(mm.mysql〜とかいう奴じゃ駄目だ)。開発元のhttp://www.mysql.com/ から落とされると良かろう。まあ、こいつらを使ってやるわけだから、次のようなコマンドで利用できることになる。

% java -classpath .;log4j-1.3alpha.jar;mysql-connector-java-3.0.15-ga.jar \
         jp.or.nurs.sug.log4j.test.TestLog4j

そうするとプログラム内で指定したように、joran.xml が JoranConfigurator によってパースされて、mysql.properties を取り込みながら正しく DBAppender を設定してくれる。

データベース側の用意

が、これだけじゃまだダメだ。そりゃそうだ。まだデータベース側でログを格納するテーブルをまだ作っていない。現状の log4j-1.3alpha.jar には一緒に入ってないが、多分フルパッケージには、src/java/org/apache/log4j/db/dialect の中に mysql.sql というような名前で各DBに応じたテーブル生成SQLが格納されるんじゃないかと思う。MySQL の場合にはこうだ。

BEGIN;
DROP TABLE IF EXISTS logging_event_property;
DROP TABLE IF EXISTS logging_event_exception;
DROP TABLE IF EXISTS logging_event;
COMMIT;

BEGIN;
CREATE TABLE logging_event 
  (
    sequence_number   BIGINT NOT NULL,
    timestamp         BIGINT NOT NULL,
    rendered_message  TEXT NOT NULL,
    logger_name       VARCHAR(254) NOT NULL,
    level_string      VARCHAR(254) NOT NULL,
    ndc               TEXT,
    thread_name       VARCHAR(254),
    reference_flag    SMALLINT,
    caller_filename   VARCHAR(254) NOT NULL,
    caller_class      VARCHAR(254) NOT NULL,
    caller_method     VARCHAR(254) NOT NULL,
    caller_line       CHAR(4) NOT NULL,
    event_id          INT NOT NULL AUTO_INCREMENT PRIMARY KEY
  );
COMMIT;

BEGIN;
CREATE TABLE logging_event_property
  (
    event_id          INT NOT NULL,
    mapped_key        VARCHAR(254) NOT NULL,
    mapped_value      TEXT,
    PRIMARY KEY(event_id, mapped_key),
    FOREIGN KEY (event_id) REFERENCES logging_event(event_id)
  );
COMMIT;

BEGIN;
CREATE TABLE logging_event_exception
  (
    event_id         INT NOT NULL,
    i                SMALLINT NOT NULL,
    trace_line       VARCHAR(254) NOT NULL,
    PRIMARY KEY(event_id, i),
    FOREIGN KEY (event_id) REFERENCES logging_event(event_id)
  );
COMMIT;

まあ、これを見れば「3つのテーブルを使って...」の意味が判るだろうと思う。要するに、特に面倒ではない範囲でのログが「logging_event」テーブルに、例外が「logging_event_exception」テーブルに(複数行あるわけだから、「1対多」を FOREIGN KEY と i とでうまく格納している)、「logging_event_property」テーブルは「MDC」として使うプロパティ形式の追加情報用に作られているわけなのだ。まあ、個々のフィールド名はログ要素に当然対応しているので、見れば判ると思う。

適当にDBのコマンドライン・インターフェイスを起動して、ファイルを読み込むなりしてテーブルを作ってやってくれ。MySQL だとこんなところか。

% mysql -u root
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 15 to server version: 4.0.20a-nt

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.
mysql> create database log4j;
Query OK, 1 row affected(0.00 sec)
mysql> use log4j;
Database changed
mysql> source mysql.sql
Query OK, 0 rows affected(0.00 sec)
................

これで準備完了。あとはテストプログラムを起動するだけだ。うまくいったかな? DBのコマンドラインクライアントから確認でもしてくれたまえ。うまくいかないケースは多分 DBユーザの指定だろうから、GRANT が必要ならば忘れないようにね。

DBAppender のストラテジ

でだ、今はごく簡単にDBアクセスをするために直接SQLドライバを指定するやり方でやってみたのだが、今時の話で DataSource を使ってやれたら...とか JNDI で参照して...とかいうニーズもあるわけである。というわけで、この DBAppender では、「単にDriverManagerConnectionSource だけでリソースを指定する」というやり方しか出来ない分けではないのである。要するにこれも「Strategy」で、その他のやり方も用意されているわけだ。そのための interface が org.apache.log4j.db.ConnectionSource であり、これを implements した基底クラスとして org.apache.log4j.db.ConnectionSouceSkelton が用意されていて、次のクラス構成になっている。(すべて org.apache.log4j.db パッケージなので、パッケージ名は省略)

               +----------------+
               |ConnectionSource|
               +----------------+
                        ^
                        |
            +-------------------------+
            | ConnectionSourceSkelton |
            +-------------------------+
              ^          ^           ^
              |          |           |
        +----------++----------++----------+
        |DataSource||  Driver  ||   JNDI   |
        |Connection||  Manager ||Connection|
        |  Source  ||Connection||  Source  |
        +----------+|  Source  |+----------+
                    +----------+

既に見た「DriverManagerConnectionSource」は普通のJDBC使いのように、log4j.xml の中にドライバなどを記述してリソースを取得するストラテジだが、DataSourceConnectionSource は既存の DataSource を与えるものであるし、JNDIConnectionSource は JNDI 経由で DataSource を取得するものだ。これらは DriverManagerConnectionSource 同様に指定ができる。

JNDIConnectionSource の場合、

    <connectionSource class="org.apache.log4j.db.JNDIConnectionSource">
        <param name="jndiLocation" value="JNDI名" />
    </connectionSource>

のようにして、正しい JNDIサーバをルックアップするようにすれば DB のデータソースが参照できるようになる。まあ、これは Tomcat みたいな J2EEサーバから使うためのものである。

で、ここでちょいと述べておこう。いろいろとテストしたが、オープンソース EJB サーバで有名な JBoss は、現状では log4j-1.3 には対応できていない。まあ、JBoss はデフォルトのロガーとして Log4j を使うとか、結構 Log4j をハックして使っているので、どうしてもこういう大変更には追随しにくいわけだ。JBoss だと、lib ディレクトリに新しいライブラリを放りこんで...というわけにはいかない。

とはいえ、Tomcat は Log4j のことなぞ全然知らないサーバなので、アプリケーションレベルで対応することができる。例えば、JNDIConnectionSource を使って、Servlet のログを DB に出す方法は次の通りだ。ここらへん管理ツールを使うとかで出来ることだ。

  1. まずグローバルなリソースを定義する。要するにデータソースとそれを参照する JNDI 名とを結びつけるわけだ。server.xml の記述はこういう具合になる。
    <?xml version='1.0' encoding='utf-8'?>
    <Server>
      .....
      <GlobalNamingResources>
        <!-- JNDI参照名は jdbc/log4jdb -->
        <Resource name="jdbc/log4jdb" type="javax.sql.DataSource"/>
        <ResourceParams name="jdbc/log4jdb">
          <parameter>
            <name>url</name>
            <value>jdbc:mysql://127.0.0.1/log4j?useUnicode=true</value>
          </parameter>
          <parameter>
            <name>password</name>
            <value></value>
          </parameter>
          <parameter>
            <name>maxActive</name>
            <value>4</value>
          </parameter>
          <parameter>
            <name>maxWait</name>
            <value>5000</value>
          </parameter>
          <parameter>
            <name>driverClassName</name>
            <value>com.mysql.jdbc.Driver</value>
          </parameter>
          <parameter>
            <name>username</name>
            <value>sug</value>
          </parameter>
          <parameter>
            <name>maxIdle</name>
            <value>2</value>
          </parameter>
        </ResourceParams>
        .......
    
  2. で、次は実際に Log4j のログを取る Webアプリ(Context)の側の指定である。要するにその Webアプリの側で、グローバルな JNDI 名を参照することをあらかじめ宣言しておく必要がある。これは、${CATALINA_HOME}/conf/Catalina/localhost/WebApp名.xml に記述されることになるものだ。
    <?xml version='1.0' encoding='utf-8'?>
    <Context docBase="sug" path="/sug" workDir="work/Catalina/localhost/sug">
      <ResourceLink global="jdbc/log4jdb" name="jdbc/log4jdb" type="javax.sql.DataSource"/>
    </Context>
    
  3. log4j.xml はこんな感じだ。これは ${CATALINA_HOME}/webapps/WebApp名/WEB-INF/classes に設置しておくのが良いだろう。
    <?xml version="1.0" encoding="UTF-8" ?>
    <log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" >
      <appender name="stdout" class="org.apache.log4j.ConsoleAppender">
         <param name="Target" value="System.out" /> 
         <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d %5p %c - %m%n" />
         </layout>
      </appender>
    
      <appender name="db" class="org.apache.log4j.db.DBAppender">
       <param name="locationInfo" value="true"/>
        <connectionSource class="org.apache.log4j.db.JNDIConnectionSource">
            <param name="jndiLocation" value="java:comp/env/jdbc/log4jdb" />
        </connectionSource>
      </appender>
    
      <logger name="jp.or.nurs.sug.log4j.test" >
        <level value ="info" />
        <appender-ref ref="db" />
      </logger>  
    </log4j:configuration>
    

    ここでのポイントは、JndiLocation オプションの値だ。Tomcat の側で指定したのは、「jdbc/log4jdb」だが、オプションの値としては「java:comp/env/jdbc/log4jdb」にしたまえ。まあ、これは Tomcat での JNDI の使い方の問題なので、とやかく言わないが、こういうことだ。

    ちなみにあともう一つだけ「Joran Hacks(1.3)」に、JNDI を使い倒す話があるので深めたい方はこっちも見てくれ。

    だが、DataSourceConnectionSource は、適当な javax.sql.DataSource 継承クラスを作って、ちょいと実験してみたが、どうも SQLDialect の問題で「どのDBを使っているのか?」がうまく拾い出せずに失敗する模様である...ふう。確かに DataSource継承クラスには「どのDBか?」を判別するためのインターフェイスなんてないわけだ。ちょっと設計上の不整合が起きているようだな。



    copyright by K.Sugiura, 1996-2006