Nsryjdtyk

Here's some output to give an example of what I'm talking about. The debug messages don't come solely from the Aspect4J logger, they come from several other classes as well. I've debugged the application and found that the Root logger is set to DEBUG, then later on set to INFO after the Spring Banner is printed (I don't think the banner specifically has anything to do with it).

I don't have any logging related files on my classpath unless they've been added by a dependency I'm unaware of.

I also tried setting.

# Logging

logging.level.root=INFO

logging.level.org.springframework.web=INFO

logging.level.org.hibernate=INFO

In my application.properties file but that did not help, Spring Boot 2.1 still output everything at DEBUG level until the banner printed. Any idea on how I might prevent the Root logger from coming up as DEBUG instead of INFO at the beginning would be great.

15:34:47.971 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'org.springframework.boot.logging.AbstractLoggingSystem'

15:34:47.974 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'ch.qos.logback.classic.joran.JoranConfigurator'

15:34:47.976 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'ch.qos.logback.core.joran.JoranConfiguratorBase'

15:34:47.979 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'ch.qos.logback.core.joran.GenericConfigurator'

15:34:47.980 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'org.springframework.boot.logging.logback.SpringBootJoranConfigurator'

15:34:47.982 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'ch.qos.logback.classic.spi.LoggerContextListener'

15:34:47.985 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'ch.qos.logback.classic.turbo.TurboFilter'

15:34:47.987 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'org.springframework.boot.logging.logback.LogbackLoggingSystem$1'

15:34:47.988 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'org.springframework.boot.logging.LoggerConfigurationComparator'

15:34:47.989 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'org.springframework.boot.logging.AbstractLoggingSystem$LogLevels'

15:34:48.009 [main] DEBUG AspectJ Weaver - [AspectJ] not weaving 'org.slf4j.bridge.SLF4JBridgeHandler'



  .   ____          _            __ _ _

 /\ / ___'_ __ _ _(_)_ __  __ _    

( ( )___ | '_ | '_| | '_ / _` |    

 \/  ___)| |_)| | | | | || (_| |  ) ) ) )

  '  |____| .__|_| |_|_| |___, | / / / /

 =========|_|==============|___/=/_/_/_/

 :: Spring Boot ::        (v2.0.1.RELEASE)



2018-11-21 15:34:50.094  INFO 1 --- [           main] c.s.technology.screening.SpringConfig    : Starting SpringConfig on 940e73166080 with PID 1 (/web.jar started by root in /)

2018-11-21 15:34:50.100  INFO 1 --- [           main] c.s.technology.screening.SpringConfig    : No active profile set, falling back to default profiles: default

2018-11-21 15:34:50.420  INFO 1 --- [           main] ConfigServletWebServerApplicationContext : Refreshing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@4e0ae11f: startup date [Wed Nov 21 15:34:50 EST 2018]; root of context hierarchy

2018-11-21 15:34:53.506  INFO 1 --- [           main] AspectJ Weaver                           : [AspectJ] Join point 'method-execution(org.springframework.data.domain.Page com.sasquatch.technology.screening.api.JobController.listJobs(org.springframework.data.domain.Pageable))' in Type 'com.sasquatch.technology.screening.api.JobController' (JobController.java:48) advised by around advice from 'org.springframework.security.access.intercept.aspectj.aspect.AnnotationSecurityAspect' (AnnotationSecurityAspect.aj:70)

2018-11-21 15:34:53.525  INFO 1 --- [           main] AspectJ Weaver                           : [AspectJ] Join point 'method-execution(com.sasquatch.technology.screening.persistence.entities.Job com.sasquatch.technology.screening.api.JobController.addJob(com.sasquatch.technology.screening.persistence.entities.Job))' in Type 'com.sasquatch.technology.screening.api.JobController' (JobController.java:54) advised by around advice from 'org.springframework.security.access.intercept.aspectj.aspect.AnnotationSecurityAspect' (AnnotationSecurityAspect.aj:70)

2018-11-21 15:34:53.620  INFO 1 --- [           main] AspectJ Weaver                           : [AspectJ] Join point 'method-execution(org.springframework.http.ResponseEntity com.sasquatch.technology.screening.api.TestHelperController.resetDatabase())' in Type 'com.sasquatch.technology.screening.api.TestHelperController' (TestHelperController.java:45) advised by around advice from 'org.springframework.transaction.aspectj.AnnotationTransactionAspect' (AbstractTransactionAspect.aj:66)

I was able to trace the source of the problem back to the fact that Spring does not set the logging level until it initializes and runs the implementation class for org.springframework.boot.logging.LoggingSystem. And when Logback boots up it sets the Root logger to DEBUG by default in the ch.qos.logback.classic.LoggerContext class this.root.setLevel(Level.DEBUG).

I added the following code to a static initialization block inside of the class which contains the main() method that boots up the Spring application. The root logger gets fetched (which initializes it to DEBUG), and then cast to a Logback logger. Keep in mind this means this implementation of a fix is tied to the real logging implementation on the classpath. If I were doing all my logging through log4j or apache commons the logger I get from LoggerFactory.getLogger() would be a different type and therefore need a different cast. This cast is necessary because the SLF4J facade does not expose methods to programmatically change the logging level. Once I had a refrence to the root logger, then I just set the level. This level is eventually overridden by Spring, so I'll need to do some more plumbing if I want to automagically keep the Spring settings and my initialization block the same.

@SpringBootApplication

public class SpringConfig {



    static {

        ((ch.qos.logback.classic.Logger) org.slf4j.LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME)).setLevel(Level.INFO);

    }

}