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 test
INFO: info...
Sep 23, 2017 6:51:16 PM com.chengmaoning.jroad.HelloWorldTest test
WARNING: warn...
Sep 23, 2017 6:51:16 PM com.chengmaoning.jroad.HelloWorldTest test
SEVERE: 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