封裝SLF4J/Log4j,不再處處定義logger變量
自從開(kāi)始使用日志組件后, 每個(gè)類都是這樣子的結(jié)構(gòu):
- public class A {
 - public static final Logger logger = LoggerFactory.getLogger(A.class);
 - }
 
這是一件相當(dāng)煩人事,必須對(duì)他進(jìn)行封裝,使得我們能夠通過(guò)這樣的方法來(lái)調(diào)用:
- public class A {
 - public void methodA() {
 - Logger.debug("Nice!");
 - }
 - }
 
最簡(jiǎn)單的版本
開(kāi)始動(dòng)手后,用最簡(jiǎn)單的方法封裝出了***個(gè)版本:
- // cn.hjktech.slf4j.Logger
 - public class Logger {
 - private static final org.slf4j.Logger logger = LoggerFactory.getLogger(Logger.class);;
 - ...
 - public static void debug(...) {
 - logger.debug(...);
 - ...
 - }
 - ...
 - }
 
看起來(lái)很美好, 但測(cè)試后發(fā)現(xiàn)這種方法會(huì)有一個(gè)很嚴(yán)重的問(wèn)題: 我們打印的日志通暢都帶有調(diào)用方的信息, 如類名、方法名、行數(shù)、時(shí)間等,其中類名、方法名、行數(shù)都是極其關(guān)鍵的信息,但是使用上述的方法來(lái)輸出日志的話,這三個(gè)信息都變成Logger這個(gè)類的信息,而不是調(diào)用方的信息, 這顯然是無(wú)法忍受的事。
當(dāng)然不能就這樣了事,既然正常使用的方法能輸出正確的信息,那么肯定是有辦法可以實(shí)現(xiàn)的,我們希望最終的結(jié)果是調(diào)用Logger.debug(..)打印出來(lái)的信息都是完全正確的。
分析源碼
此時(shí)寫個(gè)demo來(lái)debug跟進(jìn)一下:
- public class TestLog {
 - @Test
 - public void logTest() {
 - // 在此處打斷點(diǎn)
 - LoggerFactory.getLogger(TestLog.class).debug("看看執(zhí)行流程");
 - }
 - }
 
發(fā)現(xiàn)最終輸出的日志字符串是在PatternLayout.format方法(Logback則是PatternLayoutBase.writeLoopOnConverters方法)中生成的,方法代碼如下:
- // Log4j
 - public String format(LoggingEvent event) {
 - // Reset working stringbuffer
 - if(sbuf.capacity() > MAX_CAPACITY) {
 - sbuf = new StringBuffer(BUF_SIZE);
 - } else {
 - sbuf.setLength(0);
 - }
 - PatternConverter c = head;
 - while(c != null) {
 - c.format(sbuf, event);
 - c = c.next;
 - }
 - return sbuf.toString();
 - }
 
其中head指向一個(gè)類型為PatternConverter(Logback中是: Converter)的鏈表,這個(gè)鏈表的節(jié)點(diǎn)是在日志類初始化的時(shí)候,根據(jù)你日志配置文件里的ConversionPattern生成的,比如我的log4j.properties中是這樣配置的:
- log4j.appender.SOUT_LOGGER.layout.ConversionPattern=%d{yyyy-MM-dd-HH-mm,SSS} %p [%c] [%t] (%F:%L) %l - %m%n
 
那么這個(gè)鏈表的結(jié)構(gòu)就是(括號(hào)中代表存儲(chǔ)的信息):
- DatePatternConverter(時(shí)間點(diǎn)) -> LiteralPatternConverter(" ") ->
 - BasicPatternConverter(LEVEL) -> LiteralPatternConverter("[") ->
 - CategoryPatternConverter(LoggerName) -> LiteralPatternConverter("] [") ->
 - BasicPatternConverter(線程名) -> LiteralPatternConverter("] (") ->
 - LocationPatternConverter(所在類) -> LiteralPatternConverter(":") ->
 - LocationPatternConverter(所在行) -> LiteralPatternConverter(") -") ->
 - BasicPatternConverter(日志串) -> LiteralPatternConverter("\n") ->
 
根據(jù)這個(gè)鏈表生成日志字符串類似這樣:
- 2016-10-17-13-42,449 DEBUG [TestLog] [main] (TestLog.java:14) - Excuse me?
 
那么現(xiàn)在目標(biāo)很明確了,我們要使LocationPatternConverter的輸出為我們真正打印紙日的類的信息,繼續(xù)跟進(jìn)到PatternConverter.format(LocationPatternConverter的父類)方法,其內(nèi)部生成了一個(gè)LocationInfo對(duì)象,該類的構(gòu)造方法中如下:
- for(int i = elements.length - 1; i >= 0; i--) {
 - // 獲取第i幀的類名
 - String thisClass = (String) getClassNameMethod.invoke(elements[i], noArgs);
 - if(fqnOfCallingClass.equals(thisClass)) {
 - // 如果類名和fqnOfCallingClass相等,則認(rèn)為i + 1幀是代碼中實(shí)際調(diào)用方法的
 - int caller = i + 1;
 - if (caller < elements.length) {
 - // 記錄實(shí)際調(diào)用類的類名
 - className = prevClass;
 - // 記錄實(shí)際調(diào)用的方法名
 - methodName = (String) getMethodNameMethod.invoke(elements[caller], noArgs);
 - // 記錄實(shí)際調(diào)用類所在的文件名
 - fileName = (String) getFileNameMethod.invoke(elements[caller], noArgs);
 - if (fileName == null) {
 - fileName = NA;
 - }
 - // 記錄調(diào)用日志方法的行數(shù)
 - int line = ((Integer) getLineNumberMethod.invoke(elements[caller], noArgs)).intValue();
 - if (line < 0) {
 - lineNumber = NA;
 - } else {
 - lineNumber = String.valueOf(line);
 - }
 - // 拼接成最終要輸出到日志的字符串, 如:TestLog.logTest(TestLog.java:14)
 - 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;
 - }
 
其中elements是當(dāng)前方法調(diào)用棧的堆棧軌跡,這段代碼通過(guò)遍歷堆棧軌跡每一幀的類名并和fqnOfCallingClass比較,如果相符的話,則認(rèn)為它的上一幀是實(shí)際調(diào)用方法。
如下圖中,fqnOfCallingClass的值是org.slf4j.impl.Log4jLoggerAdapter,而在堆棧軌跡總可以發(fā)現(xiàn)類的上一個(gè)幀正好是我們的實(shí)際調(diào)用類TestLog.logTest:
因此,我們現(xiàn)在只需要讓fqnOfCallingClass的值變成我們封裝的日志類cn.hjktech.slf4j.Logger就大功告成了。fqnOfCallingClass是LoggingEvent.getLocationInformation創(chuàng)建LocationInfo時(shí)傳入的參數(shù),而LoggingEvent又是在Category.forcedLog方法中創(chuàng)建的,并且繼續(xù)網(wǎng)上追蹤,會(huì)發(fā)現(xiàn)fqnOfCallingClass的值最終來(lái)源于org.slf4j.impl.Log4jLoggerAdapter這個(gè)類:
- public final class Log4jLoggerAdapter extends MarkerIgnoringBase implements LocationAwareLogger, Serializable {
 - ...
 - static final String FQCN = Log4jLoggerAdapter.class.getName();
 - ...
 - }
 
而如果沒(méi)有配合SLF4J使用時(shí),fqnOfCallingClass的值則來(lái)源于org.apache.log4j.Logger類:
- public class Logger extends Category {
 - ...
 - private static final String FQCN = Logger.class.getName();
 - ....
 - }
 
代理Logger類來(lái)修改FQCN
好了,現(xiàn)在我們只需要修改這個(gè)值就行了。***反應(yīng)是使用反射去掉final修飾符,然后修改它的值,這種方法雖然對(duì)我們自己的代碼可行,但是當(dāng)引入其它框架,并且其它框架也使用的Log4j時(shí),就會(huì)導(dǎo)致它們的日志信息出錯(cuò),因?yàn)樗鼈儾⒉皇钦{(diào)用的我們封裝的Logger工具類,它們?nèi)罩镜亩褩\壽E中不會(huì)有我們工具類(如cn.hjktech.slf4j.Logger),因此我們需要另尋它法。
既然通過(guò)反射行不通, 那么我們可以通過(guò)動(dòng)態(tài)代理的方式,在構(gòu)造LoggingEvent對(duì)象之前將FQCN這個(gè)參數(shù)的值給替換掉,在跟蹤過(guò)程中發(fā)現(xiàn)Log4jLoggerAdapter最終都是調(diào)用的org.apache.log4j.Logger.log方法并將FQCN最為參數(shù)傳入,因此org.apache.log4j.Logger這個(gè)類就是我們要代理的類了。
了解JDK代理的人都知道,使用的條件是被代理類必須實(shí)現(xiàn)某一個(gè)接口,而org.apache.log4j.Logger.log這個(gè)方法并不是來(lái)自于某一個(gè)接口,所以我們選擇使用Cglib:
- // cn.hjktech.slf4j.Logger
 - public class Logger {
 - private static org.slf4j.Logger logger;
 - private static final String FQCN = Logger.class.getName();
 - static {
 - try {
 - Enhancer eh = new Enhancer();
 - eh.setSuperclass(org.apache.log4j.Logger.class);
 - eh.setCallbackType(LogInterceptor.class);
 - Class c = eh.createClass();
 - Enhancer.registerCallbacks(c, new LogInterceptor[]{new LogInterceptor()});
 - Constructor<org.apache.log4j.Logger> constructor = c.getConstructor(String.class);
 - org.apache.log4j.Logger loggerProxy= constructor.newInstance(Logger.class.getName());
 - ...
 - } catch (...) {
 - throw new RuntimeException("初始化Logger失敗", e);
 - }
 - }
 - private static class LogInterceptor implements MethodInterceptor {
 - public Object intercept(Object o, Method method, Object[] objects, MethodProxy methodProxy) throws Throwable {
 - // 只攔截log方法。
 - if (objects.length != 4 || !method.getName().equals("log"))
 - return methodProxy.invokeSuper(o, objects);
 - // 替換傳給log方法的***個(gè)參數(shù)為我們自定義的FQCN
 - objects[0] = FQCN;
 - return methodProxy.invokeSuper(o, objects);
 - }
 - }
 - }
 
代理defaultFactory
現(xiàn)在我們已經(jīng)有了被代理的loggerProxy對(duì)象了,我們還需要將這個(gè)對(duì)象賦值給Log4jLoggerAdapter的logger成員變量,
logger成員變量是在Log4jLoggerAdapter的構(gòu)造方法中被作為參數(shù)傳入的,它的來(lái)源如下圖:
從上圖中可以看到,LogManager.getLoggerRepository方法返回的對(duì)象中持有defaultFactory對(duì)象,因此我還需要代理這個(gè)對(duì)象,將它產(chǎn)生的'logger'對(duì)象替換成我們的'logger'就大功告成了,并且makeNewLoggerInstance方法是在LoggerFactory接口中定義的,所以我們只需要使用JDK的動(dòng)態(tài)代理就可以完成了。實(shí)現(xiàn)代碼如下:
- static {
 - try {
 - ...
 - LoggerRepository loggerRepository = LogManager.getLoggerRepository();
 - org.apache.log4j.spi.LoggerFactory lf = ReflectionUtil.getFieldValue(loggerRepository, "defaultFactory");
 - Object loggerFactoryProxy = Proxy.newProxyInstance(
 - LoggerFactory.class.getClassLoader(),
 - new Class[]{LoggerFactory.class},
 - new NewLoggerHandler(loggerProxy)
 - );
 - ReflectionUtil.setFieldValue(loggerRepository, "defaultFactory", loggerFactoryProxy);
 - logger = org.slf4j.LoggerFactory.getLogger(Logger.class.getName());
 - ReflectionUtil.setFieldValue(loggerRepository, "defaultFactory", lf);
 - } catch (...) {
 - throw new RuntimeException("初始化Logger失敗", e);
 - }
 - }
 - private static class NewLoggerHandler implements InvocationHandler {
 - private final org.apache.log4j.Logger proxyLogger;
 - public NewLoggerHandler(org.apache.log4j.Logger proxyLogger) {
 - this.proxyLogger = proxyLogger;
 - }
 - @Override
 - public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
 - return proxyLogger;
 - }
 - }
 
實(shí)現(xiàn)流程和最終代碼
我們最終實(shí)現(xiàn)方案如下:
Logger的代碼如下:
- public class Logger {
 - private static org.slf4j.Logger logger;
 - private static final String FQCN = Logger.class.getName();
 - static {
 - try {
 - Enhancer eh = new Enhancer();
 - eh.setSuperclass(org.apache.log4j.Logger.class);
 - eh.setCallbackType(LogInterceptor.class);
 - Class c = eh.createClass();
 - Enhancer.registerCallbacks(c, new LogInterceptor[]{new LogInterceptor()});
 - Constructor<org.apache.log4j.Logger> constructor = c.getConstructor(String.class);
 - org.apache.log4j.Logger loggerProxy = constructor.newInstance(Logger.class.getName());
 - LoggerRepository loggerRepository = LogManager.getLoggerRepository();
 - org.apache.log4j.spi.LoggerFactory lf = ReflectionUtil.getFieldValue(loggerRepository, "defaultFactory");
 - Object loggerFactoryProxy = Proxy.newProxyInstance(
 - LoggerFactory.class.getClassLoader(),
 - new Class[]{LoggerFactory.class},
 - new NewLoggerHandler(loggerProxy)
 - );
 - ReflectionUtil.setFieldValue(loggerRepository, "defaultFactory", loggerFactoryProxy);
 - logger = org.slf4j.LoggerFactory.getLogger(Logger.class.getName());
 - ReflectionUtil.setFieldValue(loggerRepository, "defaultFactory", lf);
 - } catch (
 - IllegalAccessException |
 - NoSuchMethodException |
 - InvocationTargetException |
 - InstantiationException e) {
 - throw new RuntimeException("初始化Logger失敗", e);
 - }
 - }
 - private static class LogInterceptor implements MethodInterceptor {
 - public Object intercept(Object o, Method method, Object[] objects, MethodProxy methodProxy) throws Throwable {
 - // 只攔截log方法。
 - if (objects.length != 4 || !method.getName().equals("log"))
 - return methodProxy.invokeSuper(o, objects);
 - objects[0] = FQCN;
 - return methodProxy.invokeSuper(o, objects);
 - }
 - }
 - private static class NewLoggerHandler implements InvocationHandler {
 - private final org.apache.log4j.Logger proxyLogger;
 - public NewLoggerHandler(org.apache.log4j.Logger proxyLogger) {
 - this.proxyLogger = proxyLogger;
 - }
 - @Override
 - public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
 - return proxyLogger;
 - }
 - }
 - // 剩下的Logger需要封裝的方法可以根據(jù)自己的需要來(lái)實(shí)現(xiàn)
 - // 我個(gè)人認(rèn)為slf4j的api足夠好用了,所以大部分只是寫了一些類似下面的代碼
 - public static void debug(String msg) {
 - logger.debug(msg);
 - }
 - }
 
ReflectionUtil的代碼如下:
- public class ReflectionUtil {
 - public static <T> T getFieldValue(@NotNull Object object,
 - @NotNull String fullName) throws IllegalAccessException {
 - return getFieldValue(object, fullName, false);
 - }
 - public static <T> T getFieldValue(@NotNull Object object,
 - @NotNull String fieldName,
 - boolean traceable) throws IllegalAccessException {
 - Field field;
 - String[] fieldNames = fieldName.split("\\.");
 - for (String targetField : fieldNames) {
 - field = searchField(object.getClass(), targetField, traceable);
 - if (field == null)
 - return null;
 - object = getValue(object, field);
 - }
 - return (T) object;
 - }
 - private static Field searchField(Class c, String targetField, boolean traceable) {
 - do {
 - Field[] fields = c.getDeclaredFields();
 - for (Field f : fields) {
 - if (f.getName().equals(targetField)) {
 - return f;
 - }
 - }
 - c = c.getSuperclass();
 - traceable = traceable && c != Object.class;
 - } while (traceable);
 - return null;
 - }
 - private static <T> T getValue(Object target, Field field) throws IllegalAccessException {
 - if (!field.isAccessible())
 - field.setAccessible(true);
 - return (T) field.get(target);
 - }
 - public static boolean setFieldValue(@NotNull Object target,
 - @NotNull String fieldName,
 - @NotNull Object value) throws IllegalAccessException {
 - return setFieldValue(target, fieldName, value, false);
 - }
 - public static boolean setFieldValue(@NotNull Object target,
 - @NotNull String fieldName,
 - @NotNull Object value,
 - boolean traceable) throws IllegalAccessException {
 - Field field = searchField(target.getClass(), fieldName, traceable);
 - if (field != null)
 - return setValue(field, target, value);
 - return false;
 - }
 - private static boolean setValue(Field field, Object target, Object value) throws IllegalAccessException {
 - if (!field.isAccessible())
 - field.setAccessible(true);
 - field.set(target, value);
 - return true;
 - }
 - }
 
測(cè)試
- public class TestLog {
 - @Test
 - public void logTest() {
 - Logger.debug((Marker)null, "這是調(diào)用封裝的Logger輸出日志");
 - LoggerFactory.getLogger(TestLog.class).info("常規(guī)方法輸出日志");
 - }
 - }
 
輸出結(jié)果:
- 2016-10-19-15-00,308 DEBUG [cn.hjktech.slf4j.Logger] [main] (TestLog.java:13) TestLog.logTest(TestLog.java:13) - 這是調(diào)用封裝的Logger輸出日志
 - 2016-10-19-15-00,311 INFO [TestLog] [main] (TestLog.java:14) TestLog.logTest(TestLog.java:14) - 常規(guī)方法輸出日志
 


















 
 
 










 
 
 
 