Logback defaults to DEBUG level logging. When running integration tests, this can result in a large volume of log output before the logging system is initialized when we set the root level to INFO. We can register a Configurator via META-INF/services to set the root logger's level to INFO. If the user has their own logback.xml or logback-test.xml, they will overwrite this custom root level. Similarly, if the user's set logging.level.root, initialization of Boot's logging system will then overwrite the root level from our configurator.
Before this change, running Boot's SampleSessionRedisApplicationTests produces 1467 lines of log output before the Spring Boot banner is displayed. With this change in place, only 22 lines are output:
16:55:09.007 [main] INFO org.testcontainers.dockerclient.DockerClientProviderStrategy -- Loaded org.testcontainers.dockerclient.UnixSocketClientProviderStrategy from ~/.testcontainers.properties, will try it first
16:55:09.023 [main] WARN org.testcontainers.dockerclient.DockerClientProviderStrategy -- DOCKER_HOST tcp://127.0.0.1:53248 is not listening
16:55:09.254 [main] INFO org.testcontainers.dockerclient.DockerClientProviderStrategy -- Found Docker environment with local Unix socket (unix:///var/run/docker.sock)
16:55:09.255 [main] INFO org.testcontainers.DockerClientFactory -- Docker host IP address is localhost
16:55:09.273 [main] INFO org.testcontainers.DockerClientFactory -- Connected to docker:
Server Version: 20.10.24
API Version: 1.41
Operating System: Docker Desktop
Total Memory: 7958 MB
16:55:09.286 [main] INFO org.testcontainers.utility.ImageNameSubstitutor -- Image name substitution will be performed by: DefaultImageNameSubstitutor (composite of 'ConfigurationFileImageNameSubstitutor' and 'PrefixingImageNameSubstitutor')
16:55:09.417 [main] INFO tc.testcontainers/ryuk:0.4.0 -- Creating container for image: testcontainers/ryuk:0.4.0
16:55:09.976 [main] INFO org.testcontainers.utility.RegistryAuthLocator -- Credential helper/store (docker-credential-desktop) does not have credentials for https://index.docker.io/v1/
16:55:10.094 [main] INFO tc.testcontainers/ryuk:0.4.0 -- Container testcontainers/ryuk:0.4.0 is starting: 294906cde6c382778b32e582f1bfad872248b1d1469de5fda456513918fe9142
16:55:10.467 [main] INFO tc.testcontainers/ryuk:0.4.0 -- Container testcontainers/ryuk:0.4.0 started in PT1.176911S
16:55:10.472 [main] INFO org.testcontainers.utility.RyukResourceReaper -- Ryuk started - will monitor and terminate Testcontainers containers on JVM exit
16:55:10.472 [main] INFO org.testcontainers.DockerClientFactory -- Checking the system...
16:55:10.472 [main] INFO org.testcontainers.DockerClientFactory -- ✔︎ Docker server version should be at least 1.6.0
16:55:10.557 [main] INFO org.springframework.test.context.support.AnnotationConfigContextLoaderUtils -- Could not detect default configuration classes for test class [smoketest.session.redis.SampleSessionRedisApplicationTests]: SampleSessionRedisApplicationTests does not declare any static, non-private, non-final, nested classes annotated with @Configuration.
16:55:10.696 [main] INFO org.springframework.boot.test.context.SpringBootTestContextBootstrapper -- Found @SpringBootConfiguration smoketest.session.redis.SampleSessionRedisApplication for test class smoketest.session.redis.SampleSessionRedisApplicationTests
16:55:10.806 [main] INFO tc.redis:4.0.14 -- Creating container for image: redis:4.0.14
16:55:10.847 [main] INFO tc.redis:4.0.14 -- Container redis:4.0.14 is starting: 0ba4ff5c185fa7b3679002b14ab2ea04f65b83480c8de9ac876d7f174412d126
16:55:11.210 [main] INFO tc.redis:4.0.14 -- Container redis:4.0.14 started in PT0.403987S
Comment From: wilkinsona
It's also possible for this to be a problem in main code, for example when code that runs in the main method before the SpringApplication has started triggers some DEBUG logging. We're going to add the configurator for the root log level to spring-boot so that it's used both in tests and at runtime.