Gradle构建测试后控制台打印Logback日志问题求助

我们有一个Spring Boot 2应用，正从Log4j迁移至Logback，整体过程顺利，但遇到一个小问题：执行包含测试的Gradle构建时，在测试阶段即将完成（生命周期变为SUCCEEDED）前，Gradle控制台会打印大量日志。排查发现问题源于Logback的ConsoleAppender——禁用它日志就消失，但也会丢失所有正常日志输出。这些日志打印发生在Gradle生成JUnit XML测试报告之前（已查看Gradle调试日志确认）。

更特殊的是，只有少数特定包的日志会被打印到控制台：

• org.springframework.amqp
• com.zaxxer
• org.mockserver.log
• org.springframework.orm.jpa

所有打印的日志级别均为INFO。如果为这些包添加Logback日志器并设置为ERROR级别，控制台就不会再打印这些日志。我们无法理解为何Gradle会在所有测试完成后打印这些日志，希望解决该问题。

环境信息 #

• Java版本：17
• JUnit版本：5
• Gradle版本：8.0.2（Gradle 7.3.3也存在相同问题）

配置文件 #

junit-platform.properties #

junit.jupiter.execution.parallel.enabled=true
junit.jupiter.execution.parallel.mode.default=concurrent

# For Hypersistence test
junit.jupiter.testclass.order.default=org.junit.jupiter.api.ClassOrderer$OrderAnnotation

Gradle版本详情 #

Gradle 8.0.2

$ ./gradlew --version
------------------------------------------------------------
Gradle 8.0.2
------------------------------------------------------------

Build time:   2023-03-03 16:41:37 UTC
Revision:     7d6581558e226a580d91d399f7dfb9e3095c2b1d

Kotlin:       1.8.10
Groovy:       3.0.13
Ant:          Apache Ant(TM) version 1.10.11 compiled on July 10 2021
JVM:          17.0.6 (Amazon.com Inc. 17.0.6+10-LTS)
OS:           Mac OS X 13.2.1 aarch64

Gradle 7.3.3

$ gradle --version

------------------------------------------------------------
Gradle 7.3.3
------------------------------------------------------------

Build time:   2021-12-22 12:37:54 UTC
Revision:     6f556c80f945dc54b50e0be633da6c62dbe8dc71

Kotlin:       1.5.31
Groovy:       3.0.9
Ant:          Apache Ant(TM) version 1.10.11 compiled on July 10 2021
JVM:          17.0.6 (Amazon.com Inc. 17.0.6+10-LTS)
OS:           Mac OS X 13.2.1 aarch64

logback-test.xml #

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org.springframework.boot/logging/logback/default.xml"/>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{ISO8601} [%thread] %-5level %logger{10} - %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="TestLogAppender" class="application.TestLogAppender"/>

    <root level="INFO">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="TestLogAppender" />
    </root>
    <logger name="org.springframework.web" level="INFO"/>
    <logger name="org.springframework.jdbc" level="INFO"/>
    <logger name="org.apache.catalina" level="ERROR"/>
    <logger name="application" level="DEBUG"/>

</configuration>

gradle.properties（相关配置） #

org.gradle.logging.level=lifecycle

示例输出（仅保留org.springframework.orm.jpa未设为ERROR级别的情况） #

$ ./gradlew clean build
Starting a Gradle Daemon, 1 busy and 1 incompatible and 1 stopped Daemons could not be reused, use --status for details

> Task :application:compileJava
Note: Some input files use or override a deprecated API.
Note: Recompile with -Xlint:deprecation for details.
Note: Some input files use unchecked or unsafe operations.
Note: Recompile with -Xlint:unchecked for details.

> Task :application:compileTestJava
Note: Some input files use or override a deprecated API.
Note: Recompile with -Xlint:deprecation for details.
Note: Some input files use unchecked or unsafe operations.
Note: Recompile with -Xlint:unchecked for details.

> Task :application:test
OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2023-03-13 08:19:19,029 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:22,691 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:25,226 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:26,956 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:28,391 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:30,009 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:32,067 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:35,300 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:36,528 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:37,729 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:39,759 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'
2023-03-13 08:19:40,896 [SpringApplicationShutdownHook] INFO  o.s.o.j.LocalContainerEntityManagerFactoryBean - Closing JPA EntityManagerFactory for persistence unit 'default'

BUILD SUCCESSFUL in 1m 58s
21 actionable tasks: 21 executed

原因分析 #

这些日志来自SpringApplicationShutdownHook线程，是测试完成后Spring上下文销毁阶段输出的。之所以只看到特定包的INFO日志，原因如下：

1. 这些组件在上下文关闭时会主动输出INFO级别的销毁日志（比如EntityManagerFactory关闭、连接池销毁等）
2. Logback根日志级别为INFO，ConsoleAppender默认输出所有符合级别的日志，包括销毁阶段的日志
3. Gradle在测试任务执行后期会保留控制台输出捕获，所以这些销毁日志会在测试任务即将结束时集中打印

解决方法 #

方法1：针对特定包调整日志级别（最直接） #

在logback-test.xml中为目标包添加日志器，将级别设为WARN或ERROR，既保留正常测试日志，又屏蔽销毁阶段的INFO日志：

<logger name="org.springframework.amqp" level="WARN"/>
<logger name="com.zaxxer" level="WARN"/>
<logger name="org.mockserver.log" level="WARN"/>
<logger name="org.springframework.orm.jpa" level="WARN"/>

方法2：过滤ShutdownHook线程的日志（更彻底） #

如果不需要任何上下文销毁阶段的日志，可以在Logback的ConsoleAppender中添加过滤器，直接过滤SpringApplicationShutdownHook线程的日志：

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d{ISO8601} [%thread] %-5level %logger{10} - %msg%n</pattern>
    </encoder>
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
        <evaluator>
            <expression>threadName.equals("SpringApplicationShutdownHook")</expression>
        </evaluator>
        <OnMismatch>NEUTRAL</OnMismatch>
        <OnMatch>DENY</OnMatch>
    </filter>
</appender>

注意：该方法会过滤所有ShutdownHook线程的日志，若有需要保留的关键日志需谨慎使用。

方法3：通过Gradle控制测试任务日志 #

在Gradle构建脚本中调整测试任务的日志输出规则，只允许ERROR级别的日志输出到控制台：

test {
    logging {
        showStandardStreams = false
        events = ["FAILED", "ERROR"]
    }
}

这种方式会限制Gradle测试任务的控制台输出内容，但可能错过部分正常测试的INFO日志，需根据需求选择。

内容的提问来源于stack exchange，提问作者bvanseg