spring日志加载代码解析

Posted 2020-09-05 剑握在手

项目用的是springmvc+spring+mybatis框架，

配置日志的时候非常简单，仅仅是把commons-logging、log4j，还有slf4j-log4j三个日志相关的jar包导入项目，然后在classpath中加个log4j.properties的配置文件即可。

但是你有没有想过Log4j是什么时候被加载进虚拟机的？为什么我们没有手动加载，spring和mybatis就能自动的用起来log4j，毫不见外？

spring使用的是commons-logging，

 

mybatis用的是自己写的，

看一下源码，非常简单，一个个的去试，没有这个就进入下一个，直到找到了log4j

 

 

这两个工具其实都只是日志工具的规范，可以理解成接口，而log4j才是一个实实在在的日志实现。

 

但是slf4j在什么地方？——虽然这两个工具没用到slf4j，我还是把它放进来，因为我引入的其他工具会用到它。。比如：

 

下面开始看代码代码来说明一下log4j是怎么被加载到虚拟机的：

首先我们来看spring，我们从web.xml看起，加载spring：

 

到这里我们看到了LogFactory，这是commons-logging的一个log工厂，这里用的是这个虚类的一个静态方法，我们继续看这个方法：

 

 再看getFactory（代码较长，可以直接跳过先看后边的结论）：

  1 public static LogFactory getFactory() throws LogConfigurationException {
  2         // Identify the class loader we will be using
  3         ClassLoader contextClassLoader = getContextClassLoaderInternal();
  4 
  5         if (contextClassLoader == null) {
  6             // This is an odd enough situation to report about. This
  7             // output will be a nuisance on JDK1.1, as the system
  8             // classloader is null in that environment.
  9             if (isDiagnosticsEnabled()) {
 10                 logDiagnostic("Context classloader is null.");
 11             }
 12         }
 13 
 14         // Return any previously registered factory for this class loader
 15         LogFactory factory = getCachedFactory(contextClassLoader);
 16         if (factory != null) {
 17             return factory;
 18         }
 19 
 20         if (isDiagnosticsEnabled()) {
 21             logDiagnostic(
 22                     "[LOOKUP] LogFactory implementation requested for the first time for context classloader " +
 23                     objectId(contextClassLoader));
 24             logHierarchy("[LOOKUP] ", contextClassLoader);
 25         }
 26 
 27         // Load properties file.
 28         //
 29         // If the properties file exists, then its contents are used as
 30         // "attributes" on the LogFactory implementation class. One particular
 31         // property may also control which LogFactory concrete subclass is
 32         // used, but only if other discovery mechanisms fail..
 33         //
 34         // As the properties file (if it exists) will be used one way or
 35         // another in the end we may as well look for it first.
 36 
 37         Properties props = getConfigurationFile(contextClassLoader, FACTORY_PROPERTIES);
 38 
 39         // Determine whether we will be using the thread context class loader to
 40         // load logging classes or not by checking the loaded properties file (if any).
 41         ClassLoader baseClassLoader = contextClassLoader;
 42         if (props != null) {
 43             String useTCCLStr = props.getProperty(TCCL_KEY);
 44             if (useTCCLStr != null) {
 45                 // The Boolean.valueOf(useTCCLStr).booleanValue() formulation
 46                 // is required for Java 1.2 compatibility.
 47                 if (Boolean.valueOf(useTCCLStr).booleanValue() == false) {
 48                     // Don\'t use current context classloader when locating any
 49                     // LogFactory or Log classes, just use the class that loaded
 50                     // this abstract class. When this class is deployed in a shared
 51                     // classpath of a container, it means webapps cannot deploy their
 52                     // own logging implementations. It also means that it is up to the
 53                     // implementation whether to load library-specific config files
 54                     // from the TCCL or not.
 55                     baseClassLoader = thisClassLoader;
 56                 }
 57             }
 58         }
 59 
 60         // Determine which concrete LogFactory subclass to use.
 61         // First, try a global system property
 62         if (isDiagnosticsEnabled()) {
 63             logDiagnostic("[LOOKUP] Looking for system property [" + FACTORY_PROPERTY +
 64                           "] to define the LogFactory subclass to use...");
 65         }
 66 
 67         try {
 68             String factoryClass = getSystemProperty(FACTORY_PROPERTY, null);
 69             if (factoryClass != null) {
 70                 if (isDiagnosticsEnabled()) {
 71                     logDiagnostic("[LOOKUP] Creating an instance of LogFactory class \'" + factoryClass +
 72                                   "\' as specified by system property " + FACTORY_PROPERTY);
 73                 }
 74                 factory = newFactory(factoryClass, baseClassLoader, contextClassLoader);
 75             } else {
 76                 if (isDiagnosticsEnabled()) {
 77                     logDiagnostic("[LOOKUP] No system property [" + FACTORY_PROPERTY + "] defined.");
 78                 }
 79             }
 80         } catch (SecurityException e) {
 81             if (isDiagnosticsEnabled()) {
 82                 logDiagnostic("[LOOKUP] A security exception occurred while trying to create an" +
 83                               " instance of the custom factory class" + ": [" + trim(e.getMessage()) +
 84                               "]. Trying alternative implementations...");
 85             }
 86             // ignore
 87         } catch (RuntimeException e) {
 88             // This is not consistent with the behaviour when a bad LogFactory class is
 89             // specified in a services file.
 90             //
 91             // One possible exception that can occur here is a ClassCastException when
 92             // the specified class wasn\'t castable to this LogFactory type.
 93             if (isDiagnosticsEnabled()) {
 94                 logDiagnostic("[LOOKUP] An exception occurred while trying to create an" +
 95                               " instance of the custom factory class" + ": [" +
 96                               trim(e.getMessage()) +
 97                               "] as specified by a system property.");
 98             }
 99             throw e;
100         }
101 
102         // Second, try to find a service by using the JDK1.3 class
103         // discovery mechanism, which involves putting a file with the name
104         // of an interface class in the META-INF/services directory, where the
105         // contents of the file is a single line specifying a concrete class
106         // that implements the desired interface.
107 
108         if (factory == null) {
109             if (isDiagnosticsEnabled()) {
110                 logDiagnostic("[LOOKUP] Looking for a resource file of name [" + SERVICE_ID +
111                               "] to define the LogFactory subclass to use...");
112             }
113             try {
114                 final InputStream is = getResourceAsStream(contextClassLoader, SERVICE_ID);
115 
116                 if( is != null ) {
117                     // This code is needed by EBCDIC and other strange systems.
118                     // It\'s a fix for bugs reported in xerces
119                     BufferedReader rd;
120                     try {
121                         rd = new BufferedReader(new InputStreamReader(is, "UTF-8"));
122                     } catch (java.io.UnsupportedEncodingException e) {
123                         rd = new BufferedReader(new InputStreamReader(is));
124                     }
125 
126                     String factoryClassName = rd.readLine();
127                     rd.close();
128 
129                     if (factoryClassName != null && ! "".equals(factoryClassName)) {
130                         if (isDiagnosticsEnabled()) {
131                             logDiagnostic("[LOOKUP]  Creating an instance of LogFactory class " +
132                                           factoryClassName +
133                                           " as specified by file \'" + SERVICE_ID +
134                                           "\' which was present in the path of the context classloader.");
135                         }
136                         factory = newFactory(factoryClassName, baseClassLoader, contextClassLoader );
137                     }
138                 } else {
139                     // is == null
140                     if (isDiagnosticsEnabled()) {
141                         logDiagnostic("[LOOKUP] No resource file with name \'" + SERVICE_ID + "\' found.");
142                     }
143                 }
144             } catch (Exception ex) {
145                 // note: if the specified LogFactory class wasn\'t compatible with LogFactory
146                 // for some reason, a ClassCastException will be caught here, and attempts will
147                 // continue to find a compatible class.
148                 if (isDiagnosticsEnabled()) {
149                     logDiagnostic(
150                         "[LOOKUP] A security exception occurred while trying to create an" +
151                         " instance of the custom factory class" +
152                         ": [" + trim(ex.getMessage()) +
153                         "]. Trying alternative implementations...");
154                 }
155                 // ignore
156             }
157         }
158 
159         // Third try looking into the properties file read earlier (if found)
160 
161         if (factory == null) {
162             if (props != null) {
163                 if (isDiagnosticsEnabled()) {
164                     logDiagnostic(
165                         "[LOOKUP] Looking in properties file for entry with key \'" + FACTORY_PROPERTY +
166                         "\' to define the LogFactory subclass to use...");
167                 }
168                 String factoryClass = props.getProperty(FACTORY_PROPERTY);
169                 if (factoryClass != null) {
170                     if (isDiagnosticsEnabled()) {
171                         logDiagnostic(
172                             "[LOOKUP] Properties file specifies LogFactory subclass \'" + factoryClass + "\'");
173                     }
174                     factory = newFactory(factoryClass, baseClassLoader, contextClassLoader);
175 
176                     // TODO: think about whether we need to handle exceptions from newFactory
177                 } else {
178                     if (isDiagnosticsEnabled()) {
179                         logDiagnostic("[LOOKUP] Properties file has no entry specifying LogFactory subclass.");
180                     }
181                 }
182             } else {
183                 if (isDiagnosticsEnabled()) {
184                     logDiagnostic("[LOOKUP] No properties file available to determine" + " LogFactory subclass from..");
185                 }
186             }
187         }
188 
189         // Fourth, try the fallback implementation class
190 
191         if (factory == null) {
192             if (isDiagnosticsEnabled()) {
193                 logDiagnostic(
194                     "[LOOKUP] Loading the default LogFactory implementation \'" + FACTORY_DEFAULT +
195                     "\' via the same classloader that loaded this LogFactory" +
196                     " class (ie not looking in the context classloader).");
197             }
198 
199             // Note: unlike the above code which can try to load custom LogFactory
200             // implementations via the TCCL, we don\'t try to load the default LogFactory
201             // implementation via the context classloader because:
202             // * that can cause problems (see comments in newFactory method)
203             // * no-one should be customising the code of the default class
204             // Yes, we do give up the ability for the child to ship a newer
205             // version of the LogFactoryImpl class and have it used dynamically
206             // by an old LogFactory class in the parent, but that isn\'t
207             // necessarily a good idea anyway.
208             factory = newFactory(FACTORY_DEFAULT, thisClassLoader, contextClassLoader);
209         }
210 
211         if (factory != null) {
212             /**
213              * Always cache using context class loader.
214              */
215             cacheFactory(contextClassLoader, factory);
216 
217             if (props != null) {
218                 Enumeration names = props.propertyNames();
219                 while (names.hasMoreElements()) {
220                     String name = (String) names.nextElement();
221                     String value = props.getProperty(name);
222                     factory.setAttribute(name, value);
223                 }
224             }
225         }
226 
227         return factory;
228     }

以上代码会先试图从classpath中加载commons-logging.properties等几个commons-logging才有的东西，直到208行代码，

 

我们看到最后创建了一个LogFactoryImpl的实例，然后返回了。

回头看看我们上边的代码：

看完了getFactory我们知道最后我们得到的是LogFactoryImpl的实例，

那么接下来我们该去这个类中看看它的getInstance方法了：

 

非常简单，在这里创建了一个Log的实例，这也是最关键的地方，我们去看看这个方法。

经过我个人进一步的代码分析logConstructor这个东西是空的，我就不再展开了，这时我们看541行这个方法，这里才是真正的创建Log实例：

 

这个方法名我们能看懂，就是去发现系统中的Log实现，也就是一个找的过程，后边的782行是找找系统变量中有没有commons-logging自己的指明实现类类名的变量，结果是没有的，因为我没有配。

这个方法还没完，中间是一大段的注释，我们直接看后边的重点：

这个时候开始遍历一个字符串数组，依此去系统中找有没有这个数组中的实现类，我们看看这个数组先。

大家看到了什么？log4j，现在大家基本已经知道为什么了，后边的代码如果还有兴趣可以自己去看，其实就是一个个的试着去系统中加载这些类，加载不到处理一下ClassNotFoundException然后继续找下一个。

 

完毕。

 

最后如果大家想看看commons-logging自己的日志，可以写一个Listener放在web xml第一个位置，把下边一句代码弄上：

 

你们会从日志中看到多了很多内容，其中有一句是：

[LogFactoryImpl@1302539661 from org.apache.catalina.loader.WebappClassLoader@1536551745] Class \'org.apache.commons.logging.impl.Log4JLogger\' was found at \'jar:file:/E:/eaipweb/wtpwebapps/EAIP/WEB-INF/lib/commons-logging-1.1.1.jar!/org/apache/commons/logging/impl/Log4JLogger.class\'

 

这回真完毕了。