slf4j對於log4j的日誌封裝-正確獲取呼叫堆疊
日誌是專案中必用的東西，日誌產品裡最普及應該就是log4j了。(logback這裡暫不討論。) 先看一下常用的log4j的用法，一般來說log4j都會配合slf4j或者common-logging使用，這裡已slf4j為例。新增gradle依賴：
dependencies {
compile('log4j:log4j:1.2.17',
'org.slf4j:slf4j-api:1.7.5',
'org.slf4j:slf4j-log4j12:1.7.5')
}
最直接的用法就是在每個需要記錄日誌的類裡，構造一個屬於自己類的log例項，實際上很多著名的開源專案也是這麼做的。如spring。
private static final Log logger = LogFactory.getLog(BeanUtils.class);
那麼我們也先從這種用法開始，先配置好最基本的log4j.xml配置檔案。
<?xml version= "1.0" encoding ="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "http://log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" >
<appender 引數說明：
%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 輸出日誌事件的發生位置，包括類目名、發生的執行緒，以及在程式碼中的行數。
日誌測試類：
package com.coderli.log4jpackage;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
/**
* log4j封裝實驗室中的使用者模擬類
*
* @author OneCoder
* @date 2013年11月25日 下午4:39:19
*/
public class UserClass {
private static final Logger logger = LoggerFactory
. getLogger(UserClass.class);
public static void main(String[] args) {
logger.info("這是一個Info級別的log4j日誌。" );
}
}
輸出日誌：
2013-11-26 11:09:21,305 >> INFO >> main >> com.coderli.log4jpackage.UserClass.main(UserClass.java:18) >> 這是一個Info級別的log4j日誌。
這裡包含的日誌發生時的類、執行緒、行號等資訊。很完整。本身這麼做沒什麼問題，只是可能有的專案考慮如果每個類裡都寫這樣一個開頭，有點麻煩，同時，如果每個類一個獨立的宣告，log4j記憶體會快取很多的例項，佔用記憶體，可能有時候也不便於統一配置管理。所以，有些專案裡考慮了對log進行封裝，提供統一的一個靜態方法呼叫：
package com.coderli.log4jpackage;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
/**
* @author lihzh(OneCoder)
* @date 2013年11月25日 下午4:39:54
* @blog http://www.coderli.com
*/
public class MyLog4j {
private static final Logger logger = LoggerFactory.getLogger("MyLog4j");
public static void info(String msg) {
logger.info(msg);
}
}
記錄日誌程式碼變為：
/**
* log4j封裝實驗室中的使用者模擬類
*
* @author OneCoder
* @date 2013年11月25日 下午4:39:19
*/
public class UserClass {
public static void main(String[] args) {
MyLog4j. info("這是一個Info級別的log4j日誌。" );
}
}
日誌輸出：
2013-11-26 11:23:29,936 >> INFO >> main >> com.coderli.log4jpackage.MyLog4j.info(MyLog4j.java:16 ) >> 這是一個Info級別的log4j日誌。
咋一看沒什麼問題，仔細分析就發現，對我們除錯很有幫助的日誌發生時的類名、行號都程式設計了封裝類裡面的類和行，這對於依靠日誌進行錯誤除錯來說是悲劇的。這種封裝雖然解決了例項過多的問題，但是也是失敗的，甚至是災難性的。
也有人把發生日誌的Class資訊也傳遞進來一起列印。如：
public static void info(String className, String msg) {
logger.info(className + ">> " + msg);
}
這種方式顯然是治標不治本的。於是很多人想到了另外的封裝方式，即提供一個統一獲取logger例項的位置，然後在自己的類裡進行嗲用：
public static Logger getLogger() {
return logger;
}
呼叫程式碼：
public static void main(String[] args) {
MyLog4j. getLogger().info("這是一個Info級別的log4j日誌。" );
}
這種方法，日誌雖然恢復了正常，但是對於開發者實際又增加了麻煩，列印一個日誌需要兩部操作了。當然你可以使用import static。或者每個類裡還是全域性宣告一個logger例項。
那麼有沒有想過，slf4j內部是怎麼對log4j封裝的呢？我們通過slf4j呼叫為什麼就可以之間獲得你實際列印日誌的行號，同時又不會把自己類給暴露出來呢？你可能還沒明白我在說什麼，細說一下，如果我們直接使用log4j的logger，打印出來的是我們呼叫類的行號這沒什麼問題，但是這裡我們獲得的是slf4j的logger例項，它底層呼叫的是log4j的logger例項，那麼為什麼不會打印出slf4j內部呼叫類的行號呢？這就是我關心的問題。知道了這個，也許我們就可以封裝出更好用的全域性log元件了。
其實，這個問題的關鍵就集中在log4j是如何獲取你呼叫日誌的程式碼的類和行號的，在Java中可以通過Throwable來獲取呼叫堆疊, 例如我們將如下程式碼，放在MyLog4j類的info方法中：
public static void info(String msg) {
Throwable throwable = new Throwable();
StackTraceElement[] ste = throwable.getStackTrace();
for (StackTraceElement stackTraceElement : ste) {
System.out
.println("ClassName: " + stackTraceElement.getClassName());
System.out.println("Method Name: "
+ stackTraceElement.getMethodName());
System.out.println("Line number: "
+ stackTraceElement.getLineNumber());
}
logger.info(msg);
}
再次通過UserClass呼叫，就可獲得如下輸出：
ClassName: com.coderli.log4jpackage.MyLog4j
Method Name: info
Line number: 28
ClassName: com.coderli.log4jpackage.UserClass
Method Name: main
Line number: 12
由此可見只要在呼叫堆疊裡找到使用者的類，就可以獲得所有我們需要的資訊。有了這個基礎，我們再來看看slf4j和log4j是怎麼做的。
在log4j的Logger中，實際對外提供了用於封裝的統一的log方法。
/**
This is the most generic printing method. It is intended to be
invoked by <b>wrapper</b> classes.
@param callerFQCN The wrapper class' fully qualified class name.
@param level The level of the logging request.
@param message The message of the logging request.
@param t The throwable of the logging request, may be null. */
public
void log(String callerFQCN, Priority level, Object message, Throwable t）
而第一個引數callerFQCN，就是關鍵的決定呼叫者位置的引數。在LocationInfo中，可看到對該引數的使用方式為：
public LocationInfo(Throwable t, String fqnOfCallingClass) {
if(t == null || fqnOfCallingClass == null)
return;
if (getLineNumberMethod != null) {
try {
Object[] noArgs = null;
Object[] elements = (Object[]) getStackTraceMethod.invoke(t, noArgs);
String prevClass = NA;
for(int i = elements.length - 1; i >= 0; i--) {
String thisClass = (String) getClassNameMethod.invoke(elements[i], noArgs);
if(fqnOfCallingClass.equals(thisClass)) {
int caller = i + 1;
if (caller < elements.length) {
className = prevClass;
methodName = (String) getMethodNameMethod.invoke(elements[caller], noArgs);
fileName = (String) getFileNameMethod.invoke(elements[caller], noArgs);
if (fileName == null) {
fileName = NA;
}
int line = ((Integer) getLineNumberMethod.invoke(elements[caller], noArgs)).intValue();
if (line < 0) {
lineNumber = NA;
} else {
lineNumber = String.valueOf(line);
}
StringBuffer buf = new StringBuffer();
buf.append(className);
buf.append(".");
buf.append(methodName);
buf.append("(");
buf.append(fileName);
buf.append(":");
buf.append(lineNumber);
buf.append(")");
this.fullInfo = buf.toString();
}
return;
}
prevClass = thisClass;
}
return;
…….//省略若干
可見，log4j把傳遞進來的callerFQCN在堆疊中一一比較，相等後，再往上一層即認為是使用者的呼叫類。所以，在slf4j封裝的logger中是這樣封裝的：
final static String FQCN = Log4jLoggerAdapter.class .getName();
public void info(String msg) {
logger.log(FQCN, Level. INFO, msg, null );
}
使用者的程式碼呼叫的正是呼叫的這個info，所以就會正常的顯示使用者程式碼的行號了。那麼對於封裝來說，你只需要注意呼叫log4j的log方法，並傳遞進去正確的FQCN即可。
final static String FQCN = Log4jLoggerAdapter.class .getName();
public void info(String msg) {
logger.log(FQCN, Level. INFO, msg, null );
}