使用高效的日志工具—Log4J （1）??
作者：趙科 發文時間：2002.11.13 09:52:21
大家在編程時經常不可避免地要使用到一些日志操作，比如開發階段的調試信息、運行時的日志記錄及審計。調查顯示，日志代碼占代碼總量的4％。通常大家可以簡單地使用System.out.println()語句輸出日志信息，但是往往會有一些判斷，比如：
if (someCondition) {
System.out.println("some information.");
}
這些判斷造成正常的程序邏輯中混雜了大量的輸出語句。而在開發階段寫下的這些判斷僅為了調試的語句，在開發完成時需要查找并移除。部署運行后，尤其是在一些企業應用系統中，還經常需要進一步調試，這時就遇到了更大的麻煩。所以，我們需要一套完備的、靈活的、可配置的日志工具。Log4J就是優秀的選擇。
Log4J是Apache軟件基金會Jakarta項目下的一個子項目，是用Java編寫的優秀日志工具包。通過Log4J可以在不修改代碼的情況下，方便、靈活地控制任意粒度的日志信息的開啟或關閉，然后使用定制的格式，把日志信息輸出到一個或多個需要的地方。并且，Log4J還有一條平滑的學習曲線，在三分鐘內就可學會它的簡單使用。隨著使用深入，你會發現Log4J功能的強大，幾乎可以滿足日志方面的所有需要。
快速入門
先看一段代碼，看看Log4J是多么易于上手，代碼如下：
package org.javaresearch.log4j;
import org.apache.log4j.*;
public class TestLog4J {
static Logger log = Logger.getLogger(TestLog4J.class.getName());
public static void main(String args[]) {
??BasicConfigurator.configure();
??// logging的各種方法
??cat.debug("Start of main()");
??cat.info("Just testing a log message with priority set to INFO");
??cat.warn("Just testing a log message with priority set to WARN");
??cat.error("Just testing a log message with priority set to ERROR");
??cat.fatal("Just testing a log message with priority set to FATAL");
??// 另一種不方便的格式
??cat.log(Priority.DEBUG, "Testing a log message use a alternate form");
??log.debug("End of main().");
}
}
把這段代碼保存在一個目錄下，編譯運行（注意要把log4j-1.2.7.jar包含入類路徑中），程序輸出如下：
0 [main] DEBUG TestLog4J??- Start of main()
10 [main] INFO TestLog4J??- Just testing a log message with priority set to INFO
20 [main] WARN TestLog4J??- Just testing a log message with priority set to WARN
30 [main] ERROR TestLog4J??- Just testing a log message with priority set to ERROR
30 [main] FATAL TestLog4J??- Just testing a log message with priority set to FATAL
40 [main] DEBUG TestLog4J??- Testing a log message use a alternate form
50 [main] DEBUG TestLog4J??- End of main().
首先解釋一下上面輸出結果的意義。第一個數字是指程序開始運行到運行該日志語句所經歷的毫秒數（用來做一點運行效率分析也不錯），“[main]”是日志事件發生的線程，隨后的“DEBUG”、“INFO”等信息是相應日志信息的優先級別，“TestLog4”是當前Logger的實例名，最后是日志信息。
在這段程序中，使用了Log4J提供的一個基本配置類BasicConfigurator對Log4J進行初始化。但在實際使用時通常不這么做，因為這多少有點“硬”編碼。今后如果要修改Log4J的配置，就需要修改、重新編譯代碼，這通常不是大家所希望的。通常，我們都提供一個名為log4j.properties的文件，在第一次調用到Log4J時，Log4J會在類路徑中定位這個文件，并讀入這個文件完成的配置。這個配置文件告訴Log4J以什么樣的格式、把什么樣的信息、輸出到什么地方。我們來看一個簡單的log4j.properties配置文件的示例，代碼如下：
log4j.rootLogger=DEBUG, A1
log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern= "%-4r [%t] %-5p %c %x - %m%n
把上面的內容存儲為log4j.properties，并放到和TestLog4J.class同一目錄下（當然也可以放到其它任何目錄，只要該目錄被包含到類路徑中即可）。具體這些配置文件中每行的意義，在以后章節會有詳細的說明，現在可以先跳過。現在你可以注釋掉上面程序中的“BasicConfigurator. configure();”語句，然后使用log4j.properties屬性文件完成Log4J的配置，重新編譯、運行，就得到和上面一樣的結果。
這樣做有什么好處呢？現在就初步領略一些Log4J的靈活、強大功能。比如系統要上線了，希望輸出一些警告和錯誤信息，這時僅需要修改log4j.properties文件中的“log4j.rootCategory=DEBUG, A1”即可，然后設置日志輸出的最低級別是WARN，設置為“log4j.root Category=WARN, A1”。此時不需要修改任何代碼，重新運行系統，輸出結果就變成了：
20 [main] WARN TestLog4J??- Just testing a log message with priority set to WARN
30 [main] ERROR TestLog4J??- Just testing a log message with priority set to ERROR
30 [main] FATAL TestLog4J??- Just testing a log message with priority set to FATAL
原理分析
Log4J有三個主要部件，它們是記錄器（Loggers）、輸出源（Appenders）和布局（Logouts）。記錄器按照布局中指定的格式把日志信息寫入一個或多個輸出源。輸出源可以是控制臺、文本文件、XML文件或Socket，甚至還可以把信息寫入到Windows事件日志或通過電子郵件發送，這都需要相應的類來處理，這些相關的類是ConsoleAppender、FileAppender、SocketAppender、NtEventLogAppender和JMSAppender。
記錄器（Logger）
首先讓我們看Logger類，代碼如下：
package org.apache.log4j;
public class Logger {
//創建和恢復方法
public static Logger getRootLogger();
public static Logger getLogger(String name);
public static Logger getLogger(Class clazz);
// 打印方法
public void debug(Object message);
public void info(Object message);
public void warn(Object message);
public void error(Object message);
public void fatal(Object message);
// 常用打印方法
public void log(Level l, Object message);
}
從這段代碼中可以看出Logger的基本使用。首先需要獲取一個Logger對象，獲取Logger對象的語句為：
Logger logger = Logger.getLogger(JavaLoggingExample.class.getName());
有了這個Logger對象，就可以在需要的地方方便地輸出日志信息。對于這些信息是否輸出、輸出的格式等，都可以通過配置文件方便地配置，而不需要修改代碼，這就是Log4J帶來的方便之處。
記錄器的層次結構
使用Log4J的Logger.getLogger()方法時會得到一個Logger的實例。如果一個應用中包含了上千個類，那么也幾乎需要上千個Logger實例。如何對這上千個Logger實例進行方便地配置，就是一個很重要的問題。Log4J采用了一種樹狀的繼承層次巧妙地解決了這個問題。在Log4J中Logger是具有層次關系的。它有一個共同的根，位于最上層，其它Logger遵循類似包的層次，比如：
static Logger root = Logger.getRootLogger();
static Logger log1 = Logger.getLogger("org");
static Logger log2 = Logger.getLogger("org.javaresearch");
static Logger log3 = Logger.getLogger("org.javaresearch.log4j.TestLog4J");
上面代碼中，log1是log2的父親，是log3的祖先，而root是所有log1、log2、log3的祖先，它們都從root中繼承。所以，一般情況下，僅需要配置好rootLogger，其它子記錄器都會從中繼承rootLogger的配置。如果修改了rootLogger的配置，其它所有的子記錄器也會繼承這種變化。這樣就大大地方便了配置。現在回頭看看在“快速入門”中的配置文件，我們僅配置了rootLogger，就可以控制所有的Logger的行為。
級別（Level）
Log4J中的一個核心概念是日志級別是有序的。Log4J內置了5種日志級別為：
DEBUG??<??INFO??<??WARN??<??ERROR??<??FATAL
右邊的級別比左邊的高。每一個Logger實例都有一個日志級別，上面的5種輸出方法就是對應于5種不同級別的日志請求。比如，如果c是一個Logger實例，c.info("some information")就是一個INFO級別的日志請求。一個日志請求會不會輸出，取決于該Logger實例的日志級別和該日志請求級別的比較。規則如下：
假如在一個級別為p的Logger實例中發生一個級別為q的日志請求，則當q >= p時請求才會啟用。
我們先來看實例2代碼如下：
// 得到一個logger 實例 "com.foo"
Logger??logger = Logger.getLogger("com.foo")
// 現在設置logger的級別，但正常情況是不需要刻意設置lgger級別的，因為它已經在配置文件中完成了
logger.setLevel(Level.INFO);
Logger barlogger = Logger.getLogger("com.foo.Bar");
//因為 WARN >= INFO，這個請求是可以實現的
logger.warn("Low fuel level.");
// 因為DEBUG < INFO，所以這個請求是無法實現的
logger.debug("Starting search for nearest gas station.");
// logger實例"com.foo.Bar"將從"com.foo"繼承級別，這樣，因為INFO >=
INFO，所以可以實現下面的請求
barlogger.info("Located nearest gas station.");
//因為DEBUG < INFO，這個請求是不能實現的
barlogger.debug("Exiting gas station search");
布局（Layout）
Log4J采用類似C語言中的printf函數的打印格式格式化日志信息，打印參數見表1如下：
%m 輸出代碼中指定的消息
%p 輸出優先級，即DEBUG，INFO，WARN，ERROR，FATAL
%r 輸出自應用啟動到輸出該log信息耗費的毫秒數
%c 輸出所屬的類目，通常就是所在類的全名
%t 輸出產生該日志事件的線程名
%n 輸出一個回車換行符，Windows平臺為“\r\n”，Unix平臺為“\n”
%d 輸出日志時間點的日期或時間，默認格式為ISO8601，也可以在其后指定格式，比如：%d{yyy MMM dd HH:mm:ss,SSS}，輸出類似：2002年10月18日 22：10：28，921
%l 輸出日志事件的發生位置，包括類目名、發生的線程，以及在代碼中的行數。舉例：Testlog4.main(TestLog4.java:10)
使用高效的日志工具—Log4J （2）??
作者：趙科 發文時間：2002.11.13 09:52:21
基本應用
Log4J的配置
現在來看log4j.properties配置文件的意義。第一行指定了根Logger的級別是DEBUG，并將此指定輸出到A1。A1就是第二行定義的org.apache.log4j.ConsoleAppender，此行表示將A1輸出到控制臺。第三行規定了輸出到A1的格式為org.apache.log4j.PatternLayout。第四行規定了輸出到A1格式的轉換模式為org.javaresearch.log4j.TestLog4J。
很多成熟的服務器類的軟件日志信息會輸出到控制臺，同時輸出到日志文件備查。使用Log4J可以在不改變任何代碼的情況下，僅通過修改配置文件就可以輕松地完成這項功能。相關配置文件如下：
#### Use two appenders, one to log to console, another to log to a file
log4j.rootCategory=debug, stdout, R
# Print only messages of priority WARN or higher for your category
log4j.category.your.category.name=WARN
#### First appender writes to console
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
# Pattern to output the caller's file name and line number.
log4j.appender.stdout.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n
#### Second appender writes to a file
log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.File=example.log
# Control the maximum log file size
log4j.appender.R.MaxFileSize=100KB
# Archive log files (one backup file here)
log4j.appender.R.MaxBackupIndex=1
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%p %t %c - %m%n
這個配置文件指定了兩個輸出源stdout和R。前者把日志信息輸出到控制臺，后者是一個輪轉日志文件。最大的文件是100KB，當一個日志文件達到最大尺寸時，Log4J會自動把example.log重命名為example.log.1，然后重建一個新的example.log文件，依次輪轉。
在Web應用中使用
在Web應用中，應該在哪兒對Log4J進行配置呢？首先要明確，Log4J必須在應用的其它代碼執行前完成初始化。因為Servlet是在Web服務器啟動時立即裝入的，所以，在Web應用中一般使用一個專門的Servlet來完成Log4J的配置，并保證在web.xml的配置中，這個Servlet位于其它Servlet之前。下面是一個例子，代碼如下：
package org.javaresearch.log4j;
import java.io.*;
import javax.servlet.*;
import org.apache.log4j.*;
public class Log4JInit extends HttpServlet {
public void init() throws ServletException {
??String prefix = getServletContext().getRealPath("/");
??String file = getServletConfig().getInitParameter("log4j-config-file");
??// 從Servlet參數讀取log4j的配置文件
??if (file != null) {
?? PropertyConfigurator.configure(prefix + file);
??}
}
public void doGet(HttpServletRequest request,HttpServletResponse response)throws
IOException, ServletException {}
public void doPost(HttpServletRequest request,HttpServletResponse response)throws
IOException, ServletException {}
}
<servlet>
??<servlet-name>log4jinit</servlet-name>
?? <servlet-class>org.javaresearch. log4j.Log4JInit</servlet-class>??????????????????
?? <init-param>
?? <param-name> log4j-config-file </param-name>
????????<param-value>/properties/log4j.properties</param-value>
?? </init-param>
?? <load-on-startup>1</load-on-startup>
??</servlet>
注意：上面的load-on-startup應設為1，以便在Web容器啟動時即裝入該Servlet。log4j.properties文件放在根的properties子目錄中，也可以把它放在其它目錄中。應該把.properties文件集中存放，這樣方便管理。
高級話題
性能
在記錄一些日志信息時，會一定程度地影響系統的運行效率，這時日志工具是否高效就是一個關鍵。Log4J的首要設計目標就是高效，一些關鍵組件都重寫過很多次以不斷提高性能。根據Log4J項目小組的報告，在AMD Duron 800MHz ＋ JDK1.3.1的環境下，Log4J判斷一條日志語句是否需要輸出僅需要5納秒。實際的日志語句執行的也非常快速，從使用SimpleLayout的21微秒（幾乎與System.out.println一樣快），到使用TTCCLayout的37微秒不等。
嵌套診斷環境NDC
在多用戶并發的環境下，通常是由不同的線程分別處理不同的客戶端請求。此時要在日志信息中區分出不同的客戶端，你可以為每一個線程生成一個Logger，從而從一堆日志信息中區分出哪些信息是屬于哪個線程的，但這種方式并不高效。Log4J巧妙地使用了Neil Harrison提出的“NDC（嵌套診斷環境）”機制來解決這個問題。Log4J為同一類別的線程生成一個Logger，多個線程共享使用，而它僅在日志信息中添加能夠區分不同線程的信息。NDC是什么？舉例來說，如果一個Servlet接到并發請求時，為每一個客戶端創建一個新的線程，然后分配一個用于保存該請求上下文的NDC堆棧。該上下文可能是發出請求的主機名、IP地址或其它任何可以用于標識該請求的信息。這樣，由于不同的客戶端處理線程具有不同的NDC堆棧，即使這個Servlet同時生成多個線程處理不同的請求，這些日志信息仍然可以區分出來，就好像Log4J為每一個線程都單獨生成了一個Logger實例一樣。在Log4J中是通過org.apache.log4j.NDC實現這種機制的。使用NDC的方法也很簡單，步驟如下：
1. 在進入一個環境時調用NDC.push(String)，然后創建一個NDC；
2. 所做的日志操作輸出中包括了NDC的信息；
3. 離開該環境時調用NDC.pop方法；
4. 當從一個線程中退出時調用NDC.remove方法，以便釋放資源。
下面是一個模擬記錄來自不同客戶端請求事件的例子，代碼如下：
import org.apache.log4j.Logger;
import org.apache.log4j.NDC;
public class TestNDC {
static Logger log = Logger.getLogger(TestNDC.class.getName());
public static void main(String[] args) {
??log.info("Make sure %x is in your layout pattern!");
??// 從客戶端獲得IP地址的例子
??String[] ips = {"192.168.0.10","192.168.0.27"};
??for (int i = 0; i<ips.length ; i++)??// 模擬一個運行方法
??{
?? // 將IP放進 NDC中
?? NDC.push(ips[i]);
?? log.info("A NEW client connected, who's ip should appear in this log message.");
?? NDC.pop();
??}
??NDC.remove();
??log.info("Finished.");
}
}
注意配置文件中的布局格式中一定要加上%x。系統輸出如下：
INFO?? - Make sure %x is in your layout pattern!
INFO??192.168.0.10 - A NEW client connected, who's ip should appear in this log
message.
INFO??192.168.0.27 - A NEW client connected, who's ip should appear in this log
message.
INFO?? - Finished.
使用Log4J還是JDK logging API
從JDK 1.4.0開始，引入了java.util.logging包。雖然Log4J小組曾竭力游說JCP（Java Community Process）采用Log4J作為JDK 1.4的“標準”日志API，雖然最終因Sun的日志API規范的負責人Graham Hamilton的一句“Merlin的開發已經到了最后階段，這時不允許再對主要API做出改變”而沒有被采納，但Log4J還是對新的日志API產生了重要影響。那么，我們到底應該采用Log4J還是java.util.logging包呢？下面僅對兩者做一簡單的比較。
1. Log4J更加成熟，從1999年10月開始至今已經有3年的時間，并且已經在許多項目中有著成熟的應用。而JDK中的logging包是在1.4之后才引入的，并且不能運行于JDK 1.3之前的版本。Log4J則可以良好地運行于JDK 1.1之后的所有版本。
2. Log4J已經被移植到多種環境下，包括log4c（C）、log4cpp（C++）、log4perl（Perl）、log4net（.net）等。在這些環境下，可以感受到幾乎一致的配置和使用方式。這是JDK中的logging API所不能比擬的。
3. Log4J還具有更加強力的格式化系統，可以使記錄輸出時實現簡單的模式。但是，它不會增加類而導致格式化工具的擴展。眾多的附加程序和處理器使得Log4J數據包成為一個絕佳的選擇，所有你所需要的都可能加以實現。
4. Log4J在性能上做了最大的優化。
Logging API對于簡單的使用是足夠的，但它缺少了許多Log4J所具有的功能。所以，如果你需要一個強力的logging機制，就應堅持使用Log4J；而如果只是需要一些簡單的控制或文件記錄，那么可以使用已經內建在JDK之中的logging API。
雖然Log4J和JDK logging API是一種競爭關系，但在logging API還在JCP中討論（JSR47）時，兩者之間就已經開始相互影響了。
FAQ
1. 如何讓Log4J使用指定的配置文件
在啟動你的應用時植入系統屬性。例如，可以把上面的log4j.properties文件放到\properties的相對路徑下，并改名為log.properties，此時如果讓Log4J能夠找到這個配置文件并正確地初始化，需要這樣運行程序：
D:\..\java -Dlog4j.configuration=. \properties\log.properties YourAppName
為什么一定要使用系統屬性，而不在配置文件中指定呢？很顯然，如果把它寫入配置文件，那么，Log4J讀到它時已經遲了。
2. 如何查看到Log4J的配置過程
可以類似1中的那樣，設置系統屬性log4j.debug=true，從而打開Log4J的Verbose模式，此時會輸出Log4J的初始化過程，這樣就會對Log4J的啟動有一個更詳細的了解。下面是Log4J啟動信息的一個示例：
log4j: Trying to find [log4j.xml] using context classloader
sun.misc.Launcher$AppClassLoader@92e78c.
log4j: Trying to find [log4j.xml] using sun.misc.Launcher$ExtClassLoader@9fbe93class
loader.
log4j: Trying to find [log4j.xml] using ClassLoader.getSystemResource().
log4j: Trying to find [log4j.properties] using context classloader
sun.misc.Launcher$AppClassLoader@92e78c.
log4j: Using URL [file:/D:/java/logging/src/log4j.properties] for automatic log4j
configuration.
log4j: Reading configuration from URL file:/E:/java/logging/src/log4j.properties
log4j: Parsing for [root] with value=[DEBUG, A1].
log4j: Level token is [DEBUG].
log4j: Category root set to DEBUG
log4j: Parsing appender named "A1".
log4j: Parsing layout options for "A1".
log4j: Setting property [conversionPattern] to [%d %l %-5p %c [%t] - %m%n].
log4j: End of parsing for "A1".
log4j: Parsed "A1" options.
log4j: Finished configuring.
......??// 下面就是應用的日志信息，省略。