Logback issue
Table of Contents
Reproduce
-
Create application using Spring initializr
-
Add some minimal
logback-spring.xmllike
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<include resource="org/springframework/boot/logging/logback/defaults.xml"/>
<include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
<appender name="MY_CONSOLE_APPENDER" class="ch.qos.logback.core.ConsoleAppender" />
</configuration>Erroneous behavior
When starting the application, the following behavior can be observed, which did not occur with Spring Boot 2.7.x. The applications logs a lot of logback (internal) stuff.
17:34:44,541 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.4.11
17:34:44,543 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - Here is a list of configurators discovered as a service, by rank:
17:34:44,543 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - org.springframework.boot.logging.logback.RootLogLevelConfigurator
17:34:44,543 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - They will be invoked in order until ExecutionStatus.DO_NOT_INVOKE_NEXT_IF_ANY is returned.
17:34:44,543 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - Constructed configurator of type class org.springframework.boot.logging.logback.RootLogLevelConfigurator
17:34:44,552 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - org.springframework.boot.logging.logback.RootLogLevelConfigurator.configure() call lasted 1 milliseconds. ExecutionStatus=INVOKE_NEXT_IF_ANY
17:34:44,552 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - Trying to configure with ch.qos.logback.classic.joran.SerializedModelConfigurator
17:34:44,552 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - Constructed configurator of type class ch.qos.logback.classic.joran.SerializedModelConfigurator
17:34:44,559 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.scmo]
17:34:44,560 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.scmo]
17:34:44,560 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - ch.qos.logback.classic.joran.SerializedModelConfigurator.configure() call lasted 8 milliseconds. ExecutionStatus=INVOKE_NEXT_IF_ANY
17:34:44,560 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - Trying to configure with ch.qos.logback.classic.util.DefaultJoranConfigurator
17:34:44,560 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - Constructed configurator of type class ch.qos.logback.classic.util.DefaultJoranConfigurator
17:34:44,560 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
17:34:44,560 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.xml]
17:34:44,560 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 0 milliseconds. ExecutionStatus=INVOKE_NEXT_IF_ANY
17:34:44,560 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - Trying to configure with ch.qos.logback.classic.BasicConfigurator
17:34:44,561 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - Constructed configurator of type class ch.qos.logback.classic.BasicConfigurator
17:34:44,561 |-INFO in ch.qos.logback.classic.BasicConfigurator@6c0d9d86 - Setting up default configuration.
17:34:44,572 |-INFO in ch.qos.logback.classic.util.ContextInitializer@53fd0d10 - ch.qos.logback.classic.BasicConfigurator.configure() call lasted 11 milliseconds. ExecutionStatus=NEUTRAL
17:34:44,780 |-INFO in ch.qos.logback.core.joran.util.ConfigurationWatchListUtil@4ce1d6d0 - Adding [jar:file:/home/msievers/.m2/repository/org/springframework/boot/spring-boot/3.1.3/spring-boot-3.1.3.jar!/org/springframework/boot/logging/logback/defaults.xml] to configuration watch list.
17:34:44,780 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@24111ef1 - URL [jar:file:/home/msievers/.m2/repository/org/springframework/boot/spring-boot/3.1.3/spring-boot-3.1.3.jar!/org/springframework/boot/logging/logback/defaults.xml] is not of type file
17:34:44,782 |-INFO in ch.qos.logback.core.joran.action.ConversionRuleAction - registering conversion word clr with class [org.springframework.boot.logging.logback.ColorConverter]
17:34:44,783 |-INFO in ch.qos.logback.core.joran.action.ConversionRuleAction - registering conversion word wex with class [org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter]
17:34:44,783 |-INFO in ch.qos.logback.core.joran.action.ConversionRuleAction - registering conversion word wEx with class [org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter]
17:34:44,783 |-INFO in ch.qos.logback.core.joran.util.ConfigurationWatchListUtil@4ce1d6d0 - Adding [jar:file:/home/msievers/.m2/repository/org/springframework/boot/spring-boot/3.1.3/spring-boot-3.1.3.jar!/org/springframework/boot/logging/logback/console-appender.xml] to configuration watch list.
17:34:44,783 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@24111ef1 - URL [jar:file:/home/msievers/.m2/repository/org/springframework/boot/spring-boot/3.1.3/spring-boot-3.1.3.jar!/org/springframework/boot/logging/logback/console-appender.xml] is not of type file
17:34:44,801 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.apache.catalina.startup.DigesterFactory] to ERROR
17:34:44,802 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1f3f02ee - Propagating ERROR level on Logger[org.apache.catalina.startup.DigesterFactory] onto the JUL framework
17:34:44,802 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.apache.catalina.util.LifecycleBase] to ERROR
17:34:44,802 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1f3f02ee - Propagating ERROR level on Logger[org.apache.catalina.util.LifecycleBase] onto the JUL framework
17:34:44,802 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.apache.coyote.http11.Http11NioProtocol] to WARN
17:34:44,802 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1f3f02ee - Propagating WARN level on Logger[org.apache.coyote.http11.Http11NioProtocol] onto the JUL framework
17:34:44,802 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.apache.sshd.common.util.SecurityUtils] to WARN
17:34:44,802 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1f3f02ee - Propagating WARN level on Logger[org.apache.sshd.common.util.SecurityUtils] onto the JUL framework
17:34:44,802 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.apache.tomcat.util.net.NioSelectorPool] to WARN
17:34:44,802 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1f3f02ee - Propagating WARN level on Logger[org.apache.tomcat.util.net.NioSelectorPool] onto the JUL framework
17:34:44,802 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.eclipse.jetty.util.component.AbstractLifeCycle] to ERROR
17:34:44,802 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1f3f02ee - Propagating ERROR level on Logger[org.eclipse.jetty.util.component.AbstractLifeCycle] onto the JUL framework
17:34:44,802 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.hibernate.validator.internal.util.Version] to WARN
17:34:44,802 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1f3f02ee - Propagating WARN level on Logger[org.hibernate.validator.internal.util.Version] onto the JUL framework
17:34:44,802 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.springframework.boot.actuate.endpoint.jmx] to WARN
17:34:44,802 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1f3f02ee - Propagating WARN level on Logger[org.springframework.boot.actuate.endpoint.jmx] onto the JUL framework
17:34:44,802 |-WARN in ch.qos.logback.core.model.processor.AppenderModelHandler - Appender named [CONSOLE] not referenced. Skipping further processing.
17:34:44,802 |-WARN in ch.qos.logback.core.model.processor.AppenderModelHandler - Appender named [MY_CONSOLE_APPENDER] not referenced. Skipping further processing.
17:34:44,802 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@1fde5d22 - End of configuration.
17:34:44,803 |-INFO in org.springframework.boot.logging.logback.SpringBootJoranConfigurator@5dcb4f5f - Registering current configuration as safe fallback point
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v3.1.3)
Process finished with exit code 0Related Spring Boot issue
It seems this is related to the following existing Spring Boot issue * spring-projects/spring-boot#34505
Countermeasures
In the existing issue, a user mentions a workaround, namely setting
<statusListener class="ch.qos.logback.core.status.NopStatusListener" />
to disable the unwanted log outputs. However, this is just a workaround.