Spring Boot 3.2 automatically change log level during shutdown

157 Views Asked by At

We recently upgraded springBoot version to 3.2, and Java 21 64 bit. We observed wired behaviour while shutting down spring boot application , log level automatically change INFO to ERROR, and we are not getting expected log messages.

After so many research, we found there is a feature "automatic log level propagation".

We have some important INFO messages that should appear during application off.

We tried to disable with few properties like : management.tracing.enabled = false spring.main.log-shutdown-info = true

But nothing help, it is still ERROR.

Please suggest and help what we can do to get INFO level at end of application.

We need INFO log level while spring boot application is shutting down.

As per Shutdown Log when run the application with argument -Dlog4j2.debug : TRACE StatusLogger [AsyncContext@25bbe1b6] AsyncLoggerDisruptor: disruptor has been shut down :

Shutdown log

TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class jp.co.tec.ngp.broker.device.controller.DeviceAdminApiContoller
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class jp.co.tec.ngp.broker.device.admin.DeviceAdminServiceImpl
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class jp.co.tec.ngp.broker.device.admin.BrokerAdminServiceImpl
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class jp.co.tec.ngp.broker.service.impl.BrokerServiceImpl
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.transport.tcp.TcpTransportFactory
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.util.ServiceSupport
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.transport.TransportSupport
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.transport.tcp.TcpTransport
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.transport.AbstractInactivityMonitor
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.transport.InactivityMonitor
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.transport.WireFormatNegotiator
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.transport.ResponseCorrelator
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.util.IdGenerator
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.thread.SchedulerTimerTask
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.transport.FutureResponse
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.AdvisoryConsumer
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.ActiveMQSession
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.TransactionContext
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.ActiveMQSessionExecutor
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.ActiveMQMessageProducer
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.management.JMSEndpointStatsImpl
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.util.ThreadPoolUtils
TRACE StatusLogger Log4jLoggerFactory.getContext() found anchor class org.apache.activemq.thread.TaskRunnerFactory
DEBUG StatusLogger [AsyncContext@25bbe1b6] AsyncLoggerDisruptor: shutting down disruptor for this context.
TRACE StatusLogger [AsyncContext@25bbe1b6] AsyncLoggerDisruptor: disruptor has been shut down.
DEBUG StatusLogger Stopping LoggerContext[name=AsyncContext@25bbe1b6, org.apache.logging.log4j.core.async.AsyncLoggerContext@45d2ade3]...
WARN StatusLogger [AsyncContext@25bbe1b6] Ignoring log event after log4j was shut down: INFO [jp.co.tec.ngp.broker.device.base.statemachine.BaseStateMachineListener] [stateChanged] -------------------------------------------
TRACE StatusLogger Unregistering 1 MBeans: [org.apache.logging.log4j2:type=AsyncContext@25bbe1b6]
WARN StatusLogger Ignoring log event after log4j was shut down
TRACE StatusLogger Unregistering 1 MBeans: [org.apache.logging.log4j2:type=AsyncContext@25bbe1b6,component=StatusLogger]
WARN StatusLogger [AsyncContext@25bbe1b6] Ignoring log event after log4j was shut down: INFO [jp.co.tec.ngp.broker.device.base.statemachine.BaseStateMachineListener] [stateChanged] Device- CashChanger state change to sub state STOPPED
TRACE StatusLogger Unregistering 1 MBeans: [org.apache.logging.log4j2:type=AsyncContext@25bbe1b6,component=ContextSelector]
WARN StatusLogger Ignoring log event after log4j was shut down
1

There are 1 best solutions below

3
Piotr P. Karwasz On

The problem you are having is due to the ordering between application listeners: the LoggingApplicationListener has a very high precedence of:

Ordered.HIGHEST_PRECEDENCE + 20

This means that the listener is called pretty early at startup, but unless I am mistaken Spring calls listeners in the same order at shutdown.

If your shutdown listener requires logging, it should have a precedence between Ordered.HIGHEST_PRECEDENCE and Ordered.HIGHEST_PRECEDENCE + 19. Specifying the order can be done either by implementing Ordered or using the @Order annotation.