Unit test log level changes to DEBUG after updating dependencies between AEM 6.4 to 6.5

Question

I have a project generated a couple of years ago, based on the AEM Project Archetype, that is currently using AEM 6.4 and getting upgraded to AEM 6.5.

<dependency>
    <groupId>com.adobe.aem</groupId>
    <artifactId>uber-jar</artifactId>
    <version>6.5.10</version>
    <scope>provided</scope>
</dependency>

After upgrading the AEM uber jar dependency from 6.4.8.2 to 6.5.10, we started seeing lots of DEBUG level messages printed in the console while tests, specifically ones based on the Sling Testing library, are executed. Apparently, all of them pertain to registering adapters for the purpose of mocking Sling.

14:36:32.141 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.SlingHttpServletRequest] and adapters : [com.example.XXXXXXX]
14:36:32.146 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.resource.Resource] and adapters : [com.example.XXXXXXX]
14:36:32.151 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.resource.Resource] and adapters : [com.adobe.acs.commons.workflow.bulk.execution.model.Config]
14:36:32.155 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.SlingHttpServletRequest, org.apache.sling.api.resource.Resource] and adapters : [com.example.XXXXXXX]
14:36:32.158 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.SlingHttpServletRequest, org.apache.sling.api.resource.Resource] and adapters : [com.adobe.cq.wcm.core.components.models.form.Button, com.adobe.cq.export.json.ComponentExporter]
14:36:32.159 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.resource.Resource] and adapters : [com.example.XXXXXXX]
14:36:32.160 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.resource.Resource] and adapters : [com.adobe.acs.commons.reports.models.QueryReportConfig]
14:36:32.161 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.resource.Resource, org.apache.sling.api.SlingHttpServletRequest] and adapters : [com.example.XXXXXXX]
14:36:32.165 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.SlingHttpServletRequest] and adapters : [com.adobe.cq.wcm.core.components.models.form.Text, com.adobe.cq.export.json.ComponentExporter]
14:36:32.165 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.resource.Resource] and adapters : [com.example.XXXXXXX]
14:36:32.167 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.SlingHttpServletRequest, org.apache.sling.api.resource.Resource] and adapters : [com.example.XXXXXXX]
14:36:32.168 [main] DEBUG org.apache.sling.testing.mock.sling.MockAdapterManagerImpl - Registered service org.apache.sling.adapter.Adaption with adaptables : [org.apache.sling.api.SlingHttpServletRequest] and adapters : [com.adobe.cq.wcm.core.components.models.form.Field, com.adobe.cq.export.json.ComponentExporter]
... and it goes on

At first, I thought this was happening because of a new SLF4J binding appearing on the classpath. The output does mention this being a problem.

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/foo/.m2/repository/com/adobe/aem/uber-jar/6.5.10/uber-jar-6.5.10.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/foo/.m2/repository/org/slf4j/slf4j-simple/1.7.25/slf4j-simple-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/foo/.m2/repository/uk/org/lidalia/slf4j-test/1.0.1/slf4j-test-1.0.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder]

However, I've managed to get this warning to disappear by excluding different versions of SLF4J in the pom, and the DEBUG-level logging is still there.

I've also generated a fresh AEM 6.5 project based on the Archetype and I can't reproduce the issue, despite multiple bindings being found.

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/home/foo/.m2/repository/uk/org/lidalia/slf4j-test/1.0.1/slf4j-test-1.0.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/foo/.m2/repository/com/adobe/aem/uber-jar/6.5.10/uber-jar-6.5.10.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [uk.org.lidalia.slf4jtest.TestLoggerFactory]

One thing I've noticed is that as soon as I use the 6.5 jar, the type of the binding actually used becomes different. In the fresh new project, it's uk.org.lidalia.slf4jtest.TestLoggerFactory and in my actual project, it's ch.qos.logback.classic.util.ContextSelectorStaticBinder, which does appear to be coming from the Uber Jar (I can see the class inside it)

This class seems to be just added to the archive, rather than as a transitive dependency so I can't find a way to exclude it.

Changing the Uber Jar version back from 6.5.10 to 6.4.8.4, with no other changes to the codebase or dependencies, causes the unit tests to stop printing these DEBUG level messages.

I've tried adding https://wcm.io/testing/logging/logback/ and https://github.com/apache/sling-org-apache-sling-testing-logging-mock as dependencies but this also doesn't seem to help.

What controls this log level and how does changing the uber-jar alter it?

Answer 1

Adding the following dependency fixed the issue for us.

<dependency>
    <groupId>io.wcm</groupId>
    <artifactId>io.wcm.testing.logging.logback</artifactId>
    <version>1.0.0</version>
    <scope>test</scope>
</dependency>