Spring Boot 3.2关闭时日志级别自动从INFO转为ERROR的解决求助

问题背景 #

我们将Spring Boot版本升级至3.2，同时切换到Java 21 64位后，发现应用关闭时无法输出预期的INFO日志，初步观察误以为是日志级别自动从INFO变为ERROR。

经调研曾怀疑与“automatic log level propagation”特性有关，尝试以下配置未生效：

management.tracing.enabled = false
spring.main.log-shutdown-info = true

日志分析（添加-Dlog4j2.debug后的关闭日志） #

TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 jp.co.tec.ngp.broker.device.controller.DeviceAdminApiContoller
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 jp.co.tec.ngp.broker.device.admin.DeviceAdminServiceImpl
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 jp.co.tec.ngp.broker.device.admin.BrokerAdminServiceImpl
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 jp.co.tec.ngp.broker.service.impl.BrokerServiceImpl
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.transport.tcp.TcpTransportFactory
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.util.ServiceSupport
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.transport.TransportSupport
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.transport.tcp.TcpTransport
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.transport.AbstractInactivityMonitor
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.transport.InactivityMonitor
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.transport.WireFormatNegotiator
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.transport.ResponseCorrelator
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.util.IdGenerator
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.thread.SchedulerTimerTask
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.transport.FutureResponse
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.AdvisoryConsumer
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.ActiveMQSession
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.TransactionContext
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.ActiveMQSessionExecutor
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.ActiveMQMessageProducer
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.management.JMSEndpointStatsImpl
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.util.ThreadPoolUtils
TRACE StatusLogger Log4jLoggerFactory.getContext() 找到锚点类 org.apache.activemq.thread.TaskRunnerFactory
DEBUG StatusLogger [AsyncContext@25bbe1b6] AsyncLoggerDisruptor: 正在关闭此上下文的Disruptor。
TRACE StatusLogger [AsyncContext@25bbe1b6] AsyncLoggerDisruptor: Disruptor已关闭。
DEBUG StatusLogger 正在停止LoggerContext[name=AsyncContext@25bbe1b6, org.apache.logging.log4j.core.async.AsyncLoggerContext@45d2ade3]...
WARN StatusLogger [AsyncContext@25bbe1b6] Log4j关闭后忽略日志事件: INFO [jp.co.tec.ngp.broker.device.base.statemachine.BaseStateMachineListener] [stateChanged] -------------------------------------------
TRACE StatusLogger 注销1个MBean: [org.apache.logging.log4j2:type=AsyncContext@25bbe1b6]
WARN StatusLogger Log4j关闭后忽略日志事件
TRACE StatusLogger 注销1个MBean: [org.apache.logging.log4j2:type=AsyncContext@25bbe1b6,component=StatusLogger]
WARN StatusLogger [AsyncContext@25bbe1b6] Log4j关闭后忽略日志事件: INFO [jp.co.tec.ngp.broker.device.base.statemachine.BaseStateMachineListener] [stateChanged] 设备- CashChanger状态变更为子状态STOPPED
TRACE StatusLogger 注销1个MBean: [org.apache.logging.log4j2:type=AsyncContext@25bbe1b6,component=ContextSelector]
WARN StatusLogger Log4j关闭后忽略日志事件

从日志中的WARN StatusLogger [AsyncContext@25bbe1b6] Log4j关闭后忽略日志事件可以明确：问题根源不是日志级别被修改为ERROR，而是Log4j2上下文提前关闭，导致后续的INFO日志被直接丢弃，和最初怀疑的"automatic log level propagation"无关。

解决方案 #

方案1：禁用Log4j2自动关闭钩子 #

Spring Boot默认会在上下文关闭流程中提前关闭Log4j2，导致后续Bean销毁时的日志无法输出。通过以下配置禁用Log4j2的自动关闭钩子，让Spring在所有Bean销毁完成后再处理日志上下文：

在application.properties中添加：

logging.log4j2.shutdownHook.enabled = false

或者YAML格式：

logging:
  log4j2:
    shutdownHook:
      enabled: false

方案2：确保关闭日志在Spring生命周期内优先执行 #

如果你的INFO日志是在@PreDestroy方法或ApplicationListener<ContextClosedEvent>中输出，需要确保这些逻辑在Spring上下文关闭的早期阶段执行，避免日志上下文关闭后才触发。

可以通过实现Ordered接口设置最高优先级：

@Component
public class ShutdownInfoLogger implements ApplicationListener<ContextClosedEvent>, Ordered {

    private static final Logger logger = LoggerFactory.getLogger(ShutdownInfoLogger.class);

    @Override
    public void onApplicationEvent(ContextClosedEvent event) {
        // 输出关键关闭日志
        logger.info("应用开始关闭，当前设备状态：XXX");
        // 其他业务日志逻辑
    }

    @Override
    public int getOrder() {
        return Ordered.HIGHEST_PRECEDENCE; // 优先执行
    }
}

方案3：调整异步日志关闭超时时间 #

从日志可以看出使用了异步日志（AsyncLoggerContext），异步日志的Disruptor会提前关闭导致日志丢失。可以配置超时时间，确保异步日志有足够时间输出完成：

在application.properties中添加：

logging.log4j2.asyncLoggerShutdownTimeout = 3000

或者在Log4j2配置文件（如log4j2.xml）中添加：

<AsyncLoggerConfig shutdownTimeout="3000">
    <!-- 你的日志配置内容 -->
</AsyncLoggerConfig>

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