Spring Boot 2.0下配置Log4j2下的错误问题分析与解决

环境介绍

Spring Boot 2.0.2 Java 8

任务描述

由于Spring Boot 2.0 默认情况下是使用logback作为日志系统的，这里希望切换到log4j2.

pom.xml内容定义

这里在pom.xml新增了spring-boot中的日志组件

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

第一次运行碰到的错误信息

直接运行，在控制台中报出如下的错误信息：

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/D:/DevSpace/M2Space/ch/qos/logback/logback-classic/1.2.3/logback-classic-1.2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/D:/DevSpace/M2Space/org/apache/logging/log4j/log4j-slf4j-impl/2.10.0/log4j-slf4j-impl-2.10.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder]
13:55:11.713 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Included patterns for restart : []
13:55:11.721 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Excluded patterns for restart : [/spring-boot-actuator/target/classes/, /spring-boot-devtools/target/classes/, /spring-boot/target/classes/, /spring-boot-starter-[\w-]+/, /spring-boot-autoconfigure/target/classes/, /spring-boot-starter/target/classes/]
13:55:11.722 [main] DEBUG org.springframework.boot.devtools.restart.ChangeableUrls - Matching URLs for reloading : [file:/D:/CodeSpace/photobuyapi/target/classes/]
Logging system failed to initialize using configuration from ‘classpath:log4j2.xml‘
java.lang.IllegalStateException: Logback configuration error detected: 
ERROR in ch.qos.logback.core.joran.spi.Interpreter@3:17 - no applicable action for [properties], current ElementPath  is [[configuration][properties]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@4:35 - no applicable action for [property], current ElementPath  is [[configuration][properties][property]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@7:16 - no applicable action for [appenders], current ElementPath  is [[configuration][appenders]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@9:53 - no applicable action for [Console], current ElementPath  is [[configuration][appenders][Console]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@10:92 - no applicable action for [PatternLayout], current ElementPath  is [[configuration][appenders][Console][PatternLayout]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@16:91 - no applicable action for [RollingRandomAccessFile], current ElementPath  is [[configuration][appenders][RollingRandomAccessFile]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@17:106 - no applicable action for [PatternLayout], current ElementPath  is [[configuration][appenders][RollingRandomAccessFile][PatternLayout]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@18:23 - no applicable action for [Policies], current ElementPath  is [[configuration][appenders][RollingRandomAccessFile][Policies]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@19:45 - no applicable action for [TimeBasedTriggeringPolicy], current ElementPath  is [[configuration][appenders][RollingRandomAccessFile][Policies][TimeBasedTriggeringPolicy]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@21:48 - no applicable action for [DefaultRolloverStrategy], current ElementPath  is [[configuration][appenders][RollingRandomAccessFile][DefaultRolloverStrategy]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@25:14 - no applicable action for [loggers], current ElementPath  is [[configuration][loggers]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@27:58 - no applicable action for [logger], current ElementPath  is [[configuration][loggers][logger]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@30:74 - no applicable action for [logger], current ElementPath  is [[configuration][loggers][logger]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@31:42 - no applicable action for [appender-ref], current ElementPath  is [[configuration][loggers][logger][appender-ref]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@32:46 - no applicable action for [appender-ref], current ElementPath  is [[configuration][loggers][logger][appender-ref]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@36:28 - no applicable action for [root], current ElementPath  is [[configuration][loggers][root]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@37:42 - no applicable action for [appender-ref], current ElementPath  is [[configuration][loggers][root][appender-ref]]
ERROR in ch.qos.logback.core.joran.spi.Interpreter@38:46 - no applicable action for [appender-ref], current ElementPath  is [[configuration][loggers][root][appender-ref]]
 at org.springframework.boot.logging.logback.LogbackLoggingSystem.loadConfiguration(LogbackLoggingSystem.java:166)
 at org.springframework.boot.logging.AbstractLoggingSystem.initializeWithSpecificConfig(AbstractLoggingSystem.java:67)
 at org.springframework.boot.logging.AbstractLoggingSystem.initialize(AbstractLoggingSystem.java:57)
 at org.springframework.boot.logging.logback.LogbackLoggingSystem.initialize(LogbackLoggingSystem.java:114)
 at org.springframework.boot.context.logging.LoggingApplicationListener.initializeSystem(LoggingApplicationListener.java:269)
 at org.springframework.boot.context.logging.LoggingApplicationListener.initialize(LoggingApplicationListener.java:237)
 at org.springframework.boot.context.logging.LoggingApplicationListener.onApplicationEnvironmentPreparedEvent(LoggingApplicationListener.java:200)
 at org.springframework.boot.context.logging.LoggingApplicationListener.onApplicationEvent(LoggingApplicationListener.java:173)
 at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)
 at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)
 at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
 at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:127)
 at org.springframework.boot.context.event.EventPublishingRunListener.environmentPrepared(EventPublishingRunListener.java:74)
 at org.springframework.boot.SpringApplicationRunListeners.environmentPrepared(SpringApplicationRunListeners.java:54)
 at org.springframework.boot.SpringApplication.prepareEnvironment(SpringApplication.java:358)
 at org.springframework.boot.SpringApplication.run(SpringApplication.java:317)
 at org.springframework.boot.SpringApplication.run(SpringApplication.java:1255)
 at org.springframework.boot.SpringApplication.run(SpringApplication.java:1243)
 at com.jd.ai.cv.api.PubAPIApplication.main(PubAPIApplication.java:17)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:498)
 at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49)

从上述日志中，可以发现，默认使用了logback-classic的日志组件，所以和这里引用的logging组件发生了冲突。

注释掉logback

在pom.xml中注释掉logback.xml中的logback的引用类库，在Eclipse中的Dependency Hierarchy中搜索logback类库，右击选中，选择Exclude Maven Artifact…操作，就将exclude规则写到了pom.xml中了。

从上图中可以看到，这里是Logging组件本身对于logback有依赖，这里应该是从Logging中将logback的依赖包Exclude掉，但是…..问题出现了。在pom.xml，将看到如下的Exclude规则：

<dependency>
     <groupId>org.springframework.boot</groupId>
         <artifactId>spring-boot-starter-web</artifactId>
         <exclusions>
                <exclusion>
                    <groupId>ch.qos.logback</groupId>
                    <artifactId>logback-classic</artifactId>
                </exclusion>
         </exclusions>
</dependency>
<dependency>
      <groupId>org.springframework.boot</groupId>
      <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

虽然从图中看到的和pom.xml中的实际Exclude规则是不一致的，实际的Exclude规则被放到了Web的组件中了， 那为什么会是这样的？
那只能有一种解释，Web组件实质上依赖于Logging组件的，在组件的设计中，只是将logback类包放入到了Logging组件中，但是Spring Boot中的Web组件是直接使用logback类库的。所以，Exclude规则是发生在了Spring Boot的Web组件中。

第二次执行碰到的问题

在Exclude了logback之后，重新执行整个项目，希望可以正常启动项目，结果问题依然，只是错误信息不同了。。。。。

Exception in thread "main" java.lang.StackOverflowError
at org.apache.logging.log4j.util.StackLocator.getCallerClass(StackLocator.java:112)
at org.apache.logging.log4j.util.StackLocator.getCallerClass(StackLocator.java:125)
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)
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)

从错误信息中可以发现，发生死循环了，哪里来的死循环呢？是Log4j的实例化过程中死循环。

问题的解决

在经历了若干个分钟的无奈思考之后，于是想尝试一下。由于Web组件中直接依赖了Logging组件，导致了整个问题的发生，是否可以直接将Logging组件从Web中Exclude掉，然后在pom.xml中直接引入Logging组件。是否就可以解决问题？
大胆假设，小心求证，来吧。

<dependency>
    <groupId>org.springframework.boot</groupId>
         <artifactId>spring-boot-starter-web</artifactId>
         <exclusions>
            <exclusion>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-logging</artifactId>
        </exclusion>
            <exclusion>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
        </exclusion>
    </exclusions>
</dependency>

如果上述的方法依然无法解决您的问题，就基于如下的方式，直接排除掉logging的组件：

<dependency>
          <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework.boot</groupId>
                    <artifactId>spring-boot-starter-logging</artifactId>
                </exclusion>
            </exclusions>
        </dependency>

重新执行

系统正常启动，问题已解决。

总结

这里的问题症结点在logging组件与log4j2组件在Spring Boot体系中的彼此冲突问题，这里只能Exclude掉其中一个，方可正常地启动系统。