快速上手Java日志框架

1、日志框架

  对于一个应用程序来说日志记录是必不可少的一部分。线上问题追踪，基于日志的业务逻辑统计分析等都离不日志。java领域存在多种日志框架，目前常用的日志框架包括Log4j 1，Log4j 2，Commons Logging，Slf4j，Logback，Jul。
  Java常用日志框架类别：
  Log4j ：Apache Log4j是一个基于Java的日志记录工具。它是由Ceki Gülcü首创的，现在则是Apache软件基金会的一个项目。 Log4j是几种Java日志框架之一。
  Log4j2：Apache Log4j 2是apache开发的一款Log4j的升级产品。
  Commons Logging：Apache基金会所属的项目，是一套Java日志接口，之前叫Jakarta Commons Logging，后更名为Commons Logging。
  Slf4j：类似于Commons Logging，是一套简易Java日志门面，本身并无日志的实现。（Simple Logging Facade for Java，缩写Slf4j）。
  Logback：一套日志组件的实现(Slf4j阵营)。
  Jul ：(Java Util Logging),自Java1.4以来的官方日志实现。

日志门面（日志的抽象层）	日志实现
JCL(Jakarta Commons Logging)、SLF4J(Simple Logging Facade for Java)、jboss-logging	Log4j、JUL(Java.util.logging)、Log4j、Logback

  一般我们选择的时候都是左边选一个门面，右边选一个实现；
  比如，最常见的组合是：SLF4J+Logback。
  像spring框架默认是JCL，SpringBoot默认是SLF4J+Logback。
  SLF4J官网：http://www.slf4j.org/
  Logback官网：http://logback.qos.ch/

2、SLF4J

  使用手册：http://www.slf4j.org/manual.html
  Slf4j的设计思想比较简洁，使用了Facade设计模式，Slf4j本身只提供了一个slf4j-api-version.jar包，这个jar中主要是日志的抽象接口，jar中本身并没有对抽象出来的接口做实现。
  对于不同的日志实现方案(例如Logback，Log4j…)，封装出不同的桥接组件(例如logback-classic-version.jar，slf4j-log4j12-version.jar)，这样使用过程中可以灵活的选取自己项目里的日志实现。
  每一个日志的实现框架都有自己的配置文件。使用slf4j以后，配置文件还是做成日志实现框架自己本身的配置文件；

  Slf4j与其他各种日志组件的桥接说明：

jar包	说明
slf4j-log4j12-1.7.13.jar	Log4j1.2版本的桥接器，你需要将Log4j.jar加入Classpath。
slf4j-jdk14-1.7.13.jar	java.util.logging的桥接器，Jdk原生日志框架。
slf4j-nop-1.7.13.jar	NOP桥接器，默默丢弃一切日志。
slf4j-simple-1.7.13.jar	一个简单实现的桥接器，该实现输出所有事件到System.err. 只有Info以及高于该级别的消息被打印，在小型应用中它也许是有用的。
slf4j-jcl-1.7.13.jar	Jakarta Commons Logging 的桥接器. 这个桥接器将Slf4j所有日志委派给Jcl。
logback-classic-1.0.13.jar(requires logback-core-1.0.13.jar)	Slf4j的原生实现，Logback直接实现了Slf4j的接口，因此使用Slf4j与Logback的结合使用也意味更小的内存与计算开销

  具体的接入方式如下：

  箭头：A调用位于B的软件。

3、SLF4J调用过程源码分析

3.1 不加入任何实现包

3.1.1 准备过程

  准备工作：只导入slf4j-api-version.jar，不加入任何实现包。

<dependency>
	<groupId>org.slf4j</groupId>
	<artifactId>slf4j-api</artifactId>
	<version>1.7.13</version>
</dependency>

  然后写一个测试类：

package cn.klb;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
 * @Author: Konglibin
 * @Description:
 * @Date: Create in 2020/4/26 17:19
 * @Modified By:
 */
public class App {
    final static Logger logger = LoggerFactory.getLogger("logDemo");

    public static void main(String[] args) {
        logger.info("Hello Logger!");
    }
}

  运行结果：

3.1.2 分析过程

  分析测试代码，首先是从日志工厂LoggerFactory获取一个Logger，然后调用了它的info方法。那么，到底发生了什么事情呢？
  先点进去getLogger方法：

public static Logger getLogger(String name) {
	ILoggerFactory iLoggerFactory = getILoggerFactory();
	return iLoggerFactory.getLogger(name);
}

  getLogger()方法做了一件事情，就是调用getILoggerFactory()方法创建一个ILoggerFactory工厂，然后调用工厂的getLogger()方法。
  我们着重来看看这个getILoggerFactory()方法是如何创建ILoggerFactory的，进入getILoggerFactory()方法：

public static ILoggerFactory getILoggerFactory() {
	if (INITIALIZATION_STATE == 0) {
		INITIALIZATION_STATE = 1;
		performInitialization();
	}
	
	switch(INITIALIZATION_STATE) {
		case 1:
			return TEMP_FACTORY;
		case 2:
			throw new IllegalStateException("org.slf4j.LoggerFactory could not be successfully initialized. See also http://www.slf4j.org/codes.html#unsuccessfulInit");
		case 3:
			return StaticLoggerBinder.getSingleton().getLoggerFactory();
		case 4:
			return NOP_FALLBACK_FACTORY;
		default:
			throw new IllegalStateException("Unreachable code");
	}
}

  getILoggerFactory()方法调用了初始化操作performInitialization()，然后判断INITIALIZATION_STATE的值。我们现在是想知道日志工厂是如何来的，所以接着看这个初始化方法：

private static final void performInitialization() {
	bind();
	if (INITIALIZATION_STATE == 3) {
		versionSanityCheck();
	}
}

  performInitialization()方法调用了bind()方法，很明显，日志工厂的创建和它相关，我们接着点进去：

private static final void bind() {
	String msg;
	try {
		Set<URL> staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet();
		reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);
		StaticLoggerBinder.getSingleton();
		INITIALIZATION_STATE = 3;
		reportActualBinding(staticLoggerBinderPathSet);
		fixSubstitutedLoggers();
	} catch (NoClassDefFoundError var2) {
		msg = var2.getMessage();
		if (!messageContainsOrgSlf4jImplStaticLoggerBinder(msg)) {
			failedBinding(var2);
			throw var2;
		}
	
		INITIALIZATION_STATE = 4;
		Util.report("Failed to load class \"org.slf4j.impl.StaticLoggerBinder\".");
		Util.report("Defaulting to no-operation (NOP) logger implementation");
		Util.report("See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.");
	} catch (NoSuchMethodError var3) {
		msg = var3.getMessage();
		if (msg != null && msg.contains("org.slf4j.impl.StaticLoggerBinder.getSingleton()")) {
			INITIALIZATION_STATE = 2;
			Util.report("slf4j-api 1.6.x (or later) is incompatible with this binding.");
			Util.report("Your binding is version 1.5.5 or earlier.");
			Util.report("Upgrade your binding to version 1.6.x.");
		}
	
		throw var3;
	} catch (Exception var4) {
		failedBinding(var4);
		throw new IllegalStateException("Unexpected initialization failure", var4);
	}
}

  有点长，不过这个bind()方法是最关键的。为了能够具体分析，我现在打个断点，然后运行：

  只走了这两行就进入异常了，来看看这两行做了什么事情。
  进入findPossibleStaticLoggerBinderPathSet()：

  它创建了一个staticLoggerBinderPathSet，然后经过中间一系列处理，等要return的时候还是null，我们看到：staticLoggerBinderPathSet的复制是来源于这个paths，这个变量来源于STATIC_LOGGER_BINDER_PATH，也就是中间黄色圈起来的那段。很明显就是因为这个STATIC_LOGGER_BINDER_PATH是没有的，导致paths没有内容。我们来看看这个常量是什么东西，点进去看它的定义：

  哦吼，原来是从一个org/slf4j/impl/路径中找StaticLoggerBinder这个类，然后我们工程中或者slf4j的jar包也是没有它的：

  我们回到bind()方法中：

  接着分析下一行，调用了reportMultipleBindingAmbiguity方法，参数就是上一步获得的那个空的Set。我们点进去这个方法看做了啥事情：

  那下一行的StaticLoggerBinder.getSingleton();为啥就直接异常了呢？我们来看这个StaticLoggerBinder是哪来的：

  所以这时就直接进入catch代码段了，就是找不到类呗。

  然后我们这个异常处理代码段，不就是我们控制台的输出嘛：

  除了输出这三句话，还有很重要的一点，就是把bind()所在类的属性INITIALIZATION_STATE设置成4了，这个4又是干啥的？现在bind()方法执行完了，我们回到之前调用它的地方：

  现在performInitialization()也执行完毕了，回到调用它的地方：

  也就是说，getILoggerFactory()这个方法就是返回一个NOP_FALLBACK_FACTORY，这个就是一个Logger工厂了。回到调用getILoggerFactory()的地方：

  咦，这里返回的是一个Logger，也就是说这里其实是调用了NOP_FALLBACK_FACTORY.getLogger(name)。让我回去看一下这个NOP_FALLBACK_FACTORY是什么：

  点进去这个类：

  继续挖掘：

  分析完毕，总结起来就是：获得了一个NOPLoggerFactory类型的日志工厂，然后这个工厂获取了一个NOPLogger类型的日志类，这个日志类的info()方法是空白的。

3.1.3 小结

  通过分析，很关键的一个就是bind()方法，这个方法里面涉及到一个org/slf4j/impl/StaticLoggerBinder.class，上面我们说过SLF4J是一个门面，也就是接口，而这个现在没有的，就是实现类了。下面我们加入实现类，来接着分析！

3.2 加入实现包

3.1.1 准备过程

  在上面工程的基础上，加入实现包依赖：

<dependencies>
	<!--slf4j-api依赖-->
	<dependency>
		<groupId>org.slf4j</groupId>
		<artifactId>slf4j-api</artifactId>
		<version>1.7.13</version>
	</dependency>
	
	<!--logback-classic依赖logback-core，会自动级联引入-->
	<dependency>
		<groupId>ch.qos.logback</groupId>
		<artifactId>logback-classic</artifactId>
		<version>1.2.3</version>
	</dependency>
</dependencies>

  会自动关联Logback核心组件：

  APP类和上面一样，没有任何改变。运行结果：

  现在就不会提示找不到类什么的，因为实现类有了：

3.1.2 分析过程

  我们跟上面的分析过程一样，还是先看看日志工厂是哪个货：

  现在获得的日志工厂是ch.qos.logback.classic.LoggerContext[default]，虽然不知道这货是啥，我们接着看这个getILoggerFactory()方法是如何获得它的：

  我们知道是performInitialization()方法把INITIALIZATION_STATE变为4的，我们点进去看为什么会是4：

  毫无疑问，肯定是bind()里面搞的鬼，进去看一看：

  之前没有实现类的时候我们已经知道，读取实现类就是findPossibleStaticLoggerBinderPathSet()做的事情，我们再进去看看：

  也就是说，现在这个Set已经有值，而且只有一个：

  我们看下一行的reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);做了什么：

  我们分析一下，什么时候这里会大于1呢？没错，就是不止一个实现类的时候，你看他if里面的方法体，内容就是说有多个SLF4J绑定什么的，里面的while就是在随机选择其中一个了。
  好了，回到bind()方法：

  终于知道INITIALIZATION_STATE为啥会变为3了。咦，后面还有两个方法，逐个看一下是干啥的：

  fixSubstitutedLoggers()方法名称叫做修复可选择的Logger，明显和上一行一样是针对多个实现包的情况，这里不讨论。回到调用bind()方法的地方：

  现在INITIALIZATION_STATE为3了，分析里面的方法：

  回到调用performInitialization()的地方：

  看一下圈出来的那个getLoggerFactory()，就是它返回了日志工厂：

  so，返回的是this.contextSelectorBinder.getContextSelector().getLoggerContext()，看一下这个Context是啥：

  原来这个LoggerContext就是获得到的日志工厂，那么它肯定有生产日志类的方法了，我们点进去找一下：

  接着看这个root是谁：


  好的，分析到这里就差不多了。在往下挖掘就是实现类的具体内容了，我们只分析日志类和日志工厂是从哪来的就可以了。

3.1.3 小结

  SLF4J是一个日志门面（也就是接口的意思啦），然后配合实现类使用。但是如果存在多种实现包，比如Logback、slf4j-log4j12、slf4j-jdk14和slf4j-jcl都导入的话，那么SLF4J的绑定就会选择其中一个，具体如何选择就跟JVM有关了，随机的，因此实际开发中应该避免这个情况。

4、使用SLF4J桥接遗留的api

4.1 原理

  实际开发中，一个项目是由多个子项目组成，而这些子项目可能使用了不同的日志框架。比如SpringFramework使用Commons Logging，然后MyBatis使用jboss-logging什么的。这时，我们就得把这些杂七杂八的日志框架进行整合（也叫桥接）。
  SLF4J桥接方案：

jar包	功能
log4j-over-slf4j-version.jar	将Log4j重定向到Slf4j
jcl-over-slf4j-version.jar	将Commons Logging里的Simple Logger重定向到slf4j
jul-to-slf4j-version.jar	将Java Util Logging重定向到Slf4j

  大概的原理如下图所示：

4.2 api桥接注意事项

  需要注意的是要避免死循环。

多个日志jar包形成死循环的条件	原因分析
log4j-over-slf4j.jar 和 slf4j-log4j12.jar 同时存在	由于slf4j-log4j12.jar的存在会将所有日志调用委托给log4j。但log4j-over-slf4j.jar的存在，会将所有对log4j api的调用委托给相应等值的slf4j,所以log4j-over-slf4j.jar和slf4j-log4j12.jar同时存在会形成死循环
jul-to-slf4j.jar 和 slf4j-jdk14.jar 同时存在	由于slf4j-jdk14.jar的存在会将所有日志调用委托给jdk的log。但由于同时jul-to-slf4j.jar的存在，会将所有对jul api的调用委托给相应等值的slf4j，所以jul-to-slf4j.jar和slf4j-jdk14.jar同时存在会形成死循环

4.3 桥接过程

  在实际使用过程中，项目会根据需要引入一些第三方组件，例如常用的Spring，而Spring本身的日志实现使用了Commons Logging，我们又想使用Slf4j+Loback组合，这时候需要在项目中将Commons Logging排除掉，通常会用到以下3种方案，3种方案各有利弊，可以根据项目的实际情况选择最适合自己项目的解决方案。
  方案一：采用maven的exclusion方案

<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-core</artifactId>
    <exclusions>
        <exclusion>
            <groupId>commons-logging</groupId>
            <artifactId>commons-logging</artifactId>
        </exclusion>
    </exclusions>
    <version>${springframework.version}</version>
</dependency>

  这种方案优点是exclusion是maven原生提供的，不足之处是如果有多个组件都依赖了commons-logging，则需要在很多处增加，使用起来不太方便。
  方案二：在maven声明commons-logging的scope为provided

<dependency>
	<groupId>commons-logging</groupId>
	<artifactId>commons-logging</artifactId>
	<version>1.1.1</version>
	<scope>provided</scope>
</dependency>
<dependency>
	<groupId>org.slf4j</groupId>
	<artifactId>jcl-over-slf4j</artifactId>
	<version>1.8.0-beta2</version>
</dependency>

  这种方案在调试代码时还是有可能导致IDE将commons-logging放置在classpath下，从而导致程序运行时出现异常。
  方案三：在maven私服中增加类似于99.0-does-not-exist这种虚拟的版本号

<dependency>    
    <groupId>commons-logging</groupId>    
    <artifactId>commons-logging</artifactId>    
    <version>99.0-does-not-exist</version>    
</dependency> 
<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>jcl-over-slf4j</artifactId>
  <version>1.8.0-beta2</version>
</dependency> 

  这种方案好处是声明方式比较简单，用IDE调试代码时也不会出现问题，不足之处是99.0-does-not-exist这种版本是maven*仓库中是不存在的，需要发布到自己的maven私服中。

5、总结

  由于历史原因JDK自身提供的Log组件出现的较晚，导致Jdk提供Log组件时第三方社区的日志组件已经比较稳定成熟。经过多年的发展Slf4j+Logback与组合，Commons Logging与Log4j组合两大阵营已经基本成为了Java项目开发的标准，建议在新的项目开发中从这两种方案中选择适合自己项目的组合方案。
  题外话：SpringBoot能自动适配所有的日志，而且底层使用slf4j+logback的方式记录日志，引入其他框架的时候，只需要把这个框架依赖的日志框架排除掉即可。