Jakarta log4j.xml に設定するログレベルの整理

はじめに †

• log4j.xml のログレベルの関係がよく分からないので調べてみる。次の３つで制御されるが、それぞれの関係は？
  1. appender の <param name="threshold" value="debug"/>
  2. category の <priority value="debug" />
  3. root の <priority value="info" />
• 結局こうなる
  • category と root は、影響し合わない
  • 実際に出力されるログレベルは、
    • root と appender で指定したログレベルの内、どちらか厳しいもの
    • category と appender で指定したログレベルの内、どちらか厳しいもの
• いろいろ面倒なので、基本的に root は使わず、category のみにしたほうがいいかも
  • アプリケーションではなく、ライブラリからのログも混じってしまう
  • 微妙に挙動がおかしくなる・・・

↑

検証アプリケーション †

↑

プロジェクトの構成 †

↑

Log4jExamApplication?†

  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29

       -||||||-|||||||||||!|!

package com.snail.exam.log4j; import org.apache.log4j.Logger; import com.snail.exam.log4j.buggy.BuggyClass;import com.snail.exam.log4j.gentle.GentleClass; public class Log4jExamApplication {    private static Logger logger = Logger.getLogger(Log4jExamApplication.class);   /**   * @param args   */  public static void main(String[] args) {    logger.fatal("本当にやばいログ　　");    logger.error("普通にやばいログ　　");    logger.warn( "ちょっとやばいログ　");    logger.info( "運用時に必要なログ　");    logger.debug("開発時に必要なログ　");    logger.trace("デスマ時に必要なログ");        new BuggyClass().doSomething();        new GentleClass().doSomething();   } }

↑

BuggyClass?†

  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21

    -||||||-||||||!|!

package com.snail.exam.log4j.buggy; import org.apache.log4j.Logger; public class BuggyClass {    private static Logger logger = Logger.getLogger(BuggyClass.class);   /**   * @param args   */  public void doSomething() {    logger.fatal("本当にやばいログ　　");    logger.error("普通にやばいログ　　");    logger.warn( "ちょっとやばいログ　");    logger.info( "運用時に必要なログ　");    logger.debug("開発時に必要なログ　");    logger.trace("デスマ時に必要なログ");  } }

↑

GentleClass?†

  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21

    -||||||-||||||!|!

package com.snail.exam.log4j.gentle; import org.apache.log4j.Logger; public class GentleClass {    private static Logger logger = Logger.getLogger(GentleClass.class);   /**   * @param args   */  public void doSomething() {    logger.fatal("本当にやばいログ　　");    logger.error("普通にやばいログ　　");    logger.warn( "ちょっとやばいログ　");    logger.info( "運用時に必要なログ　");    logger.debug("開発時に必要なログ　");    logger.trace("デスマ時に必要なログ");  } }

↑

実行結果 †

↑

実行結果１ †

運用時に良くある log4j.xml。基本的に info 以上を出力し、どうもおかしい振る舞いをするパッケージは、debug 以上を出力する。

↑

log4j.xml †

  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46

<?xml version="1.0" encoding="UTF-8" ?><!DOCTYPE log4j:configuration SYSTEM "log4j.dtd"> <log4j:configuration xmlns:log4j='http://jakarta.apache.org/log4j/'>    <!-- ********************** 標準出力への出力 ********************** -->  <appender name="STDOUT" class="org.apache.log4j.ConsoleAppender">    <param name="threshold" value="info"/>      <!-- レイアウトの指定 -->    <layout class="org.apache.log4j.PatternLayout">      <param name="ConversionPattern"             value="RUNTIME [%x%-5p] %-10.10m @ %c%n" />    </layout>  </appender>    <!-- ********************** ファイルへの出力 ********************** -->  <appender name="FILE" class="org.apache.log4j.DailyRollingFileAppender">    <param name="threshold" value="debug"/>      <!-- ファイル情報 -->    <param name="file" value="C:\\Users\\kagyuu\\Documents\\logtest.txt" />        <param name="append" value="false" />    <param name="datePattern" value="'.'yyyy-MM-dd" />        <!-- レイアウトの指定 -->    <layout class="org.apache.log4j.PatternLayout">      <param name="ConversionPattern"             value="DEBUG [%x%-5p] %-10.10m @ %c%n" />    </layout>  </appender>   <!-- ********************** category定義 ************************* -->  <category name="com.snail.exam.log4j.buggy">    <priority value="debug" />    <appender-ref ref="FILE" />  </category>   <!-- ********************** root定義 ***************************** -->  <root>    <priority value="debug" />    <appender-ref ref="STDOUT" />  </root>   </log4j:configuration>

↑

出力 †

• STDOUT

  RUNTIME [FATAL] 本当にやばいログ　　 @ com.snail.exam.log4j.Log4jExamApplicationRUNTIME [ERROR] 普通にやばいログ　　 @ com.snail.exam.log4j.Log4jExamApplicationRUNTIME [WARN ] ちょっとやばいログ　 @ com.snail.exam.log4j.Log4jExamApplicationRUNTIME [INFO ] 運用時に必要なログ　 @ com.snail.exam.log4j.Log4jExamApplicationRUNTIME [FATAL] 本当にやばいログ　　 @ com.snail.exam.log4j.buggy.BuggyClassRUNTIME [ERROR] 普通にやばいログ　　 @ com.snail.exam.log4j.buggy.BuggyClassRUNTIME [WARN ] ちょっとやばいログ　 @ com.snail.exam.log4j.buggy.BuggyClassRUNTIME [INFO ] 運用時に必要なログ　 @ com.snail.exam.log4j.buggy.BuggyClassRUNTIME [FATAL] 本当にやばいログ　　 @ com.snail.exam.log4j.gentle.GentleClassRUNTIME [ERROR] 普通にやばいログ　　 @ com.snail.exam.log4j.gentle.GentleClassRUNTIME [WARN ] ちょっとやばいログ　 @ com.snail.exam.log4j.gentle.GentleClassRUNTIME [INFO ] 運用時に必要なログ　 @ com.snail.exam.log4j.gentle.GentleClass

• FILE(C:\Users\kagyuu\Documents\logtest.txt)

  DEBUG [FATAL] 本当にやばいログ　　 @ com.snail.exam.log4j.buggy.BuggyClassDEBUG [ERROR] 普通にやばいログ　　 @ com.snail.exam.log4j.buggy.BuggyClassDEBUG [WARN ] ちょっとやばいログ　 @ com.snail.exam.log4j.buggy.BuggyClassDEBUG [INFO ] 運用時に必要なログ　 @ com.snail.exam.log4j.buggy.BuggyClassDEBUG [DEBUG] 開発時に必要なログ　 @ com.snail.exam.log4j.buggy.BuggyClass

↑

フィルタリングの概要 †

• root
  • root で info 未満は切り捨てられて、
  • appender では debug 未満を切り捨てるから、
  • 結局 info 以上が出力される
• category
  • category で、BuggyClass? 以外、debug 未満は切り捨てられて、
  • appender では debug 未満を切り捨てるから、
  • 結局 BuggyClass? の debug 以上が出力される

↑

実行結果2 †

やや変則的な log4j.xml (log4j.xml の振る舞いを確かめるための log4j.xml )。

↑

log4j.xml †

  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46

<?xml version="1.0" encoding="UTF-8" ?><!DOCTYPE log4j:configuration SYSTEM "log4j.dtd"> <log4j:configuration xmlns:log4j='http://jakarta.apache.org/log4j/'>    <!-- ********************** 標準出力への出力 ********************** -->  <appender name="STDOUT" class="org.apache.log4j.ConsoleAppender">    <param name="threshold" value="warn"/>      <!-- レイアウトの指定 -->    <layout class="org.apache.log4j.PatternLayout">      <param name="ConversionPattern"             value="RUNTIME [%x%-5p] %-10.10m @ %c%n" />    </layout>  </appender>    <!-- ********************** ファイルへの出力 ********************** -->  <appender name="FILE" class="org.apache.log4j.DailyRollingFileAppender">    <param name="threshold" value="info"/>      <!-- ファイル情報 -->    <param name="file" value="C:\\Users\\kagyuu\\Documents\\logtest.txt" />        <param name="append" value="false" />    <param name="datePattern" value="'.'yyyy-MM-dd" />        <!-- レイアウトの指定 -->    <layout class="org.apache.log4j.PatternLayout">      <param name="ConversionPattern"             value="DEBUG [%x%-5p] %-10.10m @ %c%n" />    </layout>  </appender>   <!-- ********************** category定義 ************************* -->  <category name="com.snail.exam.log4j.buggy">    <priority value="debug" />    <appender-ref ref="FILE" />  </category>   <!-- ********************** root定義 ***************************** -->  <root>    <priority value="debug" />    <appender-ref ref="STDOUT" />  </root>   </log4j:configuration>

↑

出力 †

• STDOUT

  RUNTIME [FATAL] 本当にやばいログ　　 @ com.snail.exam.log4j.Log4jExamApplicationRUNTIME [ERROR] 普通にやばいログ　　 @ com.snail.exam.log4j.Log4jExamApplicationRUNTIME [WARN ] ちょっとやばいログ　 @ com.snail.exam.log4j.Log4jExamApplicationRUNTIME [FATAL] 本当にやばいログ　　 @ com.snail.exam.log4j.buggy.BuggyClassRUNTIME [ERROR] 普通にやばいログ　　 @ com.snail.exam.log4j.buggy.BuggyClassRUNTIME [WARN ] ちょっとやばいログ　 @ com.snail.exam.log4j.buggy.BuggyClassRUNTIME [FATAL] 本当にやばいログ　　 @ com.snail.exam.log4j.gentle.GentleClassRUNTIME [ERROR] 普通にやばいログ　　 @ com.snail.exam.log4j.gentle.GentleClassRUNTIME [WARN ] ちょっとやばいログ　 @ com.snail.exam.log4j.gentle.GentleClass

• FILE(C:\Users\kagyuu\Documents\logtest.txt)

  DEBUG [FATAL] 本当にやばいログ　　 @ com.snail.exam.log4j.buggy.BuggyClassDEBUG [ERROR] 普通にやばいログ　　 @ com.snail.exam.log4j.buggy.BuggyClassDEBUG [WARN ] ちょっとやばいログ　 @ com.snail.exam.log4j.buggy.BuggyClassDEBUG [INFO ] 運用時に必要なログ　 @ com.snail.exam.log4j.buggy.BuggyClass

↑

フィルタリングの概要 †

• root
  • root で info 未満は切り捨てられて、
  • appender では warn 未満を切り捨てるから、
  • 結局 warn 以上が出力される
• category
  • category で、BuggyClass? 以外、debug 未満は切り捨てられて、
  • appender では info 未満を切り捨てるから、
  • 結局 BuggyClass? の info 以上が出力される

↑

(余談) Maven2 で要らない依存ライブラリを取ってこないようにするには？†

  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29

<?xml version="1.0" encoding="UTF-8"?><project>  <modelVersion>4.0.0</modelVersion>  <groupId>Log4jExam</groupId>  <artifactId>Log4jExam</artifactId>  <version>0.0.1-SNAPSHOT</version>  <description></description>  <dependencies>    <dependency>      <groupId>log4j</groupId>      <artifactId>log4j</artifactId>      <version>1.2.15</version>      <exclusions>        <exclusion>          <groupId>com.sun.jdmk</groupId>          <artifactId>jmxtools</artifactId>        </exclusion>        <exclusion>          <groupId>com.sun.jmx</groupId>          <artifactId>jmxri</artifactId>        </exclusion>        <exclusion>          <groupId>javax.jms</groupId>          <artifactId>jms</artifactId>        </exclusion>      </exclusions>    </dependency>  </dependencies></project>

• <exclusion> で、要らない依存ライブラリ(依存ライブラリの依存ライブラリ)を指定することができる。
  • この場合、アプリケーションは log4j を使い、log4jは jmx や jms を使っているが、
  • このアプリケーションからは jmx や jms が必要な log4j の機能を使わないので <exclusion> に指定することにより、Maven2 が勝手に jmx や jms を取り込むのを防いでいる
• <exclusion> に指定されたライブラリは、Maven レポジトリから勝手に取ってこられないので、mvn package などでできた jar にも入らない
• 便利だからと言って、何にも考えずに POM ファイルにライブラリを記述していくと、最終成果物が数十MB になったりするんだよね・・・