从一个Logger异常开始梳理Java日志体系

从一个启动异常开始

SpringBoot项目在启动时报堆栈溢出，错误如下。

Exception in thread "main" java.lang.StackOverflowError
    at org.apache.logging.log4j.util.StackLocator.getCallerClass(StackLocator.java:108)
    at org.apache.logging.log4j.util.StackLocator.getCallerClass(StackLocator.java:121)
    at org.apache.logging.log4j.util.StackLocatorUtil.getCallerClass(StackLocatorUtil.java:55)
    at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:42)
    at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:46)
    at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:358)
    at org.apache.logging.slf4j.SLF4JLoggerContext.getLogger(SLF4JLoggerContext.java:39)
    at org.apache.logging.slf4j.Log4jLoggerFactory.newLogger(Log4jLoggerFactory.java:37)
    at org.apache.logging.slf4j.Log4jLoggerFactory.newLogger(Log4jLoggerFactory.java:29)
    at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:52)
    at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:358)

日志输出很长很长，都是重复，初步判断是递归调用太深导致栈溢出，问题源头指向日志接口。

分析这个异常出现的具体原因之前，有必要先了解一下现有的Java日志体系。对于Java应用来说，日志记录是一个必不可少的东西。通过日志，开发人员可以更为方便的追踪线上问题，分析业务数据等等。而开发人员在进行项目开发的时候，经常会被项目中遇到的各种日志框架弄的晕头转向，经常不知道在一个类中应该用哪个框架来打印日志。因此，感觉有必要对Java的日志体系进行一次梳理，搞清楚各个日志框架之前的关系，以便自己日后用起来能够得心应手。

1、Java日志体系发展历程

在实际开发过程中，Java的日志框架体系之所以会给编程人员带来一种混乱的感觉，根本原因是Java日志框架没有统一的使用标准。

1. Log4，在最初的上古时代，程序员们并没有现成的日志框架，Java开发者们只能使用原始的System.out.println(), System.err.println()或者e.printStackTrace()。通过把debug日志写到StdOut流，错误日志写到ErrOut流，来实现应用程序运行状态的记录。这样有一个很大的问题，那就是无法定制化，并且日志的输出粒度不够细。于是1999年，Ceki Gülcü创建了Log4j项目，并几乎成为了Java日志框架的实际标准。
2. JUL，Log4j作为Apache基金会的一员，Apache希望将Log4j引入jdk，不过被sun公司拒绝了。随后，sun模仿Log4j，在jdk1.4中实现了JUL即java.util.logging。
3. JCL，后来为了实现将日志接口与实现解耦，Apache推出了JCL即Apache Commons Logging。JCL只定义了一套日志接口，具体实现由Log4j或JUL来完成。JCL基于动态绑定来实现日志的记录，在使用时只需要用JCL定义的接口来编写代码即可，程序真正运行时会检查classpath中的具体实现，因此可以自由选择是有log4j还是JUL来实现日志功能。
4. Slf4j&Logback，后来，Java日志大佬Ceki Gülcü离开了Apache自己单干，先后创建了Slf4j和Logback两个项目。Slf4j是一个日志门面，只提供接口，可以支持Logback、JUL、log4j等实现；Logback作为大佬自己提供的具体实现，相较于log4j有更快的执行速度和更完善的功能。
5. log4j2，最后，Apache为了避免Slf4j和Logback，慢慢取代JCL和Log4j ，推出了自己的反击之作log4j2。log4j2不兼容log4j，性能获得了很大的提升。于是，我们就看到了如此多的日志框架并存的局面。

2、日志门面、桥接器与日志实现

2.1、门面模式

比直接使用具体日志框架更合理的选择是使用日志门面接口。日志门面接口提供了一套独立于具体日志框架实现的API，应用程序通过使用这些独立的API就能够实现与具体日志框架的解耦，这跟JDBC是类似的。最早的日志门面接口是commons-logging，但目前最受欢迎的是SLF4J。

SLF4J（Simple logging Facade for Java）

意思为简单日志门面，它是把不同的日志系统的实现进行了具体的抽象化，只提供了统一的日志使用接口，使用时只需要按照其提供的接口方法进行调用即可，由于它只是一个接口，并不是一个具体的可以直接单独使用的日志框架，所以最终日志的格式、记录级别、输出方式等都要通过接口绑定的具体的日志系统来实现，这些具体的日志系统就有log4j2、log4j、logback、java.util.logging等，它们才实现了具体的日志系统的功能。日志门面在使用时，可以动态或者静态的指定具体的日志框架实现，实现了接口和实现的解耦，使得用户可以灵活的选择日志的具体实现框架。另一种就是具体的日志系统，它提供了具体的日志接口实现，应用程序通过具体实现执行日志打印的功能。

那为什么要将日志的体系搞这么复杂呢，简单一个实现不就好了吗，为什么分成门面与实现？要解答这个问题，需要回顾一下门面模式。门面模式，其核心为：外部与一个子系统的通信，必须通过一个统一的外观对象进行，使得子系统更易于使用。

现在，我们可以回到最初的问题了，日志体系为什么要使用SLF4J作为门面呢？

• 使用slf4j后有利于根据自己实际的需求更换具体的日志系统，比如，之前使用的具体的日志系统为log4j，想更换为logback时，只需要删除log4j相关的jar，然后加入logback相关的jar和日志配置文件即可，而不需要改动具体的日志输出方法，试想如果没有采用这种方式，当你的系统中日志输出有成千上万条时，你要更换日志系统将是多么庞大的一项工程。如果你开发的是一个面向公众使用的组件或公共服务模块，那么一定要使用slf4的这种形式，这有利于别人在调用你的模块时保持和他系统中使用统一的日志输出。

2.2、sl4j与具体日志框架的结合

Java日志体系当前大体可以分为三个部分：日志门面接口、桥接器、日志框架具体实现。门面接口与日志实现上面已经介绍过了。那么什么是桥接器呢？所谓“桥接器”，不过就是对某套API的伪实现，这种实现并不是直接去完成API所声明的功能，而是去调用有类似功能的别的API。这样就完成了从“某套API”到“别的API”的转调。如果同时存在A-to-B.jar和B-to-A.jar这两个桥接器，那么可以想象当应用程序开始调用A或者B的API时，会发生什么事。这就是最开始引出的那个stack overflow异常的基本原理。

下图来自SL4J官网文档。

可以看到slf4j与具体日志框架结合的方案有很多种。当然，每种方案的最上层（绿色的应用层）都是统一的，它们向下都是直接调用slf4j提供的API（浅蓝色的抽象API层），依赖slf4j-api.jar。然后slf4j API向下再怎么做就非常自由了，几乎可以使用所有的具体日志框架。注意图中的第二层是浅蓝色的，看左下角的图例可知这代表抽象日志API，也就是说它们不是具体实现。如果像左边第一种方案那样下层没有跟任何具体日志框架实现相结合，那么日志是无法输出来的（ 这里不确定是否可能会默认输出到标准输出 ）。

图中第三层明显就不如第一、二层那么整齐划一了，因为这里已经开始涉及到了具体的日志框架。

首先看第三层中间的两个湖蓝色块，这是适配层，也就是桥接器。左边的slf4j-log4j12.jar桥接器看名字就知道是slf4j到log4j的桥接器，同样，右边的slf4j-jdk14.jar就是slf4j到Java原生日志实现的桥接器了。它们的下一层分别是对应的日志框架实现，log4j的实现代码是log4j.jar，而jul实现代码已经包含在了JVM runtime中，不需要单独的jar包。

再看第三层其余的三个深蓝色块。它们三个也是具体的日志框架实现，但是却不需要桥接器，因为它们本身就已经直接实现了slf4j API。slf4j-simple.jar和slf4j-nop.jar这两个不用多说，看名字就知道一个是slf4j的简单实现，一个是slf4j的空实现，平时用处也不大。而logback之所以也实现了slf4j API，是因为logback和slf4j出自同一人之手。

第三层所有的灰色jar包都带有红框，这表示它们都直接实现了slf4j API，只是湖蓝色的桥接器对slf4j API的实现并不是直接输出日志，而是转去调用别的日志框架声明的API。

2.3、其他日志框架桥接到sl4j

如果只存在上面这些从sfl4j到其他日志框架的桥接器，可能还不会出什么问题。但是实际上还有另外一类桥接器，它们的作用跟上面的恰好相反，它们将其它日志框架的API转调到slf4j的API上。

下图来自SL4J官网文档。

上图展示了目前为止能安全地从别的日志框架API转调回slf4j的所有三种情形。

以左上角第一种情形为例，当slf4j底层使用的具体实现是logback时，上层允许桥接到slf4j的日志框架API有log4j和jul。jcl虽然不是什么日志框架的具体实现，但是它的API仍然是能够被转调回slf4j的。要想实现转调，方法就是图上列出的用特定的桥接器jar替换掉原有的日志框架jar。

看完三种情形以后，会发现几乎所有其他日志框架的API，包括jcl的API，都能够随意的转调回slf4j。 但是有一个唯一的限制就是转调回slf4j的日志框架不能跟slf4j当前使用的底层具体日志实现框架相同。 这个限制就是为了防止A-to-B.jar跟B-to-A.jar同时出现在类路径中，从而导致A和B一直不停地互相递归调用，最后堆栈溢出。目前这个限制并不是通过技术保证的，仅仅靠开发者自己保证，这也是为什么slf4j官网上要强调所有合理的方式只有上图的三种情形。

假设slf4j+log4j：一个具体的日志操作的过程，首先调用slf4j的API接口，然后 slf4j将请求转发给slf4j-log4j12来处理，这个是在编译期间静态绑定好的。然后slf4j-log4j12最后通过log4j来完成日志操作。

如果再加一个 log4j-over-slf4j会怎样？其实日志请求又重新打回给 slf4j，形成一个环形

到这里，本文一开始所展示的那个异常的原理基本已经清楚了。此外，通过上图还可以看出可能会出现类似异常的组合不仅仅是log4j-over-slf4j和slf4j-log4j12，slf4j官网还指出了另外一对： jcl-over-slf4j.jar和slf4j-jcl.jar

2.4、multiple SLF4J bindings警告

其实本文一开始的启动异常是可以提前避免的，使用maven编译工程时可以发现如下multiple SLF4J bindings警告，如果直接忽略此警告，启动spring boot应用就会报上面提到的stackOverFlow异常。

上边警告大概意思是说logback-classic包和log4j-slf4j-impl包，关于org/slf4j/impl/StaticLoggerBinder.class 这个类发生了冲突。原因是一个接口，被两个实现类实现了，然则程序在启动获取时，只想获取一个。这个接口是：org.apache.logging.slf4j.Log4jLoggerFactory
两个实现类分别是：

• logback-classic包中的org.slf4j.impl.StaticLoggerBinder
• log4j-slf4j-impl包org.slf4j.impl.StaticLoggerBinder

发生这个错误的原因，首先logback日志的开发者和log4j的开发是同一个人，而SpringBoot默认日志是较新的logback日志。但是在以前流行的日志却是log4j ，而且很多的第三方工具都含有log4j的引入。而我们在项目开发中，难免会引入各种各样的工具包，所以，基本上SpringBoot项目，如果不注意，肯定会出现这种冲突的。

参考文章

https://blog.csdn.net/huangrunqing/article/details/51782374
https://www.cnblogs.com/hanszhao/p/9754419.html
https://blog.csdn.net/wohaqiyi/article/details/81009689
https://segmentfault.com/a/1190000017285395