93 log4j-slf4j-impl 搭配上 log4j-to-slf4j 导致的 StackOverflow

前言

呵呵 最近想要 做一个 mongo 低版本的客户端读取高版本的服务端传递过来的数据造成的一个错误的时候, 出现了这样的问题  

引入了 mongo-java-driver 之后, 使用相关 api 的时候会触发 com.mongo.internal.connection.BaseCluser 的初始化, 其依赖的 Loggers 间接的依赖的是 org.slf4j.LoggerFactory 来获取 logger 

然后 启动一个简单的 public static void main, 之后就 StackOverflow 了 

稍微看了一下, 是由于 log4j-slf4j-impl 和 log4j-to-slf4j 依赖, 导致的一个比现的一个问题 

因此 来一个 case 看一下 具体的情况 

也顺便 看了一下 slf4j 和 log4j, 以及他们的一些关联关系, 之前 也是稀里糊涂的复制过来直接使用, 没有怎么关注这个 

简单的来说 slf4j 是一套接口, 一套约束, 适配了各种实现, slf4j-api.jar 属于接口的约束, log4j-slf4j-impl 属于 log4j 适配 slf4j 系列接口的具体的实现 

log4j 是一种具体的日志输出的实现, 和 logback, slf4j-simple, jdk的Logger 都属于具体的 impl 

 

 

测试用例

依赖如下

        <dependency><groupId>org.apache.logging.log4j</groupId><artifactId>log4j-slf4j-impl</artifactId><version>2.10.0</version></dependency><dependency><groupId>org.apache.logging.log4j</groupId><artifactId>log4j-to-slf4j</artifactId><version>2.13.2</version></dependency>

 

测试用例

package com.hx.test;import org.slf4j.Logger;
import org.slf4j.LoggerFactory;/*** Test01LoggerStackOverflow** @author Jerry.X.He <[e-mail]>* @version 1.0* @date 2021-10-23 12:08*/
public class Test01LoggerStackOverflow {// loggerpublic static final Logger LOGGER = LoggerFactory.getLogger(Test01LoggerStackOverflow.class);// Test01LoggerStackOverflowpublic static void main(String[] args) {LOGGER.error("Hello World");}}

 

启动之后抛出异常如下, 是在 LoggerFactory.getLogger 的时候 

Exception in thread "main" java.lang.StackOverflowErrorat 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:355)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:355)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)

 

 

问题的调试

这个问题 我们要关注两个地方, 一个是 LoggerFactory 的选择, 一个是 LoggerContextFactory 的选择 

slf4j-simple 里面的实现就相对简单, 直接通过 LoggerFactory 创建 Logger 

但是 log4j-slf4j-impl 里面需要实际工作的 Logger 是 log4j 的 Logger, log4j 中构建 Logger 需要构建 LoggerContext, 并基于 LoggerContext 来创建 Logger 

 

 

LoggerFactory 的选择

首先来看一下 LoggerFactory 的一些初始化的地方  

这里获取 Slf4jServiceProvier 是通过 serviceloader 来实现的, 我们这里只能够获取到一个 provider, 这个 是 log4j-slf4j-impl 里面的一个具体的实现 

 

比如我现在增加一个 slf4j-simple 的一个实现, 那么 这里可以获取到两个 Slf4jServiceProvier 

 

存在多个 Slf4jServiceProvider 的情况下, 就会输出我们常见的如下日志信息, 并且日志中输出了 选择的是哪一个 Slf4jServiceProvider, 选择的规则是选择第一个  

 

 

LoggerContextFactory 的选择 

我们来具体看一下 log4j-slf4j-impl 里面 LoggerFactory 创建 Logger 的具体的实现 

看这里创建了一个 context, 并使用 context 创建 Logger, 按道理来说, 我们期望这个 context.getLogger 应该是一个具体的创建 Logger 的地方 

但是可以看到这里的 context 的到的是一个 Slf4jLoggerContext[是在 log4j-to-slf4j.jar 的包中], 这个 context 里面没有创建 Logger, 而是吧创建 Logger 的业务委托给了 org.slf4j.LoggerFactory, 所以 这里就构成了一个没有退出边界的递归, 造成了 StackOverflow 

 

我们来看一下 正常的的情况下, 可以看到 这里获取到的 LoggerContext 是 log4j-core 下面的 

然后实际的工作, 也是创建真实的 log4j 的 Logger  

 

 

为什么 log4j-slf4j-impl 和 log4j-to-slf4j 都存在的时候, 会选择到 Slf4jLoggerContext 呢 ?

AbstractLoggerAdapter 中创建 LoggerContext 是委托给了 LogManager 

LogManager 中创建 LoggerContext 取决于具体的 factory, 也就是 LoggerContextFactory 

ProviderUtil 中使用 servicelaoder 加载对应的 Provider 加载了两个, 一个是 Log4jContextFactory, 一个是 Slf4jLoggerContextFactory, 并且 Slf4jLoggerContextFactory 的优先级比 Log4jContextFactory 要高, 因此优先选择的是 Slf4jLoggerContextFactory 

这两个 Provider 分别是来自于 log4j-slf4j-impl 和 log4j-to-slf4j 这两个包中 

 

 

所以 如果你不需要 log4j-to-slf4j 的话, 可以直接排除掉这个包避免问题 

当然 还有其他一些方式, 搞一个优先级更高的 Provider 

 

假设我们调整一下 Log4jContextFactory 的优先级

可以按到这里将  Log4jContextFactory 的优先级调整到了 20, 因此选择的 LoggerContextFactory 是 Log4jContextFactory, 做了真实的事情 

然后 最终程序运行正常, 符合我们期望的结果 

 

 

log4j-to-slf4j.jar 是干什么?

看一下 Slf4jLogger, 实现的 log4j 的接口, 入参是 slf4j 的 Logger, 那就是一个 slf4j 适配 log4j 的一个工具类

 

Slf4jLoggerContext 的内容, 主要是从上下文获取 slf4j 的 Logger, 然后将它转换成 Slf4jLogger[实现的是 log4j 的接口]

 

 

slf4j1.7.x 版本和 slf4j1.8.x 版本的上述流程的差异

主要的差异在于 1.7.x 版本中 Slf4jServiceProvider 的角色为 StaticLoggerBinder  

并且 1.7.x 中加载 StaticLoggerBinder 是基于 classloader 加载的, 不是基于 serviceloader 加载的

 

 

完