In a unit test using Dropwizard 1.2.1, junit and DAOTestRule, a call to DAOTestRule.newBuilder().build(); seems to reset the loglevel in slf4j to error.
I’ve got a class like this:
package test;
import com.tngtech.java.junit.dataprovider.DataProviderRunner;
import io.dropwizard.testing.junit.DAOTestRule;
import org.junit.ClassRule;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@RunWith(DataProviderRunner.class)
public class TestLogger {
public static Logger logger = LoggerFactory.getLogger(TestLogger.class);
@ClassRule
public static DAOTestRule database = DAOTestRule.newBuilder().build();
@Test
public void testGiveConsent() {
logger.error("error");
logger.info("info");
logger.debug("debug");
}
}
and a logback.xml config like this:
<configuration debug="true">
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<logger name="test" level="DEBUG" />
<root level="INFO">
<appender-ref ref="STDOUT" />
</root>
</configuration>
When I run this test I expect to see 3 log statements, but get only 1:
21:49:18,498 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
21:49:18,498 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
21:49:18,498 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/target/test-classes/logback.xml]
21:49:18,617 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
21:49:18,621 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
21:49:18,632 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
21:49:18,690 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [test] to INFO
21:49:18,690 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
21:49:18,690 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
21:49:18,691 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
21:49:18,692 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@6325a3ee - Registering current configuration as safe fallback point
21:49:18.708 [main] ERROR test.TestLogger - error
If I remove the initialization of DAOTestRule database:
public static DAOTestRule database = null;
the output changes from
21:49:18.708 [main] ERROR test.TestLogger - error
to:
21:46:02.298 [main] ERROR test.TestLogger - error
21:46:02.299 [main] INFO test.TestLogger - info
21:46:02.299 [main] DEBUG test.TestLogger – debug
which is the output I would expect to see. Changing the loglevel in logback.xml also changes the output, so I guess the logback.xml file is correct and is found by the test.
How can I get logging on debug level in tests that depend on DAOTestRule?