commons-logging 原理浅析

介绍

Apache Commons Logging，又叫做JakartaCommons Logging (JCL)，他提供的是一个日志(Log)接口(interface)，同时兼顾轻量级和不依赖于具体的日志实现工具。它提供给中间件/日志工具开发者一个简单的日志操作抽象，允许程序开发人员使用不同的具体日志实现工具。用户被假定已熟悉某种日志实现工具的更高级别的细节。JCL提供的接口，对其它一些日志工具，包括Log4J, Avalon LogKit, and JDK等，进行了简单的包装，此接口更接近于Log4J和LogKit的实现.

以上是官方文档翻译，直白的说，Apache Commons Logging只是一个接口层，该接口为用户提供统一的日志API，不在乎日志框架具体实现。Apache Commons Logging会自动发现当前应用依赖的日志框架实现，按照用户配置或者默认顺序决定应该使用的日志框架。这样当以后升级或者更换日志组件时候，只需要改变日志组件依赖的jar包即可，就不用在应用代码内一行一行的改了。

ps: sfl4j, logback, log4j都是出自Ceki Gülcü大神之手，大神也是闲啊。

例子

我们先看一个列子感受一下。

import org.apache.commons.logging.Log;import org.apache.commons.logging.LogFactory;import org.junit.Test;public class HelloWorldTest {    private static final Log logger = LogFactory.getLog(HelloWorldTest.class);    @Test    public void test() {        logger.debug("debug...");        logger.info("info...");        logger.warn("warn...");        logger.error("error...");    }}

依赖：

        <dependency>            <groupId>commons-logging</groupId>            <artifactId>commons-logging</artifactId>            <version>1.2</version>        </dependency>

如果只是依赖JCL，不依赖其他具体日志组件实现的话，应该会打印出什么？

Sep 23, 2017 6:51:16 PM com.chengmaoning.jroad.HelloWorldTest testINFO: info...Sep 23, 2017 6:51:16 PM com.chengmaoning.jroad.HelloWorldTest testWARNING: warn...Sep 23, 2017 6:51:16 PM com.chengmaoning.jroad.HelloWorldTest testSEVERE: error...

实际上，真正打印上面日志的是JDK自带的日志组件，java.util.logging(JUL)。
如果加入Log4j的依赖（为求简单，仍使用Log4j 1）：

        <dependency>            <groupId>log4j</groupId>            <artifactId>log4j</artifactId>            <version>1.2.17</version>        </dependency>        <dependency>            <groupId>commons-logging</groupId>            <artifactId>commons-logging</artifactId>            <version>1.2</version>        </dependency>        <!-- log end -->

运行结果为：

log4j:WARN No appenders could be found for logger (com.chengmaoning.jroad.HelloWorldTest).log4j:WARN Please initialize the log4j system properly.log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.

可见，这个时候打印日志的是Log4j，由于我们没有配置Log4j，输出日志要求我们“合理的初始化Log4j组件”。
JCL抽象层会自主猜测（发现）应该使用哪个日志组件。具体日志组件的初始化,配置，结束日志组件自己完成，JCL不参与。

原理

Logging组件通用设计

当前的Java 日志框架（抽象层如，JCL，SLF4J及具体实现如，Log4j，Logback）都基于相同的设计，即从一个LogFactory中取得一个命名的Log（Logger）实例，然后使用这个Log（Logger）实例打印debug、info、warn、error等不同级别的日志。Logging框架由以下三个核心组件组成：

    Loggers：Logger负责捕捉事件并将其发送给合适的Appender。    Appenders：也被称为Handlers，负责将日志事件记录到目标位置。在将日志事件输出之前，Appenders使用Layouts来对事件进行格式化处理。    Layouts：也被称为Formatters，它负责对日志事件中的数据进行转换和格式化。Layouts决定了数据在一条日志记录中的最终形式。

当Logger记录一个事件时，它将事件转发给适当的Appender。然后Appender使用Layout来对日志记录进行格式化，并将其发送给控制台、文件或者其它目标位置。另外，Filters可以让你进一步指定一个Appender是否可以应用在一条特定的日志记录上。在日志配置中，Filters并不是必需的，但可以让你更灵活地控制日志消息的流动。

源码

下面我们跟踪private static final Log logger = LogFactory.getLog(HelloWorldTest.class);
来看看JCL是如何发现Logging实现的。

LogFactory是个抽象类，是JCL的核心。如果开发者要扩展LogFactory以支持其他Logging组件，或者修改Logging组件的发现顺序，可以自己继承实现。JCL提供了默认的实现LogFactoryImpl， 一般来说无需自己实现。

 public static Log getLog(Class clazz) throws LogConfigurationException {        return getFactory().getInstance(clazz);    }

    public Log getInstance(String name) throws LogConfigurationException {        Log instance = (Log) instances.get(name);        if (instance == null) {            instance = newInstance(name);            instances.put(name, instance);        }        return instance;    }

LogFactory 缓存已存在的Logger 在 instances里以提高性能。

/**     * The {@link org.apache.commons.logging.Log} instances that have     * already been created, keyed by logger name.     */    protected Hashtable instances = new Hashtable();

如果名为name的Logger 不存在，就会创建newInstance(name)。

获取LogFactory实例

首先 我们看LoggerFactory实例 是如何获取到的。

/**     * Construct (if necessary) and return a <code>LogFactory</code>     * instance, using the following ordered lookup procedure to determine     * the name of the implementation class to be loaded.     * <p>     * <ul>     * <li>The <code>org.apache.commons.logging.LogFactory</code> system     *     property.</li>     * <li>The JDK 1.3 Service Discovery mechanism</li>     * <li>Use the properties file <code>commons-logging.properties</code>     *     file, if found in the class path of this class.  The configuration     *     file is in standard <code>java.util.Properties</code> format and     *     contains the fully qualified name of the implementation class     *     with the key being the system property defined above.</li>     * <li>Fall back to a default implementation class     *     (<code>org.apache.commons.logging.impl.LogFactoryImpl</code>).</li>     * </ul>     * <p>     * <em>NOTE</em> - If the properties file method of identifying the     * <code>LogFactory</code> implementation class is utilized, all of the     * properties defined in this file will be set as configuration attributes     * on the corresponding <code>LogFactory</code> instance.     * <p>     * <em>NOTE</em> - In a multi-threaded environment it is possible     * that two different instances will be returned for the same     * classloader environment.     *     * @throws LogConfigurationException if the implementation class is not     *  available or cannot be instantiated.     */    public static LogFactory getFactory() throws LogConfigurationException {    }

大家可以打开源码，源码中这段很长，我们分解一下。

• 在factories 缓存中查询当前ClassLoader 对应的 LoggerFactory是否已经存在。

// Identify the class loader we will be using        ClassLoader contextClassLoader = getContextClassLoaderInternal();        if (contextClassLoader == null) {            // This is an odd enough situation to report about. This            // output will be a nuisance on JDK1.1, as the system            // classloader is null in that environment.            if (isDiagnosticsEnabled()) {                logDiagnostic("Context classloader is null.");            }        }        // Return any previously registered factory for this class loader        LogFactory factory = getCachedFactory(contextClassLoader);        if (factory != null) {            return factory;        }

• 根据系统变量的配置决定具体的LoggerFactory 子类。

// First, try a global system property        if (isDiagnosticsEnabled()) {            logDiagnostic("[LOOKUP] Looking for system property [" + FACTORY_PROPERTY +                          "] to define the LogFactory subclass to use...");        }        try {            String factoryClass = getSystemProperty(FACTORY_PROPERTY, null);            if (factoryClass != null) {                if (isDiagnosticsEnabled()) {                    logDiagnostic("[LOOKUP] Creating an instance of LogFactory class '" + factoryClass +                                  "' as specified by system property " + FACTORY_PROPERTY);                }                factory = newFactory(factoryClass, baseClassLoader, contextClassLoader);            } else {                if (isDiagnosticsEnabled()) {                    logDiagnostic("[LOOKUP] No system property [" + FACTORY_PROPERTY + "] defined.");                }            }        } catch (SecurityException e) {            if (isDiagnosticsEnabled()) {                logDiagnostic("[LOOKUP] A security exception occurred while trying to create an" +                              " instance of the custom factory class" + ": [" + trim(e.getMessage()) +                              "]. Trying alternative implementations...");            }            // ignore        } catch (RuntimeException e) {            // This is not consistent with the behaviour when a bad LogFactory class is            // specified in a services file.            //            // One possible exception that can occur here is a ClassCastException when            // the specified class wasn't castable to this LogFactory type.            if (isDiagnosticsEnabled()) {                logDiagnostic("[LOOKUP] An exception occurred while trying to create an" +                              " instance of the custom factory class" + ": [" +                              trim(e.getMessage()) +                              "] as specified by a system property.");            }            throw e;        }

• 尝试JDK1.3的类发现机制。
  查找META-INF/services/org.apache.commons.logging.LogFactory" 配置文件，该文件只有一行，即为具体要实现的子类全限定类名。

try {                final InputStream is = getResourceAsStream(contextClassLoader, SERVICE_ID);                if( is != null ) {                    // This code is needed by EBCDIC and other strange systems.                    // It's a fix for bugs reported in xerces                    BufferedReader rd;                    try {                        rd = new BufferedReader(new InputStreamReader(is, "UTF-8"));                    } catch (java.io.UnsupportedEncodingException e) {                        rd = new BufferedReader(new InputStreamReader(is));                    }                    String factoryClassName = rd.readLine();                    rd.close();                    if (factoryClassName != null && ! "".equals(factoryClassName)) {                        if (isDiagnosticsEnabled()) {                            logDiagnostic("[LOOKUP]  Creating an instance of LogFactory class " +                                          factoryClassName +                                          " as specified by file '" + SERVICE_ID +                                          "' which was present in the path of the context classloader.");                        }                        factory = newFactory(factoryClassName, baseClassLoader, contextClassLoader );                    }                } else {                    // is == null                    if (isDiagnosticsEnabled()) {                        logDiagnostic("[LOOKUP] No resource file with name '" + SERVICE_ID + "' found.");                    }                }

• 根据commons-logging.properties 的决定。

// Third try looking into the properties file read earlier (if found)        if (factory == null) {            if (props != null) {                if (isDiagnosticsEnabled()) {                    logDiagnostic(                        "[LOOKUP] Looking in properties file for entry with key '" + FACTORY_PROPERTY +                        "' to define the LogFactory subclass to use...");                }                String factoryClass = props.getProperty(FACTORY_PROPERTY);                if (factoryClass != null) {                    if (isDiagnosticsEnabled()) {                        logDiagnostic(                            "[LOOKUP] Properties file specifies LogFactory subclass '" + factoryClass + "'");                    }                    factory = newFactory(factoryClass, baseClassLoader, contextClassLoader);                    // TODO: think about whether we need to handle exceptions from newFactory                } else {                    if (isDiagnosticsEnabled()) {                        logDiagnostic("[LOOKUP] Properties file has no entry specifying LogFactory subclass.");                    }                }            } else {                if (isDiagnosticsEnabled()) {                    logDiagnostic("[LOOKUP] No properties file available to determine" + " LogFactory subclass from..");                }            }        }

• 使用默认实现org.apache.commons.logging.impl.LogFactoryImpl。

// Fourth, try the fallback implementation class        if (factory == null) {            if (isDiagnosticsEnabled()) {                logDiagnostic(                    "[LOOKUP] Loading the default LogFactory implementation '" + FACTORY_DEFAULT +                    "' via the same classloader that loaded this LogFactory" +                    " class (ie not looking in the context classloader).");            }            // Note: unlike the above code which can try to load custom LogFactory            // implementations via the TCCL, we don't try to load the default LogFactory            // implementation via the context classloader because:            // * that can cause problems (see comments in newFactory method)            // * no-one should be customising the code of the default class            // Yes, we do give up the ability for the child to ship a newer            // version of the LogFactoryImpl class and have it used dynamically            // by an old LogFactory class in the parent, but that isn't            // necessarily a good idea anyway.            factory = newFactory(FACTORY_DEFAULT, thisClassLoader, contextClassLoader);        }

以上即为，加载LoggerFactory实例的全过程，通常情况下，我们无需任何配置，直接使用默认实现org.apache.commons.logging.impl.LogFactoryImpl。

LogFactoryImpl获取Log 实例

LoggerFactory的实例得到后，我们现在来看LogFactoryImpl是如何获取Logger的。

Concrete subclass of LogFactory that implements the following algorithm to dynamically select a logging implementation class to instantiate a wrapper for:

• Use a factory configuration attribute named org.apache.commons.logging.Log to identify the requested implementation class.

• Use the org.apache.commons.logging.Log system property to identify the requested implementation class.

• If Log4J is available, return an instance of org.apache.commons.logging.impl.Log4JLogger.

• If JDK 1.4 or later is available, return an instance of org.apache.commons.logging.impl.Jdk14Logger.

• Otherwise, return an instance of org.apache.commons.logging.impl.SimpleLog.

This factory will remember previously created Log instances
for the same name, and will return them on repeated requests to the
getInstance() method.

1. 查看factory属性配置和系统变量是否指定Log子类。

 /**     * Checks system properties and the attribute map for     * a Log implementation specified by the user under the     * property names {@link #LOG_PROPERTY} or {@link #LOG_PROPERTY_OLD}.     *     * @return classname specified by the user, or <code>null</code>     */    private String findUserSpecifiedLogClassName() {        if (isDiagnosticsEnabled()) {            logDiagnostic("Trying to get log class from attribute '" + LOG_PROPERTY + "'");        }        String specifiedClass = (String) getAttribute(LOG_PROPERTY);        if (specifiedClass == null) { // @deprecated            if (isDiagnosticsEnabled()) {                logDiagnostic("Trying to get log class from attribute '" +                              LOG_PROPERTY_OLD + "'");            }            specifiedClass = (String) getAttribute(LOG_PROPERTY_OLD);        }        if (specifiedClass == null) {            if (isDiagnosticsEnabled()) {                logDiagnostic("Trying to get log class from system property '" +                          LOG_PROPERTY + "'");            }            try {                specifiedClass = getSystemProperty(LOG_PROPERTY, null);            } catch (SecurityException e) {                if (isDiagnosticsEnabled()) {                    logDiagnostic("No access allowed to system property '" +                        LOG_PROPERTY + "' - " + e.getMessage());                }            }        }        if (specifiedClass == null) { // @deprecated            if (isDiagnosticsEnabled()) {                logDiagnostic("Trying to get log class from system property '" +                          LOG_PROPERTY_OLD + "'");            }            try {                specifiedClass = getSystemProperty(LOG_PROPERTY_OLD, null);            } catch (SecurityException e) {                if (isDiagnosticsEnabled()) {                    logDiagnostic("No access allowed to system property '" +                        LOG_PROPERTY_OLD + "' - " + e.getMessage());                }            }        }        // Remove any whitespace; it's never valid in a classname so its        // presence just means a user mistake. As we know what they meant,        // we may as well strip the spaces.        if (specifiedClass != null) {            specifiedClass = specifiedClass.trim();        }        return specifiedClass;    }

1. classpath中按顺序发现，找到第一个Log实现即返回。

 // No user specified log; try to discover what's on the classpath        //        // Note that we deliberately loop here over classesToDiscover and        // expect method createLogFromClass to loop over the possible source        // classloaders. The effect is:        //   for each discoverable log adapter        //      for each possible classloader        //          see if it works        //        // It appears reasonable at first glance to do the opposite:        //   for each possible classloader        //     for each discoverable log adapter        //        see if it works        //        // The latter certainly has advantages for user-installable logging        // libraries such as log4j; in a webapp for example this code should        // first check whether the user has provided any of the possible        // logging libraries before looking in the parent classloader.        // Unfortunately, however, Jdk14Logger will always work in jvm>=1.4,        // and SimpleLog will always work in any JVM. So the loop would never        // ever look for logging libraries in the parent classpath. Yet many        // users would expect that putting log4j there would cause it to be        // detected (and this is the historical JCL behaviour). So we go with        // the first approach. A user that has bundled a specific logging lib        // in a webapp should use a commons-logging.properties file or a        // service file in META-INF to force use of that logging lib anyway,        // rather than relying on discovery.        if (isDiagnosticsEnabled()) {            logDiagnostic(                "No user-specified Log implementation; performing discovery" +                " using the standard supported logging implementations...");        }        for(int i=0; i<classesToDiscover.length && result == null; ++i) {            result = createLogFromClass(classesToDiscover[i], logCategory, true);        }        if (result == null) {            throw new LogConfigurationException                        ("No suitable Log implementation");        }        return result;    }

发现顺序：

     /**       * The names of classes that will be tried (in order) as logging       * adapters. Each class is expected to implement the Log interface,       * and to throw NoClassDefFound or ExceptionInInitializerError when       * loaded if the underlying logging library is not available. Any       * other error indicates that the underlying logging library is available       * but broken/unusable for some reason.       */      private static final String[] classesToDiscover = {              LOGGING_IMPL_LOG4J_LOGGER,              "org.apache.commons.logging.impl.Jdk14Logger",              "org.apache.commons.logging.impl.Jdk13LumberjackLogger",              "org.apache.commons.logging.impl.SimpleLog"      };

利用反射加载：

    try {                    c = Class.forName(logAdapterClassName, true, currentCL);                } catch (ClassNotFoundException originalClassNotFoundException) {                    // The current classloader was unable to find the log adapter                    // in this or any ancestor classloader. There's no point in                    // trying higher up in the hierarchy in this case..                    String msg = originalClassNotFoundException.getMessage();                    logDiagnostic("The log adapter '" + logAdapterClassName + "' is not available via classloader " +                                  objectId(currentCL) + ": " + msg.trim());                    try {                        // Try the class classloader.                        // This may work in cases where the TCCL                        // does not contain the code executed or JCL.                        // This behaviour indicates that the application                        // classloading strategy is not consistent with the                        // Java 1.2 classloading guidelines but JCL can                        // and so should handle this case.                        c = Class.forName(logAdapterClassName);                    } catch (ClassNotFoundException secondaryClassNotFoundException) {                        // no point continuing: this adapter isn't available                        msg = secondaryClassNotFoundException.getMessage();                        logDiagnostic("The log adapter '" + logAdapterClassName +                                      "' is not available via the LogFactoryImpl class classloader: " + msg.trim());                        break;                    }                }                constructor = c.getConstructor(logConstructorSignature);                Object o = constructor.newInstance(params);                // Note that we do this test after trying to create an instance                // [rather than testing Log.class.isAssignableFrom(c)] so that                // we don't complain about Log hierarchy problems when the                // adapter couldn't be instantiated anyway.                if (o instanceof Log) {                    logAdapterClass = c;                    logAdapter = (Log) o;                    break;                }

这样我们就得到具体的Log了。

JCL的Logger 和底层Logging组件怎么交流？

很简单，Logger 只是个代理，对Logger 的请求会被转发给具体的Logging框架。以Log4JLogger 为例:

public class Log4JLogger implements Log, Serializable {    /** Serializable version identifier. */    private static final long serialVersionUID = 5160705895411730424L;    // ------------------------------------------------------------- Attributes    /** The fully qualified name of the Log4JLogger class. */    private static final String FQCN = Log4JLogger.class.getName();    /** Log to this logger */    private transient volatile Logger logger = null;    /** Logger name */    private final String name;    private static final Priority traceLevel;

这里的Logger对应的就是Log4j里的org.apache.log4j.Logger。同理，Jdk14Logger里的Logger对应的就是java.util.logging.Logger。

当我们调用Log4JLogger的打印日志方法时，请求就会被转发给下层实际Logging框架。

    public void debug(Object message, Throwable t) {        getLogger().log(FQCN, Level.DEBUG, message, t);    }    /**     * Logs a message with <code>org.apache.log4j.Priority.INFO</code>.     *     * @param message to log     * @see org.apache.commons.logging.Log#info(Object)     */    public void info(Object message) {        getLogger().log(FQCN, Level.INFO, message, null);    }

以上就分析完了，大家可以debug模式下跟下代码就明白Commons Logging是如何工作的了，与SLF4J类似都是日志抽象层，为开发者提供统一的日志API。
至于具体日志框架，如Log4j，Logback等，是什么时候初始化的，如何配置及配置文件格式这属于具体具体Logging框架的内容，后面讨论。

参考文献

1. Apache Commons Logging源码
2. http://commons.apache.org/proper/commons-logging/
3. http://www.importnew.com/16331.html