封装SLF4J/Log4j，不再处处定义logger变量
转载请注明出处: 封装SLF4J/Log4j，不再处处定义logger变量懒得看实现过程的可以直接跳到最后看实现流程图和代码实现。Logback和log4j是内部实现相似，所以可以用类似的思路实现。
自从开始使用日志组件后， 每个类都是这样子的结构:
public class A {
public static final Logger logger = LoggerFactory.getLogger(A.class);
}这是一件相当烦人事，必须对他进行封装，使得我们能够通过这样的方法来调用：
public class A {
public void methodA() {
Logger.debug("Nice!");
}
}最简单的版本
开始动手后，用最简单的方法封装出了第一个版本:
// cn.hjktech.slf4j.Logger
public class Logger {
private static final org.slf4j.Logger logger = LoggerFactory.getLogger(Logger.class);;
...
public static void debug(...) {
logger.debug(...);
...
}
...
}看起来很美好， 但测试后发现这种方法会有一个很严重的问题： 我们打印的日志通畅都带有调用方的信息， 如类名、方法名、行数、时间等，其中类名、方法名、行数都是极其关键的信息，但是使用上述的方法来输出日志的话，这三个信息都变成Logger这个类的信息，而不是调用方的信息， 这显然是无法忍受的事。
当然不能就这样了事，既然正常使用的方法能输出正确的信息，那么肯定是有办法可以实现的，我们希望最终的结果是调用Logger.debug(..)打印出来的信息都是完全正确的。
分析源码
此时写个demo来debug跟进一下：
public class TestLog {
@Test
public void logTest() {
// 在此处打断点
LoggerFactory.getLogger(TestLog.class).debug("看看执行流程");
}
}发现最终输出的日志字符串是在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指向一个类型为PatternConverter(Logback中是: Converter)的链表，这个链表的节点是在日志类初始化的时候，根据你日志配置文件里的ConversionPattern生成的，比如我的log4j.properties中是这样配置的:
log4j.appender.SOUT_LOGGER.layout.ConversionPattern=%d{yyyy-MM-dd-HH-mm,SSS} %p [%c] [%t] (%F:%L) %l - %m%n那么这个链表的结构就是(括号中代表存储的信息):
DatePatternConverter(时间点) -> LiteralPatternConverter(" ") ->
BasicPatternConverter(LEVEL) -> LiteralPatternConverter("[") ->
CategoryPatternConverter(LoggerName) -> LiteralPatternConverter("] [") ->
BasicPatternConverter(线程名) -> LiteralPatternConverter("] (") ->
LocationPatternConverter(所在类) -> LiteralPatternConverter(":") ->
LocationPatternConverter(所在行) -> LiteralPatternConverter(") -") ->
BasicPatternConverter(日志串) -> LiteralPatternConverter("\n") ->根据这个链表生成日志字符串类似这样: 2016-10-17-13-42,449 DEBUG [TestLog] [main] (TestLog.java:14) - Excuse me?
那么现在目标很明确了，我们要使LocationPatternConverter的输出为我们真正打印纸日的类的信息，继续跟进到PatternConverter.format(LocationPatternConverter的父类)方法，其内部生成了一个LocationInfo对象，该类的构造方法中如下：
for(int i = elements.length - 1; i >= 0; i--) {
// 获取第i帧的类名
String thisClass = (String) getClassNameMethod.invoke(elements[i], noArgs);
if(fqnOfCallingClass.equals(thisClass)) {
// 如果类名和fqnOfCallingClass相等，则认为i + 1帧是代码中实际调用方法的
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);
}
// 拼接成最终要输出到日志的字符串， 如：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是当前方法调用栈的堆栈轨迹，这段代码通过遍历堆栈轨迹每一帧的类名并和fqnOfCallingClass比较，如果相符的话，则认为它的上一帧是实际调用方法。
如下图中，fqnOfCallingClass的值是org.slf4j.impl.Log4jLoggerAdapter，而在堆栈轨迹总可以发现类的上一个帧正好是我们的实际调用类TestLog.logTest：
因此，我们现在只需要让fqnOfCallingClass的值变成我们封装的日志类cn.hjktech.slf4j.Logger就大功告成了。fqnOfCallingClass是LoggingEvent.getLocationInformation创建LocationInfo时传入的参数，而LoggingEvent又是在Category.forcedLog方法中创建的，并且继续网上追踪，会发现fqnOfCallingClass的值最终来源于org.slf4j.impl.Log4jLoggerAdapter这个类:
public final class Log4jLoggerAdapter extends MarkerIgnoringBase implements LocationAwareLogger, Serializable {
...
static final String FQCN = Log4jLoggerAdapter.class.getName();
...
}而如果没有配合SLF4J使用时，fqnOfCallingClass的值则来源于org.apache.log4j.Logger类：
public class Logger extends Category {
...
private static final String FQCN = Logger.class.getName();
....
}代理Logger类来修改FQCN
好了，现在我们只需要修改这个值就行了。第一反应是使用反射去掉final修饰符，然后修改它的值，这种方法虽然对我们自己的代码可行，但是当引入其它框架，并且其它框架也使用的Log4j时，就会导致它们的日志信息出错，因为它们并不是调用的我们封装的Logger工具类，它们日志的堆栈轨迹中不会有我们工具类（如cn.hjktech.slf4j.Logger），因此我们需要另寻它法。
既然通过反射行不通， 那么我们可以通过动态代理的方式，在构造LoggingEvent对象之前将FQCN这个参数的值给替换掉，在跟踪过程中发现Log4jLoggerAdapter最终都是调用的org.apache.log4j.Logger.log方法并将FQCN最为参数传入，因此org.apache.log4j.Logger这个类就是我们要代理的类了。
了解JDK代理的人都知道，使用的条件是被代理类必须实现某一个接口，而org.apache.log4j.Logger.log这个方法并不是来自于某一个接口，所以我们选择使用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方法的第一个参数为我们自定义的FQCN
objects[0] = FQCN;
return methodProxy.invokeSuper(o, objects);
}
}
}代理defaultFactory
现在我们已经有了被代理的loggerProxy对象了，我们还需要将这个对象赋值给Log4jLoggerAdapter的logger成员变量，logger成员变量是在Log4jLoggerAdapter的构造方法中被作为参数传入的，它的来源如下图：
从上图中可以看到，LogManager.getLoggerRepository方法返回的对象中持有defaultFactory对象，因此我还需要代理这个对象，将它产生的'logger'对象替换成我们的'logger'就大功告成了，并且makeNewLoggerInstance方法是在LoggerFactory接口中定义的，所以我们只需要使用JDK的动态代理就可以完成了。实现代码如下：
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;
}
}实现流程和最终代码
我们最终实现方案如下：
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需要封装的方法可以根据自己的需要来实现
// 我个人认为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;
}
}测试
public class TestLog {
@Test
public void logTest() {
Logger.debug((Marker)null, "这是调用封装的Logger输出日志");
LoggerFactory.getLogger(TestLog.class).info("常规方法输出日志");
}
}输出结果：2016-10-19-15-00,308 DEBUG [cn.hjktech.slf4j.Logger] [main] (TestLog.java:13) TestLog.logTest(TestLog.java:13) - 这是调用封装的Logger输出日志
2016-10-19-15-00,311 INFO [TestLog] [main] (TestLog.java:14) TestLog.logTest(TestLog.java:14) - 常规方法输出日志