How can I get logging on debug level in tests that depend on Dropwizard DAOTestRule?

Viewed 386

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?

0 Answers
Related