Shulou(Shulou.com)06/01 Report--

This article mainly explains "how to encapsulate SLF4J and Log4j". The content in the article is simple and clear, and it is easy to learn and understand. Please follow the editor's train of thought to study and learn "how to encapsulate SLF4J and Log4j".

Since the beginning of using the logging component, every class has been structured like this:

Public class A {public static final Logger logger = LoggerFactory.getLogger (A.class);}

This is quite annoying and must be encapsulated so that we can call it in this way:

Public class A {public void methodA () {Logger.debug ("Nice!");}}

The simplest version

After getting started, we encapsulated * versions in the simplest way:

/ / cn.hjktech.slf4j.Logger public class Logger {private static final org.slf4j.Logger logger = LoggerFactory.getLogger (Logger.class);. Public static void debug (...) {logger.debug (...);...}.}

It looks good, but after testing, it is found that there is a serious problem with this method: the log we print is unobstructed with the caller's information, such as class name, method name, number of lines, time, etc., in which the class name, method name and the number of rows are all extremely critical information, but if we use the above method to output the log, all three information will become the information of the Logger class, not the caller's information. This is obviously unbearable.

Of course, it can't be done like this. since the normal method can output the correct information, then there must be a way to achieve it. We hope that the end result is to call Logger.debug (..). The printed information is completely correct.

Analyze the source code

Write a demo to debug at this time to follow up:

Public class TestLog {@ Test public void logTest () {/ / break the point here LoggerFactory.getLogger (TestLog.class) .debug ("look at the execution flow");}}

It is found that the final output log string is generated in the PatternLayout.format method (Logback is the PatternLayoutBase.writeLoopOnConverters method). The method code is as follows:

/ / 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.nextt;} return sbuf.toString ();}

Head points to a linked list of type PatternConverter (Converter in Logback). The nodes of this linked list are generated according to the ConversionPattern in your log configuration file when the log class is initialized, for example, it is configured like this in my log4j.properties:

Log4j.appender.SOUT_LOGGER.layout.ConversionPattern=%d {yyyy-MM-dd-HH-mm,SSS}% p [% c] [% t] (% FRV% L)% l -% m% n

Then the structure of the linked list is (the information stored in parentheses):

DatePatternConverter (time step)-> LiteralPatternConverter (")-> BasicPatternConverter (LEVEL)-> LiteralPatternConverter (" [")-> CategoryPatternConverter (LoggerName)-> LiteralPatternConverter ("] [")-> BasicPatternConverter (thread name)-> LiteralPatternConverter ("] (")-> LocationPatternConverter (class)-> LiteralPatternConverter (": ")-> LocationPatternConverter (line)- > LiteralPatternConverter (") -")-> BasicPatternConverter (log string)-> LiteralPatternConverter ("\ n")->

Generate log strings based on this linked list, similar to this:

2016-10-17-13-42449 DEBUG [TestLog] [main] (TestLog.java:14)-Excuse me?

So now the goal is clear. We want to make the output of LocationPatternConverter the information of our real print class, and continue to follow up to the PatternConverter.format (parent class of LocationPatternConverter) method, which generates a LocationInfo object internally. The constructor of this class is as follows:

For (int I = elements.length-1; I > = 0; iMurt -) {/ / get the class name of frame I String thisClass = (String) getClassNameMethod.invoke (elements [I], noArgs); if (fqnOfCallingClass.equals (thisClass)) {/ / if the class name is equal to fqnOfCallingClass, then frame I + 1 is considered to be the int caller = I + 1 of the actual method called in the code; 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：

So now we just need to change the value of fqnOfCallingClass to our encapsulated log class cn.hjktech.slf4j.Logger and we're done. FqnOfCallingClass is the parameter passed when LoggingEvent.getLocationInformation creates LocationInfo, and LoggingEvent is created in the Category.forcedLog method. If you continue to track it online, you will find that the value of fqnOfCallingClass finally comes from the class org.slf4j.impl.Log4jLoggerAdapter:

Public final class Log4jLoggerAdapter extends MarkerIgnoringBase implements LocationAwareLogger, Serializable {... Static final String FQCN = Log4jLoggerAdapter.class.getName ();...}

If it is not used with SLF4J, the value of fqnOfCallingClass comes from the org.apache.log4j.Logger class:

Public class Logger extends Category {... Private static final String FQCN = Logger.class.getName ();.... }

Proxy the Logger class to modify the FQCN

Okay, now we just need to change this value. The * response is to use reflection to remove the final modifier and then modify its value, which is feasible for our own code, but when we introduce other frameworks and other frameworks also use Log4j, it will cause errors in their log information, because they are not our encapsulated Logger utility classes, and our tool classes (such as cn.hjktech.slf4j.Logger) are not in their log stack tracks. So we need to find another way.

Since it doesn't work through reflection, we can replace the value of the parameter FQCN before constructing the LoggingEvent object by dynamic proxy. During the trace, we find that Log4jLoggerAdapter is finally the called org.apache.log4j.Logger.log method and passes in the most parameter FQCN, so the class org.apache.log4j.Logger is the class we want to proxy.

Anyone who is familiar with the JDK proxy knows that the condition is that the proxied class must implement an interface, and the org.apache.log4j.Logger.log method does not come from an interface, so we choose to use 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 constructor = c.getConstructor (String.class); org.apache.log4j.Logger loggerProxy= constructor.newInstance (Logger.class.getName ());...} catch (...) {throw new RuntimeException ("failed to initialize Logger", e) }} private static class LogInterceptor implements MethodInterceptor {public Object intercept (Object o, Method method, Object [] objects, MethodProxy methodProxy) throws Throwable {/ / only intercepts the log method. If (objects.length! = 4 | |! method.getName (). Equals ("log") return methodProxy.invokeSuper (o, objects); / / replace the * parameters passed to the log method to our custom FQCN objects [0] = FQCN; return methodProxy.invokeSuper (o, objects);}

Agent defaultFactory

Now that we have the proxied loggerProxy object, we also need to assign this object to the logger member variable of Log4jLoggerAdapter

The logger member variable is passed as a parameter in the constructor of Log4jLoggerAdapter, and its source is shown below:

As you can see from the figure above, the object returned by the LogManager.getLoggerRepository method holds the defaultFactory object, so I also need to proxy this object, replace the 'logger' object it produces with our' logger', and the makeNewLoggerInstance method is defined in the LoggerFactory interface, so we only need to use the dynamic proxy of JDK. The implementation code is as follows:

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 ("failed to initialize 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;}}

Implementation process and final code

Our final implementation plan is as follows:

The code for Logger is as follows:

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 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 ("failed to initialize Logger", e) }} private static class LogInterceptor implements MethodInterceptor {public Object intercept (Object o, Method method, Object [] objects, MethodProxy methodProxy) throws Throwable {/ / only intercepts the log method. 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 }} / / the remaining Logger methods that need to be encapsulated can be implemented according to their own needs / / I personally think that slf4j's api is good enough, so most of them just write some code like the following public static void debug (String msg) {logger.debug (msg);}}

The code for ReflectionUtil is as follows:

Public class ReflectionUtil {public static T getFieldValue (@ NotNull Object object, @ NotNull String fullName) throws IllegalAccessException {return getFieldValue (object, fullName, false);} public static 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 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;}}

test

Public class TestLog {@ Test public void logTest () {Logger.debug ((Marker) null, "this is the Logger output log encapsulated by calling"); LoggerFactory.getLogger (TestLog.class) .info ("normal method output log");}}

Output result:

2016-10-19-15-00308 DEBUG [cn.hjktech.slf4j.Logger] [main] (TestLog.java:13) TestLog.logTest (TestLog.java:13)-this is calling the encapsulated Logger output log 2016-10-19-15-00311 INFO [TestLog] [main] (TestLog.java:14) TestLog.logTest (TestLog.java:14)-General method output log thank you for reading, this is the content of "how to encapsulate SLF4J and Log4j" After the study of this article, I believe you have a deeper understanding of how to encapsulate SLF4J and Log4j, and the specific use needs to be verified in practice. Here is, the editor will push for you more related knowledge points of the article, welcome to follow!

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.