javaspring-bootlogback

Spring Boot - Logback Configuration - Annoying Boilerplate at beginning of log


I have a logback-spring.xml file in my project to configure logging to be plain text in my IDE and JSON on servers. That does work quite well, but there's a ton of boilerplaty logging garbage that logback produces directly after startup which does not follow the configurations from logback-spring.xml but just seems to be default configuration.

What gets logged out at the beginning of startup looks like this (logback blah, then the spring boot banner and then the actual json output that I am expecting)

I've tried to provide a standard logback.xml file but even with that one i get the same behaviour. Any ideas how i could remove this nonsese (of have it properly formatted)?

08:11:15,846 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.4.11
08:11:15,849 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - Here is a list of configurators discovered as a service, by rank: 
08:11:15,849 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 -   org.springframework.boot.logging.logback.RootLogLevelConfigurator
08:11:15,849 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - They will be invoked in order until ExecutionStatus.DO_NOT_INVOKE_NEXT_IF_ANY is returned.
08:11:15,850 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - Constructed configurator of type class org.springframework.boot.logging.logback.RootLogLevelConfigurator
08:11:15,853 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - org.springframework.boot.logging.logback.RootLogLevelConfigurator.configure() call lasted 1 milliseconds. ExecutionStatus=INVOKE_NEXT_IF_ANY
08:11:15,853 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - Trying to configure with ch.qos.logback.classic.joran.SerializedModelConfigurator
08:11:15,854 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - Constructed configurator of type class ch.qos.logback.classic.joran.SerializedModelConfigurator
08:11:15,881 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.scmo]
08:11:15,882 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.scmo]
08:11:15,882 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - ch.qos.logback.classic.joran.SerializedModelConfigurator.configure() call lasted 28 milliseconds. ExecutionStatus=INVOKE_NEXT_IF_ANY
08:11:15,882 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - Trying to configure with ch.qos.logback.classic.util.DefaultJoranConfigurator
08:11:15,882 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - Constructed configurator of type class ch.qos.logback.classic.util.DefaultJoranConfigurator
08:11:15,882 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
08:11:15,883 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/Users/matthiashuttar/dev/platform/kraken/libs/service-config/build/resources/main/logback.xml]
08:11:15,950 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [CONSOLE]
08:11:15,950 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
08:11:16,074 |-WARN in ch.qos.logback.core.ConsoleAppender[CONSOLE] - This appender no longer admits a layout as a sub-component, set an encoder instead.
08:11:16,074 |-WARN in ch.qos.logback.core.ConsoleAppender[CONSOLE] - To ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
08:11:16,074 |-WARN in ch.qos.logback.core.ConsoleAppender[CONSOLE] - See also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
08:11:16,074 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [de.herakles] to INFO
08:11:16,074 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [net.schmizz] to OFF
08:11:16,074 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to WARN
08:11:16,074 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [CONSOLE] to Logger[ROOT]
08:11:16,075 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@1c9b0314 - End of configuration.
08:11:16,075 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@45385f75 - Registering current configuration as safe fallback point
08:11:16,075 |-INFO in ch.qos.logback.classic.util.ContextInitializer@1f9f6368 - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 193 milliseconds. ExecutionStatus=DO_NOT_INVOKE_NEXT_IF_ANY

Standard Commons Logging discovery in action with spring-jcl: please remove commons-logging.jar from classpath in order to avoid potential conflicts
08:11:16,488 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [CONSOLE]
08:11:16,488 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
08:11:16,488 |-WARN in ch.qos.logback.core.ConsoleAppender[CONSOLE] - This appender no longer admits a layout as a sub-component, set an encoder instead.
08:11:16,488 |-WARN in ch.qos.logback.core.ConsoleAppender[CONSOLE] - To ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
08:11:16,488 |-WARN in ch.qos.logback.core.ConsoleAppender[CONSOLE] - See also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
08:11:16,488 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [de.herakles] to INFO
08:11:16,488 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@712ca57b - Propagating INFO level on Logger[de.herakles] onto the JUL framework
08:11:16,489 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [net.schmizz] to OFF
08:11:16,489 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@712ca57b - Propagating OFF level on Logger[net.schmizz] onto the JUL framework
08:11:16,489 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to WARN
08:11:16,489 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@712ca57b - Propagating WARN level on Logger[ROOT] onto the JUL framework
08:11:16,489 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [CONSOLE] to Logger[ROOT]
08:11:16,489 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@4564e94b - End of configuration.
08:11:16,489 |-INFO in org.springframework.boot.logging.logback.SpringBootJoranConfigurator@54534abf - Registering current configuration as safe fallback point

                        ___
                     .-'   `'.
                    /         \
                    |         ;
                    |         |           ___.--,
           _.._     |0) ~ (0) |    _.---'`__.-( (_.
    __.--'`_.. '.__.\    '--. \_.-' ,.--'`     `""`
   ( ,.--'`   ',__ /./;   ;, '.__.'`    __
   _`) )  .---.__.' / |   |\   \__..--""  """--.,_
  `---' .'.''-._.-'`_./  /\ '.  \ _.-~~~````~~~-._`-.__.'
        | |  .' _.-' |  |  \  \  '.               `~---`
         \ \/ .'     \  \   '. '-._)
          \/ /        \  \    `=.__`~-.
          / /\         `) )    / / `"".`\
    , _.-'.'\ \        / /    ( (     / /
     `--~`   ) )    .-'.'      '.'.  | (
            (/`    ( (`          ) )  '-;
             `      '-;         (-'

{"level":"info","message":"Starting KrakenCoreApplication using Java 21.0.1 with PID 34051 (/Users/matthiashuttar/dev/platform/kraken/apps/kraken-core/build/classes/java/main started by matthiashuttar in /Users/matthiashuttar/dev/platform)","thread":"main","logger":"de.herakles.platform.kraken.krakencore.KrakenCoreApplication"}

Solution

  • Solution was given in the content of these log messages. There's a deprecation warnings that layouts should not be used in favor of encoders. The reason that there is this warning caused logback to print all this logging information.

    when changed the logging configuration from using an encoder instead of a layout, the whole output went away.

    In my case, I had a custom Json Layout, that I wanted to keep using and didn't really care to migrate to an Encoder for now. Logback documentation mentions that a LayoutWrappingEncoder is there to help with such transitions, but it does not describe how it is being used.

    I'll post my change here, in case someone else might find it useful.

    This was my appender configuration before:

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="de.herakles.platform.kraken.serviceconfig.logging.HeraklesJsonLayout">
            <appendLineSeparator>true</appendLineSeparator>
            <includeContextName>false</includeContextName>
            <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter"/>
        </layout>
    </appender>
    

    and this is it now

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="de.herakles.platform.kraken.serviceconfig.logging.HeraklesJsonLayout">
                <appendLineSeparator>true</appendLineSeparator>
                <includeContextName>false</includeContextName>
                <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter"/>
            </layout>
        </encoder>
    </appender>
    

    what I just did, was to wrap the layout element inside an encoder element referencing to the fully qualified name of the LayoutWrappingEncoder.