SpringBoot Debug logging from StandardServletEnvironment is output when we use logback-spring.xml instead of logback.xml

Spring boot version - 2.2.8.RELEASE

Maybe it is related with issue 13736 "Debug logging from StandardServletEnvironment is output when a war file is deployed to a container #13736"

but if i change logback config file from logback.xml to logback-spring.xml my class "MyEnvironment extends StandardServletEnvironment" start printing debug info to console. Looks like it doesn't see logback settings and use logback defaults.

the class:

public class MyEnvironment extends StandardServletEnvironment {

    private static final Logger LOG = LoggerFactory.getLogger(MyEnvironment.class);

    @Override
    protected void customizePropertySources(MutablePropertySources propSources) {
        LOG.debug("why are u printing this?");
    }

}

registration:

public static void main(String[] args) {
    SpringApplication app = new SpringApplication(WebApp.class);
    app.setEnvironment(new MyEnvironment());       
    app.setAllowBeanDefinitionOverriding(true);
    app.run(args);
}

Comment From: wilkinsona

Thanks for the report. Spring Boot 2.2.x has reached the end of its OSS support period. Can you please try Spring Boot 2.3.x or 2.4.x and let us know if the problem still occurs. If it does and you would like us to spend some time investigating, please spend some time providing a complete yet minimal sample that reproduces the problem. You can share it with us by pushing it to a separate repository on GitHub or by zipping it up and attaching it to this issue.

Comment From: knihuta

@wilkinsona demo.zip

Demo project for spring boot 2.3.9.RELEASE The issue is reproduced - in console you will see

[main] DEBUG com.example.demo.MyEnvironment - why are u printing this? [main] WARN com.example.demo.MyEnvironment - printing warn is ok

with root level="WARN" in logback-spring.xml

Comment From: wilkinsona

Thanks for the sample. The Environment is the source for properties that are used to configure the logging system. This means that it is called before the logging system has been configured and, in the absence of a logback.xml file, logging will be using Logback's default configuration.

Spring Boot has a DeferredLog class that can be used in situations like this. For example, Boot uses it in the class that adds the contents of application.properties files to the Environment. You can update your custom Environment implementation to use it like this:

public class MyEnvironment extends StandardServletEnvironment {

    private static final DeferredLog LOG = new DeferredLog();

    @Override
    protected void customizePropertySources(MutablePropertySources propSources) {
        super.customizePropertySources(propSources);

        LOG.debug("why are u printing this?");
        LOG.warn("printing warn is ok");
    }

    @Override
    public void initPropertySources(ServletContext servletContext, ServletConfig servletConfig) {
        LOG.switchTo(MyEnvironment.class);
        super.initPropertySources(servletContext, servletConfig);
    }

}

Any deferred logging will be output when initPropertySources is called. This happens after the logging system has been initialised, thereby preventing the debug output from being logged:

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.9.RELEASE)

2021-03-19 14:03:16 [main] WARN  com.example.demo.MyEnvironment - printing warn is ok