Jemmy Walker

　　通常在log4j.xml會有如下的配置：

<root>
    <level value="INFO" />
    <appender-ref ref="stdout" />
</root>

　　影響所及，任何一個class只要是log到INFO等級以上的，都會被<root>帶到stdout這個appender去寫出，通常是console。Console的IO也是會影響效能。若希望自己的<logger>不為<root>所影響，則可在log4j.xml做如下設定，將additivity設為false：

<logger name="com.mycompany" additivity="false">
    <level value="INFO" />
    <appender-ref ref="dynadailyrolling" />
</logger>

　　若是由程式產出logger物件，要避免<root>影響，可增加以下這行：

org.apache.log4j.Logger log
    = org.apache.log4j.Logger.getLogger(name);
log.setAdditivity(false);

　　一段時間沒記Blog了，顯示筆者狀態由【研發】轉為【專案】。研發時用Survey最新技術看是否有助提升開發品質，專案時則需選擇最穩定技術，取得進度與風險之間的最佳平衡。三年前接手他人銀行專案前，我為該專案研發最適用的Framework，即使專案成員在程式能力不強，依然需當作客戶看待。之後我接手成為該專案Leader，卻屢屢與其中一位成員衝突，該成員說詞是為何以前可以現在不行，而我回答就是因為可以，前Leader才會被換掉。最後身為Leader，我把他換下來了。角色的轉換，不單關注焦點思維不同，連決策及身負的責任也殊異。 　　以上與本主題無關，目前要著手的專案，對Log有個By Size與By Time的需求。目前最新的Log4J核心Jar並無此功能，週邊我倒是找到兩個，一個是今年5/18釋出的TimeAndSizeRollingAppender，自http://simonsiteblog.blogspot.com/取得，並無Maven Repository。所以得比照Oracle的JDBC Jar方式放置到Local Repository。以下是用log4j.xml配置：

<appender name="DateAndSize" class="org.apache.log4j.appender.TimeAndSizeRollingAppender">
    <param name="DatePattern" value="'.'yyyy-MM-dd'.log'"/> <!--By Date設定 -->
    <param name="File" value="C:/logs/sample.log" />
    <param name="Threshold" value="DEBUG"/>
    <param name="MaxFileSize" value="20KB"/>
    <param name="MaxRollFileCount" value="10"/>
    <param name="ScavengeInterval" value="30000"/>  <!--間隔30秒輪詢,超出MaxFileSize就壓縮 -->
    <param name="BufferedIO" value="false"/>
    <param name="CompressionAlgorithm" value="GZ"/>
    <layout class="org.apache.log4j.PatternLayout">
           <param name="ConversionPattern" value="%d{yyyy/MM/dd HH:mm:ss} %-5p [%F:%L] : %m%n" />
    </layout>
</appender>

　　得到Log檔清單如右：sample.log、sample.log.2010-05-27.log.1.gz、sample.log.2010-05-27.log.2.gz、sample.log.2010-05-27.log.3.gz…。 　　另一個就不好用，叫CompositeRollingAppender，會產出sample.log、sample.log.1、sample.log.2…，但換到第二天時，只有sample.log會變成sample.log.2010-05-26.log，而有Index的log並不會跟著變更檔名，還會被今天的Log蓋過去。

　　踹JPA過程，老是遇到如下的Exception： Caused by: java.lang.AbstractMethodError: org.slf4j.impl.Log4jLoggerAdapter.trace(Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V 　　搞了半天，slf4j-api和slf4j-log12沒有同步到同一版本，即1.5.8。實在踹老半天>"<

　　Log4J的1.3版還在阿法貝塔階段。1.2版最新到1.2.15，但用於Eclipse上的Maven2卻有個Issue。在執行Maven Clean後再執行Maven Package會Build Failure，有以下的錯誤訊息： [WARNING] Invalid POM for javax.jms:jms:jar:1.1, transitive dependencies (if any) will not be available, enable debug logging for more details
[WARNING] Invalid POM for com.sun.jdmk:jmxtools:jar:1.2.1, transitive dependencies (if any) will not be available, enable debug logging for more details
[WARNING] Invalid POM for com.sun.jmx:jmxri:jar:1.2.1, transitive dependencies (if any) will not be available, enable debug logging for more details 　　這些loss的Jar在repository都空有其pom.xml檔卻無其jar檔。反而使用Eclipse的Project/Clean後，再執行Maven Package才能Build Success。但回到1.2.14版卻無此問題，經過Dependency Graph才得知Log4J 1.2.15依賴上述三個Jar之故。為何經過Project/Clean後再Package就沒問題？唔！無解，可能是循環依賴所致吧！ 　　2010/3/11補述。後來找到引用1.2.15的解法，dependency設定如下：

<dependency>
    <groupId>log4j</groupId>
    <artifactId>log4j</artifactId>
    <version>1.2.15</version>
        <exclusions>
       <exclusion>
      <groupId>javax.jms</groupId>
      <artifactId>jms</artifactId>
       </exclusion>
       <exclusion>
      <groupId>com.sun.jdmk</groupId>
      <artifactId>jmxtools</artifactId>
       </exclusion>
       <exclusion>
      <groupId>com.sun.jmx</groupId>
      <artifactId>jmxri</artifactId>
       </exclusion>
       <exclusion>
      <groupId>javax.mail</groupId>
      <artifactId>mail</artifactId>
       </exclusion>
    </exclusions>
</dependency>

　　利用排除之法就能引用1.2.15來Maven Package。2010/5/12補充：1.2.16版就沒這個情形。

　　上個月寫個Log4J以類別全名作為檔名的Log檔，每個類別都有自己的Log file。若還要再加個需求是Log File可以Daily Rolling，承襲上次的寫法也不困難：
public class DynaDailyRollingAppender extends DailyRollingFileAppender {
    private static String oldFileName = null;
    private static String oldPath = null;
    public void generateLogFile(LocationInfo info) {       
        if (oldPath == null) {
            oldPath = this.fileName.substring(0, this.fileName.lastIndexOf("test"));
        }
        SimpleDateFormat sdf = new SimpleDateFormat(this.getDatePattern());
        String fileName1 = oldPath;
        fileName1 += info.getClassName() + sdf.format(Calendar.getInstance().getTime());
        oldFileName = fileName1;
        this.setFile(fileName1);   
        this.activateOptions();
    }
    @Override
    protected void subAppend(LoggingEvent event) {
        String className =  event.getLocationInformation().getClassName();
        this.logger1.info("Class:" + className);
        if (oldFileName != className) {
            this.generateLogFile(event.getLocationInformation());
        }
        super.subAppend(event);
    }
}
　　在log4j.properties若設成DailyRolling的話，會有這樣的屬性設定：
log4j.appender.dynadailyrolling.DatePattern='.'yyyy-MM-dd'.log'
　　這樣就會在log file後面補上.2009-10-25.log(以今天為例)，是故上述getDatePattern便是取得'.'yyyy-MM-dd'.log'，再用java.text.SimpleDateFormat抓今天的日期進行format，就得到我們要的檔名。

　　其實SLF4J學起來還蠻快的。會需要兩個Jar，一是slf4j-api.jar，第二個通常是slf4j-log4j12.jar(用於Log4J 1.2.x版)，若想換成Apache的，則把第二個換成slf4j-jcl.jar就可以了。可是要是出現兩個…，slf4j-api應該是先找到第一個為主，沒事就別亂冒險。而NOP則是No OPeration之意。logback則是直接implment slf4j，血統最純。

　　SLF4J的Sample如下：
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
　　final Logger logger = LoggerFactory.getLogger(Ｍy.class);   // 從Factory取得Facade，一次用了兩個Design Pattern
 
　　在Apache的JCL也有類似的，但只能轉接到Log4J。就是在commons-logging.properties檔內容設定如下：
org.apache.commons.logging.Log=org.apache.comons.logging.impl.Log4JLogger

　　寫了幾年的Java，最弱的部份是Log，現在看來還是差不多。最近在改寫Framework時才對Log4J的用法稍有體會，不然也是渾渾噩噩看別人怎麼配置，自己也跟著配置。
　　2006年曾設計Logger Proxy委託天津同事開發，其目的有二：一是預設按class full name產生log檔，二是避開像JBoss本身的log4j.properties影響。這樣做效益有好有壞，壞就壞在Ap Server會記一份，自己又用Proxy記了一份，而且不只如此，移到不同的AP Server或Web Server，因WAR或EAR的目錄結構不同，連帶的Proxy跟著改寫，無法通用。
　　後來在Google找有無可依不同的class name為檔名產出不同的log檔，是有接近的solution，但不完全滿足其需求。也間接了解了log4j.properties真正的配置方式：
log4j.rootLogger = INFO, stdout
log4j.category.com.opensymphony=DEBUG
log4j.category.org.apache.struts2=INFO, rolling
　　原來Log4J是由Logger、Appender和Layout決定。後兩者設定方式還算清楚，而Logger其實可以模擬做到依不同class或package產出不同的log file。上例的log4j.rootLogger、log4j.category.package.class就是一種Logger，rootLogger是super Logger可以記錄所有class的Log，而log4j.category.後面是接package甚至是class full name。
　　等於(=)後面以逗號分隔，第一個參數是Level，第二個以後的參數均是Appender，以log4j.category.com.opensymphony為例，雖然rootLogger的Level是INFO，但com.opensymphony這package內所有的class和子class均是DEBUG Level，除非還有更detail的package另外設Level，則以最接近的package為優先。第三例則表示還可參照rolling這個appender。
　　但為何不能滿足在執行期動態決定產出的log file name，看FileAppender如下：
log4j.appender.rolling=org.apache.log4j.RollingFileAppender
log4j.appender.rolling.File=c:/logs/test
log4j.appender.rolling.MaxFileSize=100KB
log4j.appender.rolling.MaxBackupIndex=1
log4j.appender.rolling.layout=org.apache.log4j.PatternLayout
log4j.appender.rolling.layout.ConversionPattern=%d{ABSOLUTE} %-5p [%F:%L] : %m%n
　　上例的粗體字就事先把file給產出，若是目錄就會報錯，爾後在Google找到解法是去繼承RollingFileAppender。
(log4j.properties設定)
log4j.appender.dynarolling=com.xyz.util.DynaRollingAppender
log4j.appender.dynarolling.File=C:/logs/test
log4j.appender.dynarolling.MaxFileSize=100KB
log4j.appender.dynarolling.MaxBackupIndex=1
log4j.appender.dynarolling.layout=org.apache.log4j.PatternLayout
log4j.appender.dynarolling.layout.ConversionPattern=%d{ABSOLUTE} %-5p [%F:%L] : %m%n
(source code部份)
public class DynaRollingAppender extends RollingFileAppender {
   
    private static String oldFileName = null;
    private static String oldPath = null;
    public void generateLogFile(LocationInfo info) {       
        if (oldPath == null) {
            oldPath = this.fileName.substring(0, this.fileName.lastIndexOf("test"));
        }
        String fileName1 = oldPath;
        fileName1 += info.getClassName() + ".log";
        this.logger1.info(fileName1 + "; " + this.fileName);
        oldFileName = fileName1;
        this.setFile(fileName1);   
       this.activateOptions();
    }
    @Override
    protected void subAppend(LoggingEvent event) {
        String className =  event.getLocationInformation().getClassName();
        if (oldFileName != className) {
            this.generateLogFile(event.getLocationInformation());
        }
        super.subAppend(event);
    }
}
　　上例中，事先overide subAppend，換掉setFile內容，但是initial時在換掉之前就做了一次setFile，所以File參數必須是檔案，目的是取得其目錄，然後再換成class full name + ".log"格式做setFile，再activateOptions才會生效，而最後一行super.subAppend則將內容寫入新的log file。
　　從程式就看到LoggingEvent含有LocationInfo類別，正是log4j使用reflection取得call它的class name, file name和line number等資訊。但這樣做有沒有效能的issue未知，之前第一次去吉隆坡出差，就曾因Logger Proxy不穩掛過。

　　2006年委天津開發個LoggerProxy，按class名產出該class的Log檔，也加入可以指定某package以下共用同一個log檔的功能。這在Web Server上運作沒問題，卻在Java Main出現Lock現象。若同A Class hold這個log檔，同package的其他class無法再寫入同一個log檔，是因為使用了不同的Logger Instance。解法是想辦法讓每個class裡的Logger共用同一個Logger的instance，卻衍生一個問題，就是使用%c去顯示package class full name時，該class name是取決於當初Logger.getLogger(clazz)中，所傳的clazz的class name。後來意外發現Logger另一個特性：假設Logger的變數為loggerA，loggerA的%c就是當初傳的clazz(假設名為com.A)，若想在%c顯示自己的com.B時，只需按如下方式取得：
　　Logger loggerB = loggerA.getLogger("com.B");   // 因為getLogger是static method，透過loggerA.getLogger，loggerB就能得到loggerA屬性