本文是結合項目中使用Log4j總結的最佳實踐，非轉載。網上可以找到的是這一篇《Log4j最佳實踐》。本來Log4j使用是非常簡單的，無需多介紹其用法，這只是在小型項目中；但在大型的項目中使用log4j不太一樣。大型項目非常依賴日志，因為解決線上問題必須依靠log，依靠大量的日志！線上出現問題往往不能重現，而且無法調試，log是必須中的必須，解決線上問題全靠它。本文內容：
- 大型項目中Log4j的使用注意點
- Log4j為性能考慮的注意點
- a). 避免輸出'%C', '%F', '%L' '%M' 等位置信息
- b). 使用異步（異步寫文件，異步寫數據庫）
- 把ERROR信息輸出到單獨的文件
- 在基類寫log4j日志要注意的問題
- Log4j基礎知識
- Log4j的AsyncAppender存在的嚴重問題
大型項目中Log4j的使用注意點
在大型項目中使用Log4j要注意下面幾點：
- 不能因為寫log使得系統性能變慢（最好使用異步）
- log能易於定位問題，log要能體現何時（精確到毫秒級）、在哪（包、機器、類、函數、行、文件等）、發生了什么問題、以及嚴重性
- log要易於自動、手工、半自動分析（如記錄文件太大則不能打開分析，寫數據庫等）
- 能根據模塊/包來動態單獨配置log級別（FATAL – ERROR – WARNING – INFO – DEBUG - TRACE） 和單獨配置輸出文件等
- 可以用grep分析出獨立的行，盡量不要分行
- 有時調試線上問題還需要非常豐富的信息，例如：進入模塊和函數的入口參數信息、完成某項操作耗費的時間、SessionID、機器IP地址和端口號、版本號、try{}catch{}里面的StackTrace信息。
- 大型系統的日志文件應該定期用gzip壓縮並移動到一個專門的檔案日志服務器。應該每天晚上，或者每小時這樣做一次。
- 不要隨便從網上復制一個Log4j的配置文件，你必須深入理解里面的每一個配置項代表的含義！
- 如果你拼裝的動作比較耗資源，請用if ( log.isDebugEnabled() )
- 千萬不要try{}catch{}了異常卻沒有記錄日志
- 不要僅記錄到數據庫，記錄文件更加可靠，因為記錄到數據庫可能發生網絡和數據庫異常，沒有記錄本地磁盤可靠。
例如下面這個啟動日志包含了版本號、耗費時間、userID等等豐富的信息：
Log4j為性能考慮的注意點
為系統性能考慮，使用Log4j注意下列幾點：
- 避免輸出'%C', '%F', '%L' '%M' 等位置信息
- 盡量使用異步
- 為每個模塊設置單獨的輸出文件
- 每次調用前檢查if(logger.isDebugEnabled()){ logger.debug(……) }
a). 避免輸出'%C', '%F', '%L' '%M' 等位置信息
當配置文件中的配置項包含Location信息時候會非常昂貴，因此，需要避免'C', 'F', 'L' 'M' 等位置信息的記錄（參數配置項詳細說明）。
- %C - 輸出類名
- %F - 輸出文件名
- %L - 輸出行號
- %M - 輸出函數名
（注意：當配置為異步輸出的時候，以上位置信息可能會顯示為問號？，因為是在另外一個線程記錄的調用信息。此時，我們可以使用下面的方法來獲取類名和函數名：
StackTraceElement se = Thread.currentThread().getStackTrace()[2]; String msg = se.getClassName() + "-[" + se.getMethodName() + "] " + errorMessage;
）
b). 使用異步（異步寫文件，異步寫數據庫）
Log4j異步寫可以使用默認的appender：org.apache.log4j.AsyncAppender，配置文件log4j.xml樣例：
<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j='http://jakarta.apache.org/log4j/' debug="false">
<appender name="DAILY_FILE" class="org.apache.log4j.DailyRollingFileAppender">
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss,SSS} %5p %c %x - %m%n"/>
</layout>
<param name="File" value="log/log4j.log"/>
<param name="DatePattern" value="'.'yyyy-MM-dd"/>
</appender>
<appender name="ASYNC_FILE" class="org.apache.log4j.AsyncAppender">
<param name="BufferSize" value="10000"/>
<param name="Blocking" value="false"/>
<appender-ref ref="DAILY_FILE"/>
</appender>
<appender name="DB_OUT" class="org.apache.log4j.jdbc.JDBCAppender">
<param name="URL" value="jdbc:postgresql://192.168.1.34:5432/myDB" />
<param name="Driver" value="org.postgresql.Driver"/>
<param name="User" value="aaa"/>
<param name="Password" value="bbb"/>
<param name="Sql" value="INSERT INTO tracelog (ModuleName ,LoginID,UserName,Class, Method,createTime,LogLevel,MSG) values ('%c', '','','','','%d{yyyy-MM-dd HH:mm:ss,SSS}','%p','%m')"/>
</appender>
<appender name="ASYNC_DB" class="org.apache.log4j.AsyncAppender">
<param name="BufferSize" value="10000"/>
<param name="Blocking" value="false"/>
<appender-ref ref="DB_OUT"/>
</appender>
<root>
<level value="info"/>
<appender-ref ref="ASYNC_DB" />
<appender-ref ref="ASYNC_FILE" />
</root>
<logger name="PACKAGE_1" additivity="false">
<level value="info"/>
<appender-ref ref="ASYNC_DB" />
<appender-ref ref="ASYNC_FILE" />
</logger>
<logger name="PACKAGE_2" additivity="false">
<level value="info"/>
<appender-ref ref="ASYNC_DB" />
<appender-ref ref="ASYNC_FILE" />
</logger>
</log4j:configuration>
上面的配置文件包含異步寫文件和異步寫入postgreSQL數據庫的配置，默認是root，也有各個Package的配置。用的時候可以寫一個logUtil的類來初始化這個log4j.xml:
package com.ibm;
import org.apache.log4j.Logger;
import org.apache.log4j.xml.DOMConfigurator;
public class LogUtil implements ILogUtil {
public static LogUtil getInstance() {
if (instance == null)
instance = new LogUtil();
return instance;
}
@Override
public void init() {
//PropertyConfigurator.configure("conf/log4j.properties");
DOMConfigurator.configure("conf/log4j.xml");
}
@Override
public void close() {
}
@Override
public void logError(String errorMessage) {
logger.error(errorMessage.replace("'", "''"));
}
@Override
public void logWarn(String warnMessage) {
logger.warn(warnMessage.replace("'", "''"));
}
@Override
public void logInfo(String infoMessage) {
logger.info(infoMessage.replace("'", "''"));
}
@Override
public void logDebug(String debugMessage) {
logger.debug(debugMessage.replace("'", "''"));
}
@Override
public void logFatal(String fatalMessage) {
logger.fatal(fatalMessage.replace("'", "''"));
}
private LogUtil() {
}
private static Logger getPackageLogger(String packageName){
if(packageName.equals(PackageName.PACKAGE_1.toString()))
return Logger.getLogger(PackageName.PACKAGE_1.toString());
else if(packageName.equals(PackageName.PACKAGE_2.toString()))
return Logger.getLogger(PackageName.PACKAGE_2.toString());
else
return Logger.getRootLogger();
}
@Override
public void logError(String packageName, String errorMessage) {
getPackageLogger(packageName).error(errorMessage.replace("'", "''"));
}
@Override
public void logError(String packageName, String errorMessage,
Throwable exception) {
getPackageLogger(packageName).error(errorMessage.replace("'", "''"), exception);
}
@Override
public void logWarn(String packageName, String warnMessage) {
getPackageLogger(packageName).warn(warnMessage.replace("'", "''"));
}
@Override
public void logWarn(String packageName, String warnMessage,
Throwable exception) {
getPackageLogger(packageName).warn(warnMessage.replace("'", "''"), exception);
}
@Override
public void logInfo(String packageName, String infoMessage) {
getPackageLogger(packageName).info(infoMessage.replace("'", "''"));
}
@Override
public void logInfo(String packageName, String infoMessage,
Throwable exception) {
getPackageLogger(packageName).info(infoMessage.replace("'", "''"), exception);
}
@Override
public void logDebug(String packageName, String debugMessage) {
getPackageLogger(packageName).debug(debugMessage.replace("'", "''"));
}
@Override
public void logDebug(String packageName, String debugMessage,
Throwable exception) {
getPackageLogger(packageName).debug(debugMessage.replace("'", "''"), exception);
}
@Override
public void logFatal(String packageName, String fatalMessage) {
getPackageLogger(packageName).fatal(fatalMessage.replace("'", "''"));
}
@Override
public void logFatal(String packageName, String fatalMessage,
Throwable exception) {
getPackageLogger(packageName).fatal(fatalMessage.replace("'", "''"), exception);
}
private static Logger logger = Logger.getRootLogger();
private static LogUtil instance;
}
具體各個Package可以調用：
LogUtil.getInstance().logError("PACKAGE_1", "error message....", e);
（注意：寫數據庫的時候配置文件log4j.xml里面有一菊SQL，這個SQL在寫的message包含單引號或雙引號的時候會爆異常，所以需要把單引號或雙引號轉義為兩個單引號；我們自己的log可以控制，如果是例如Tomcat/jBoss寫的log的message包含單引號或雙引號的時候會寫數據庫異常，具體做法可以自定義JDBCAppender，參考這一片文章。自定義字段可以使用MDC和%X，參考這一片文章。）
上面的配置文件已經根據各個Package配置單獨的log輸出，可以配置為寫某個文件，或單獨寫數據庫，或是組合，都可以靈活根據自己的需要配置。
(AsyncAppender中BufferSize/默認128的含義：the number of messages allowed in the event buffer before the calling thread is blocked (if blocking is true) or until messages are summarized and discarded.)
JDBCAppender存在沒有數據庫連接池的問題，可以擴展一下JDBCAppender，引入第三方連接池例如C3P0:
package com.ibm.log4j.jdbcplus;
import org.apache.log4j.jdbc.JDBCAppender;
import org.apache.log4j.spi.LoggingEvent;
import java.sql.Connection;
import java.sql.SQLException;
import org.apache.log4j.spi.ErrorCode;
import com.codestudio.sql.PoolMan;
public class DBAppender extends JDBCAppender {
/**通過 PoolMan 獲取數據庫連接對象的 jndiName 屬性*/
protected String jndiName;
/**數據庫連接對象*/
protected Connection connection = null;
public DBAppender() {
super();
}
@Override
protected void closeConnection(Connection con) {
try {
if (connection != null && !connection.isClosed())
connection.close();
} catch (SQLException e) {
errorHandler.error("Error closing connection", e, ErrorCode.GENERIC_FAILURE);
}
}
@Override
protected Connection getConnection() throws SQLException {
try {
//通過 PoolMan 獲取數據庫連接對象(http://nchc.dl.sourceforge.net/project/poolman/PoolMan/poolman-2.1-b1/poolman-2.1-b1.zip)
Class.forName("com.codestudio.sql.PoolMan");
connection= PoolMan.connect("jdbc:poolman://" + getJndiName());
} catch (Exception e) {
System.out.println(e.getMessage());
}
return connection;
}
/**
* @return the jndiName
*/
public String getJndiName() {
return jndiName;
}
/**
* @param jndiName the jndiName to set
*/
public void setJndiName(String jndiName) {
this.jndiName = jndiName;
}
@Override
public void append(LoggingEvent event) {
if (event.getMessage() != null)
event.getMessage().toString().replace("'", "''");
// if (event.getThrowableInformation() != null)
// event.getThrowableInformation().toString().replace("'", "''");
buffer.add(event);
if (buffer.size() >= bufferSize)
flushBuffer();
}
}
把ERROR信息輸出到單獨的文件
如果你的日志級別是INFO，想把ERROR log輸出到單獨的文件，可以這樣配置：
<appender name="ERROR_FILE"> <param name="Threshold" value="ERROR"/> </appender> <appender name="GENERAL"> <param name="Threshold" value="INFO"/> </appender> <logger name="com.acme"> <level value="INFO"/> <appender-ref ref="ERROR_FILE"/> <appender-ref ref="GENERAL"/> </logger>
在基類寫log4j日志要注意的問題
最后要注意的是，如果你把寫日志這部分封裝到一個獨立的jar包模塊里面（在基類或者靜態類里面寫日志），就會導致輸出的類名、函數名都是基類的類名和函數名，這將是重大的錯誤。因為下面的這行：
private static Logger log = Logger.getLogger( MyClass.class );
如果你獲得的是基類的logger那就永遠是基類的logger。這一點需要注意.
Log4j基礎知識
如果你對Log4j基礎不熟悉，建議你學習一下什么是log4j里面的logger, root logger, appender, configuration、Additivity和layout.
SocketAppender / JMSAppender
除了AsyncAppender,你還可以使用SocketAppender, JMSAppender...和其它各種log4j的appender。當然，除了log4j，你也可以轉到slf4j, logBack.
Log4j的AsyncAppender存在的嚴重問題
Log4j的異步appender也就是AsyncAppender存在性能問題（現在Log4j 2.0 RC提供了一種新的異步寫log的機制(基於disruptor)來試圖解決問題），問題是什么呢？異步寫log有一個buffer的設置，也就是當隊列中多少個日志的時候就flush到文件或數據庫，當配置為blocking=true的時候，當你的應用寫日志很快，log4j的緩沖隊列將很快充滿，當它批量flush到磁盤文件的時候，你的磁盤寫入速度很慢，會發生什么情況？是的，隊列阻塞，寫不進去了，整個log4j阻塞了，始終等待隊列寫入磁盤/DB，整個異步線程死了變成同步的了？而當配置為blocking=false的時候，不會阻塞但會扔出異常並丟棄消息。你是希望log4j死掉，還是希望后續消息被丟棄？都是問題。
當然，一個辦法是把緩沖bufferSize設大一點。最好的解決辦法：1、自己實現消息隊列和自定義的AsyncAppender； 2. 等log4j 2.0 成熟發布。
（注：log4j 2 由於采用了LMAX Disruptor，性能超過原來AsyncAppender幾個數量級，支持每秒並發寫入1800萬條日志）