2016-11-21

好用卻陌生的 log4j 的累加屬性(additivity)

log4j 設定有三個主角:Logger、Appender 與 Pattern(Layout)。

Appender 設定的是 Log 的出口,看是要往 Console 去呢?還是送到檔案裡存下來。

Pattern 設定的就是 Log 輸出的格式,重點就是時間、程式位置與 Log 訊息。

Logger 設定的則是來自哪裡的 Log 要送去哪個 Appender。

簡單的設定如下:
## Root Log ##
log4j.rootLogger=INFO, CONSOLE

## Log ##
log4j.logger.idv.neil.log4j=INFO, FILE

## CONSOLE Appender ##
log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.CONSOLE.layout.ConversionPattern=%d{HH:mm:ss} %p [%t] %c{1} - %m%n

## FILE Appender ##
log4j.appender.FILE=org.apache.log4j.DailyRollingFileAppender
log4j.appender.FILE.File=normal.log
log4j.appender.FILE.DatePattern='.'yyyy-MM-dd
log4j.appender.FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.FILE.layout.ConversionPattern=%d{yyy/MM/dd HH:mm:ss} %p [%t] %c{1} - %m%n
設定兩個 Appender (CONSOLE 與 FILE),沒什麼問題。

然後 Logger 部份才是精彩。
## Root Log ##
log4j.rootLogger=INFO, CONSOLE
一開始的 rootLogger 是寫死的,表示整個系統「所有」INFO 以上的 Log,都要送往 CONSOLE,很正常。

因為「所有」殺傷力太大,rootLogger 是可以不用設定的,交由以下的 Looger 自行設定。
## Log ##
log4j.logger.idv.neil.log4j=INFO, FILE
再來是第二個 Logger,表示 idv.neil.log4j 「以下」的所有 INFO 以上的 Log 都要送往 FILE,包括:
  • idv.neil.log4j.Main
  • idv.neil.log4j.normal.Normal
程式如下:
package idv.neil.log4j;

import org.apache.log4j.Logger;

import idv.neil.log4j.normal.Normal;

public class Main {

  private Logger log = Logger.getLogger(this.getClass());

  public static void main(String[] args) {
    Main m = new Main();
    m.log();
  }

  public void log() {
    log.info("Main");
    new Normal().log();
  }
}
package idv.neil.log4j.normal;

import org.apache.log4j.Logger;

public class Normal {

  private Logger log = Logger.getLogger(this.getClass());

  public void log() {
    log.info("Normal");
  }
}
CONSOLE 輸出的 Log 如下:
01:18:22 INFO [main] Main - Main
01:18:22 INFO [main] Normal - Normal
FILE 輸出的 Log 如下:
2016/11/21 01:18:22 INFO [main] Main - Main
2016/11/21 01:18:22 INFO [main] Normal - Normal
一切都很正常、很完美,直到...

新增了一個 Secure class。
package idv.neil.log4j.secure;

import org.apache.log4j.Logger;

public class Secure {

  private Logger log = Logger.getLogger(this.getClass());

  public void log() {
    log.info("Secure");
  }
}
Main 裡也呼叫了 Secure。
package idv.neil.log4j;

import org.apache.log4j.Logger;

import idv.neil.log4j.normal.Normal;
import idv.neil.log4j.secure.Secure;

public class Main {

  private Logger log = Logger.getLogger(this.getClass());

  public static void main(String[] args) {
    Main m = new Main();
    m.log();
  }

  public void log() {
    log.info("Main");
    new Normal().log();
    new Secure().log();
  }
}
CONSOLE 輸出的 Log 如下:
01:21:47 INFO [main] Main - Main
01:21:47 INFO [main] Normal - Normal
01:21:47 INFO [main] Secure - Secure
FILE 輸出的 Log 如下:
2016/11/21 01:21:47 INFO [main] Main - Main
2016/11/21 01:21:47 INFO [main] Normal - Normal
2016/11/21 01:21:47 INFO [main] Secure - Secure
沒什麼問題,直到....客戶要求 Secure 的 Log 不能送到 CONSOLE,也不能送到 FILE,要另外送到一個獨立的 SECURE 檔案。

天真的想,很容易啊!
log4j.logger.idv.neil.log4j.secure=INFO, SECURE

## SECURE Appender ##
log4j.appender.SECURE=org.apache.log4j.DailyRollingFileAppender
log4j.appender.SECURE.File=secure.log
log4j.appender.SECURE.DatePattern='.'yyyy-MM-dd
log4j.appender.SECURE.layout=org.apache.log4j.PatternLayout
log4j.appender.SECURE.layout.ConversionPattern=%d{HH:mm:ss}[%t] %m%n
新增一個 SECURE Appender,然後也增加一個 idv.neil.log4j.secure 的 Logger,指向 SECURE。

簡單吧,來執行看看!

CONSOLE 輸出的 Log 如下:
01:27:08 INFO [main] Main - Main
01:27:08 INFO [main] Normal - Normal
01:27:08 INFO [main] Secure - Secure
FILE 輸出的 Log 如下:
2016/11/21 01:27:08 INFO [main] Main - Main
2016/11/21 01:27:08 INFO [main] Normal - Normal
2016/11/21 01:27:08 INFO [main] Secure - Secure
SECURE 輸出的 Log 如下:
01:27:08[main] Secure
只有 SECURE 是符合預期的,CONSOLE 和 FILE 都嚇死人了!

為什麼 CONSOLE 和 FILE 會有 Secure 的 Log?
為什麼 CONSOLE 和 FILE 會有 Secure 的 Log?
為什麼 CONSOLE 和 FILE 會有 Secure 的 Log?

令人崩潰啊!!!

回到最前面說過的
一開始的 rootLogger 是寫死的,表示整個系統「所有」INFO 以上的 Log,都要送往 CONSOLE。
還有
再來是第二個 Logger,表示 idv.neil.log4j 「以下」的所有 INFO 以上的 Log 都要送往 FILE。

看到那兩個關鍵字了吧,所有的 Log 都會送給 rootLogger,以及  idv.neil.log4j 以下的所有 Log 都會送給 idv.neil.log4j 所設定的 Appender。

歸納一個重點就是「累加」。

下層的 Log 會「自動送給」上層,直到 root。

所以 idv.neil.log4j.secure 的 Log 除了送給 idv.neil.log.secure 所設定的 Appender 之外,也會送給 idv.neil.log4j 與 rootLogger 所設定的 Appender。

Log4j 居然有這麼神奇的累加機制,玩這麼久才發現,哀...

不過 Log4j 也很神奇的提供了「停用累加」的機制,就是 additivity。

只要為不需要累加的 Logger 加上 log4j.additivity.idv.neil.log4j.secure=false,這樣 idv.neil.log4j.secure 「以下」的 Log 最多只會送到 idv.neil.log4j.secure 所設定的 Appender,不會再往上送了,是不是很貼心!
## Log ##
log4j.logger.idv.neil.log4j=INFO, FILE
log4j.logger.idv.neil.log4j.secure=INFO, SECURE
log4j.additivity.idv.neil.log4j.secure=false
CONSOLE 輸出的 Log 如下:
01:42:48 INFO [main] Main - Main
01:42:48 INFO [main] Normal - Normal
FILE 輸出的 Log 如下:
2016/11/21 01:42:48 INFO [main] Main - Main
2016/11/21 01:42:48 INFO [main] Normal - Normal
SECURE 輸出的 Log 如下:
01:42:48[main] Secure
收工。

---
---
---

沒有留言:

張貼留言