log4j 設定

職場で、「log4jの設定が良くわからない」ときかれたので、自分なりにまとめておこう。
log4jを使ってきた経験のまとめ。

http://logging.apache.org/log4j/

あらためて調べてみれば、Java以外に、.NET, PHP版もあったのか。

Apache log4j 1.2 -

Java版はここ。

Apache Download Mirrors

ダウンロード。jarやソースコードも込み。設定ファイル(プロパティファイル, XML)の例も含まれている。

ドキュメント

log4jは、はじめてのひとにはとっつきにくいとおもう。概念やら仕組みやらをおさえるのがなかなかむずかしい。

検索すると、多数ヒットするわりには、入門向けにとっつきやすいドキュメントやチュートリアルにたどりつけない。Javaで開発するひとたちにとっては、あたりまえで、長く使われているものでもあるので、逆に、経験者向けのドキュメントが、検索で上位になってしまうんだろうか。

自分が、繰り返し参照させてもらっているのは以下のサイトか。

Apache log4j 1.2 - Short introduction to log4j

Log4J徹底解説〜目次

Overview (Apache Log4j 1.2.17 API)
設定ファイルのパラメータがわからないとき、Javadocの、該当すると思われるクラスを見るとわかることがある。
PatternLayout (Apache Log4j 1.2.17 API)
とかさ。

log4jの構成

log4jは、ログ＝ログファイルというイメージだと理解しづらい。

ログのメッセージとログの出力先は、概念的に分かれている。

log4jの構成でおさえる必要があるのは、以下の３つ。

Logger

ロガー
あるログレベルのログメッセージを出力する。実際の出力先は、Appenderで決まる。Javadocを見るとLogger (Apache Log4j 1.2.17 API)なんだけど、これは、Category (Apache Log4j 1.2.17 API)という「なんでロガーなのにカテゴリーなの？」というクラスを継承している。log4jのロガーは、(Javaのパッケージには親子関係はないけど、)Javaのパッケージにあわせた階層構造をもつことができて、設定ファイルでは、パッケージとその配下のパッケージ単位で、ロガーに設定を与えることができる。この階層をカテゴリーと表現しているようだ。

Appender

ログの出力先
Appender (Apache Log4j 1.2.17 API)
Javadocを見るとAppenderは、コンソール、ファイル以外にも、SMTP(たとえば、エラー発生時にメールを飛ばすために使ったことがある), JDBC, syslog(これは、syslogサーバに送信する)だのさまざま。

Layout

ログの出力時のフォーマット
こいつも良く忘れる。log4j.propertiesに書いてある
%t %c#%M %p %m%nこんなやつ。忘れたら、「log4j layout」で検索。
PatternLayout (Apache Log4j 1.2.17 API)
log4jリファレンス（layout）

加えて、実際の作業では、やっぱりこいつが一番必要。

設定ファイル

log4j.properties

ほかに知っておく必要があるのは、

• ログレベル
  • http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/Level.html
  • OFF
  • FATAL
  • ERROR
  • WARN
  • INFO
  • DEBUG
  • TRACE
  • ALL
• 階層構造（ロガーの親子関係、設定が継承？される）
  • 下記のソースコードの実行例を参照

とかだろうか。

設定ファイル

自分は、log4jの設定ファイルについては、何年もの間、ちょこっと調べては忘れるを繰り返している。いつも実装がはじまるタイミングで書いて、それっきりだからなあ。

• 書式
  • プロパティファイル
  • XMLファイル
• 置き場所
  • log4j.properties(log4j.xml)をクラスパス直下へおいておく。
    Eclipseでテストするのであれば、src直下とかビルドパスをとおしたディレクトリへおいておけば、勝手にクラスパスのとおったディレクトリにコピーされる。
  • javaコマンドのオプションとして、システムプロパティとしてファイルパスを与える。
    java -Dlog4j.configuration=file:///xxxx/yyyy/my-log4j-config.properties
    シェルスクリプトから呼ぶなら、これかな。うえのやりかたかな？
  • 実装から呼ぶのもありか
    PropertyConfigurator.configure("/xxxx/yyyy/my-log4j-config.properties");

例

log4jをダウンロードして、解凍する。配下のディレクトリを*.xmlとか*.propertiesで検索するといくつか見つかる。

log4j.propertiesの例

apache-log4j-1.2.16/examples

log4j.xmlの例

apache-log4j-1.2.16/src/main/javadoc/org/apache/log4j/xml/examples/doc-files
これはDTD
apache-log4j-1.2.16/src/main/resources/org/apache/log4j/xml/log4j.dtd

動作確認

log4jの動作を確認してみる。

ソースコードの準備

動作確認のため、Javaのパッケージとして以下の5つ用意している。

• note.log4j.a
• note.log4j.a.a
• note.log4j.a.a.a
• note.log4j.b
• note.log4j.c

package note.log4j.a;

import org.apache.log4j.Logger;

public class ExampleAAction {

    private final static Logger logger = Logger.getLogger(ExampleAAction.class);

    public void doAction() {
        logger.info("開始");
        logger.warn("微妙です。");
        logger.debug("test data");
        logger.info("終了");
    }

}

package note.log4j.a.a;

import org.apache.log4j.Logger;

public class ExampleAaAction {

    private final static Logger logger = Logger.getLogger(ExampleAaAction.class);

    public void doAction() {
        logger.info("開始");
        logger.warn("微妙です。");
        logger.debug("test data");
        logger.info("終了");
    }

}

package note.log4j.a.a.a;

import org.apache.log4j.Logger;

public class ExampleAaaAction {

    private final static Logger logger = Logger.getLogger(ExampleAaaAction.class);

    public void doAction() {
        logger.info("開始");
        logger.warn("微妙です。");
        logger.debug("test data");
        logger.info("終了");
    }

}

package note.log4j.b;

import org.apache.log4j.Logger;

public class ExampleBAction {

    private static final Logger logger = Logger.getLogger(ExampleBAction.class);

    public void doAction() {
        logger.info("開始");
        logger.warn("微妙です。");
        logger.debug("test data");
        logger.info("終了");
    }

}

package note.log4j.c;

import org.apache.log4j.Logger;

public class ExampleCAction {

    private static final Logger logger = Logger.getLogger(ExampleCAction.class);

    public void doAction() {
        logger.info("開始");
        logger.warn("微妙です。");
        logger.debug("test data");
        logger.info("終了");
    }

}

最小？の設定ファイル

loggerは、

• rootLogger

のみ。
ふつうは、パッケージ単位のloggerを設定するけど、一応最小？ということで。

minimum-log4j.properties

log4j.debug=false

log4j.rootLogger=INFO, Console
log4j.appender.Console=org.apache.log4j.ConsoleAppender

log4j.appender.Console.layout=org.apache.log4j.PatternLayout

log4j.appender.Console.layout.ConversionPattern=%t %c#%M %p %m%n

package note.log4;

import note.log4j.a.ExampleAAction;
import note.log4j.a.a.ExampleAaAction;
import note.log4j.a.a.a.ExampleAaaAction;
import note.log4j.b.ExampleBAction;

import org.apache.log4j.PropertyConfigurator;
import org.junit.Test;


public class MnimumConfigLoggerTest {

    @Test
    public void testMinimum() {
        PropertyConfigurator.configure("conf/minimum-log4j.properties");

        doActions();
    }

    private void doActions() {
        ExampleAAction a = new ExampleAAction();
        a.doAction();
        ExampleAaAction aa = new ExampleAaAction();
        aa.doAction();
        ExampleAaaAction aaa = new ExampleAaaAction();
        aaa.doAction();
        ExampleBAction b = new ExampleBAction();
        b.doAction();
        ExampleCAction c = new ExampleCAction();
        c.doAction();
    }

}

を実行すると、

main note.log4j.a.ExampleAAction#doAction INFO 開始

main note.log4j.a.ExampleAAction#doAction WARN 微妙です。

main note.log4j.a.ExampleAAction#doAction INFO 終了

main note.log4j.a.a.ExampleAaAction#doAction INFO 開始

main note.log4j.a.a.ExampleAaAction#doAction WARN 微妙です。

main note.log4j.a.a.ExampleAaAction#doAction INFO 終了

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 開始

main note.log4j.a.a.a.ExampleAaaAction#doAction WARN 微妙です。

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 終了

main note.log4j.b.ExampleBAction#doAction INFO 開始

main note.log4j.b.ExampleBAction#doAction WARN 微妙です。

main note.log4j.b.ExampleBAction#doAction INFO 終了

main note.log4j.c.ExampleCAction#doAction INFO 開始

main note.log4j.c.ExampleCAction#doAction WARN 微妙です。

main note.log4j.c.ExampleCAction#doAction INFO 終了

パッケージ単位で、loggerを設定してみる

loggerは、

• log4j.rootLogger
• log4j.logger.note.log4j.a

を指定

log4j.debug=false

log4j.rootLogger=INFO, Console
log4j.logger.note.log4j.a=INFO, Console
log4j.appender.Console=org.apache.log4j.ConsoleAppender

log4j.appender.Console.layout=org.apache.log4j.PatternLayout

log4j.appender.Console.layout.ConversionPattern=%t %c#%M %p %m%n

package note.log4;

import note.log4j.a.ExampleAAction;
import note.log4j.a.a.ExampleAaAction;
import note.log4j.a.a.a.ExampleAaaAction;
import note.log4j.b.ExampleBAction;
import note.log4j.c.ExampleCAction;

import org.apache.log4j.PropertyConfigurator;
import org.junit.Test;


public class ALoggerTest {

    @Test
    public void testTree() {
        PropertyConfigurator.configure("conf/a-log4j.properties");

        doActions();
    }

    private void doActions() {
        ExampleAAction a = new ExampleAAction();
        a.doAction();
        ExampleAaAction aa = new ExampleAaAction();
        aa.doAction();
        ExampleAaaAction aaa = new ExampleAaaAction();
        aaa.doAction();
        ExampleBAction b = new ExampleBAction();
        b.doAction();
        ExampleCAction c = new ExampleCAction();
        c.doAction();
    }

}

を実行すると、

main note.log4j.a.ExampleAAction#doAction INFO 開始

main note.log4j.a.ExampleAAction#doAction INFO 開始

main note.log4j.a.ExampleAAction#doAction WARN 微妙です。

main note.log4j.a.ExampleAAction#doAction WARN 微妙です。

main note.log4j.a.ExampleAAction#doAction INFO 終了

main note.log4j.a.ExampleAAction#doAction INFO 終了

main note.log4j.a.a.ExampleAaAction#doAction INFO 開始

main note.log4j.a.a.ExampleAaAction#doAction INFO 開始

main note.log4j.a.a.ExampleAaAction#doAction WARN 微妙です。

main note.log4j.a.a.ExampleAaAction#doAction WARN 微妙です。

main note.log4j.a.a.ExampleAaAction#doAction INFO 終了

main note.log4j.a.a.ExampleAaAction#doAction INFO 終了

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 開始

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 開始

main note.log4j.a.a.a.ExampleAaaAction#doAction WARN 微妙です。

main note.log4j.a.a.a.ExampleAaaAction#doAction WARN 微妙です。

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 終了

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 終了

main note.log4j.b.ExampleBAction#doAction INFO 開始

main note.log4j.b.ExampleBAction#doAction WARN 微妙です。

main note.log4j.b.ExampleBAction#doAction INFO 終了

main note.log4j.c.ExampleCAction#doAction INFO 開始

main note.log4j.c.ExampleCAction#doAction WARN 微妙です。

main note.log4j.c.ExampleCAction#doAction INFO 終了

パッケージ

• note.log4j.a
• note.log4j.a.a
• note.log4j.a.a.a

に対して、2重にログを出力している

これは、
log4j.logger.note.log4j.a
がログを、自分のAppenderだけでなく、
rootLoggerのAppender
へも送っているかららしい。

rootLoggerとlog4j.logger.note.log4j.aには親子関係があり

• 親ロガー rootLogger
• 子ロガー log4j.logger.note.log4j.a

親のAppenderにもログを送るらしい。

Apache log4j 1.2 - Short introduction to log4j
のAppenders and Layouts

ためしに、

log4j.debug=false

log4j.rootLogger=INFO, Console
log4j.logger.note.log4j.a=INFO, Console

log4j.logger.note.log4j.a.a=INFO, Console

log4j.logger.note.log4j.a.a.a=INFO, Console
log4j.appender.Console=org.apache.log4j.ConsoleAppender

log4j.appender.Console.layout=org.apache.log4j.PatternLayout

log4j.appender.Console.layout.ConversionPattern=%t %c#%M %p %m%n

package note.log4;

import note.log4j.a.ExampleAAction;
import note.log4j.a.a.ExampleAaAction;
import note.log4j.a.a.a.ExampleAaaAction;
import note.log4j.b.ExampleBAction;
import note.log4j.c.ExampleCAction;

import org.apache.log4j.PropertyConfigurator;
import org.junit.Test;


public class AAALoggerTest {

    @Test
    public void testTree() {
        PropertyConfigurator.configure("conf/aaa-log4j.properties");

        doActions();
    }

    private void doActions() {
        ExampleAAction a = new ExampleAAction();
        a.doAction();
        ExampleAaAction aa = new ExampleAaAction();
        aa.doAction();
        ExampleAaaAction aaa = new ExampleAaaAction();
        aaa.doAction();
        ExampleBAction b = new ExampleBAction();
        b.doAction();
        ExampleCAction c = new ExampleCAction();
        c.doAction();
    }

}

を実行すると、

main note.log4j.a.ExampleAAction#doAction INFO 開始

main note.log4j.a.ExampleAAction#doAction INFO 開始

main note.log4j.a.ExampleAAction#doAction WARN 微妙です。

main note.log4j.a.ExampleAAction#doAction WARN 微妙です。

main note.log4j.a.ExampleAAction#doAction INFO 終了

main note.log4j.a.ExampleAAction#doAction INFO 終了

main note.log4j.a.a.ExampleAaAction#doAction INFO 開始

main note.log4j.a.a.ExampleAaAction#doAction INFO 開始

main note.log4j.a.a.ExampleAaAction#doAction INFO 開始

main note.log4j.a.a.ExampleAaAction#doAction WARN 微妙です。

main note.log4j.a.a.ExampleAaAction#doAction WARN 微妙です。

main note.log4j.a.a.ExampleAaAction#doAction WARN 微妙です。

main note.log4j.a.a.ExampleAaAction#doAction INFO 終了

main note.log4j.a.a.ExampleAaAction#doAction INFO 終了

main note.log4j.a.a.ExampleAaAction#doAction INFO 終了

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 開始

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 開始

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 開始

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 開始

main note.log4j.a.a.a.ExampleAaaAction#doAction WARN 微妙です。

main note.log4j.a.a.a.ExampleAaaAction#doAction WARN 微妙です。

main note.log4j.a.a.a.ExampleAaaAction#doAction WARN 微妙です。

main note.log4j.a.a.a.ExampleAaaAction#doAction WARN 微妙です。

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 終了

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 終了

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 終了

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 終了

main note.log4j.b.ExampleBAction#doAction INFO 開始

main note.log4j.b.ExampleBAction#doAction WARN 微妙です。

main note.log4j.b.ExampleBAction#doAction INFO 終了

main note.log4j.c.ExampleCAction#doAction INFO 開始

main note.log4j.c.ExampleCAction#doAction WARN 微妙です。

main note.log4j.c.ExampleCAction#doAction INFO 終了

log4j.logger.note.log4j.a.a.a
は、自分だけでなく
log4j.rootLogger
log4j.logger.note.log4j.a
log4j.logger.note.log4j.a.a
のAppenderにもログ出力していることがわかる。

これを解除するには、additivityを指定する。
log4j.additivity.note.log4j.a=false

additivity-log4j.properties

log4j.debug=false

log4j.rootLogger=INFO, Console
log4j.logger.note.log4j.a=INFO, Console

log4j.additivity.note.log4j.a=false
log4j.appender.Console=org.apache.log4j.ConsoleAppender

log4j.appender.Console.layout=org.apache.log4j.PatternLayout

log4j.appender.Console.layout.ConversionPattern=%t %c#%M %p %m%n

package note.log4;

import note.log4j.a.ExampleAAction;
import note.log4j.a.a.ExampleAaAction;
import note.log4j.a.a.a.ExampleAaaAction;
import note.log4j.b.ExampleBAction;
import note.log4j.c.ExampleCAction;

import org.apache.log4j.PropertyConfigurator;
import org.junit.Test;


public class AdditivityLoggerTest {

    @Test
    public void testTree() {
        PropertyConfigurator.configure("conf/additivity-log4j.properties");

        doActions();
    }

    private void doActions() {
        ExampleAAction a = new ExampleAAction();
        a.doAction();
        ExampleAaAction aa = new ExampleAaAction();
        aa.doAction();
        ExampleAaaAction aaa = new ExampleAaaAction();
        aaa.doAction();
        ExampleBAction b = new ExampleBAction();
        b.doAction();
        ExampleCAction c = new ExampleCAction();
        c.doAction();
    }

}

を実行すると、

main note.log4j.a.ExampleAAction#doAction INFO 開始

main note.log4j.a.ExampleAAction#doAction WARN 微妙です。

main note.log4j.a.ExampleAAction#doAction INFO 終了

main note.log4j.a.a.ExampleAaAction#doAction INFO 開始

main note.log4j.a.a.ExampleAaAction#doAction WARN 微妙です。

main note.log4j.a.a.ExampleAaAction#doAction INFO 終了

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 開始

main note.log4j.a.a.a.ExampleAaaAction#doAction WARN 微妙です。

main note.log4j.a.a.a.ExampleAaaAction#doAction INFO 終了

main note.log4j.b.ExampleBAction#doAction INFO 開始

main note.log4j.b.ExampleBAction#doAction WARN 微妙です。

main note.log4j.b.ExampleBAction#doAction INFO 終了

main note.log4j.c.ExampleCAction#doAction INFO 開始

main note.log4j.c.ExampleCAction#doAction WARN 微妙です。

main note.log4j.c.ExampleCAction#doAction INFO 終了

2重にログ出力しなくなった。

2重のログ出力を解除する方法としては、rootLoggerなど、親のロガーのAppenderを
設定しないという手段もあるようだ。

その他

commons-logging

• log4jやjava.util.loggingのラッパー

SLF4J

• これを採用しているオープンソースのプロジェクトも多くなっている。
• log4jやjava.util.loggingのラッパー
• ラッパーだけでなくLogbackというログの実装も提供している。

log4jをあんまり活用してない使い方

• 設定ファイルのロガー(カテゴリー)の設定でパッケージ名を指定してなくて、log4jのロガーの階層構造の仕組みが活用されてない。
  • 「パッケージでなくて、ログレベルごとに、ログファイルをわけたいのだ」という使い方をしているひとたちはいた。
  • 「パッケージでなくて、特定の用途ごとに、ログファイルをわけたいのだ」という使い方をしているひとたちはいた。
• log4jをラップして自前のロガーをつくっているのだが、実装がまずく、log4jのロガーの階層構造の仕組みが無意味になっている。
  • ログ出力したときの、クラス名がぜんぶlog4jをラップしてつくったロガーのクラス名になっているとか見たくない。
  • ログレベルとレイアウト（ログのフォーマット）、各種Appenderだけでも利用すれば便利なのはそうなのだが。