Is there any way to automatically execute JUnit testcases once with all logging enabled and once with all logging disabled to increase code-coverage and find subtle bugs?

Question

I've found a solution, see my own answer below. Does anyone have a more elegant one?

Assume the following class to be tested:

public class Foo {
    private final Logger logger = LoggerFactory.getLogger(Foo.class);
    public void bar() {
        String param=[..];
        if(logger.isInfoEnabled()) logger.info("A message with parameter {}", param);

        if(logger.isDebugEnabled()) {
            // some complicated preparation for the debug message
            logger.debug([the debug message]);
        }
    }
}

and the following test-class:

public class FooTest {
    @Test
    public void bar() {
        Foo foo=new Foo();
        foo.bar();
    }
}

A code-coverage tool like e.g. Cobertura will correctly report that only some of the conditional branches have been checked.

info and debug are either activated or deactivated for the logger.

Besides looking bad in your coverage score, this poses a real risk.

What if there is some side effect caused by code inside if(logger.isDebugEnabled())? What if your code does only work if DEBUG is enabled and fails miserably if the log level is set to INFO? (This actually happened in one of our projects :p)

So my conclusion is that code containing logger statements should always be tested once with all logging enabled and once with all logging disabled...

Is there a way to do something like that with JUnit? I know how to globally enable or disable all my logging in Logback so the problem is: How can I execute the tests twice, once with logging enabled, once with logging disabled.

p.s. I'm aware of this question but I don't think this is a duplicate. I'm less concerned about the absolute coverage values but about subtle, hard-to-find bugs that might be contained inside of a if(logger.isDebugEnabled()).

Answer 1

I would recommend switching from JUnit to TestNG. TestNG has a lot of advanced features over JUnit. It enables you to run your tests multiple times with different configuration and I guess that's what you need

Answer 2

I've solved this problem by implementing a base class that test classes should extend if such functionality is desired.

The article Writing a parameterized JUnit test contained the solution.

See LoggingTestBase for the logging base class and LoggingTestBaseExampleTest for a simple example that's using it.

Every contained test method is executed three times:

1. It's executed using the logging as defined in logback-test.xml as usual. This is supposed to help while writing/debugging the tests.
2. It's executed with all logging enabled and written to a file. This file is deleted after the test.
3. It's executed with all logging disabled.

Yes, LoggingTestBase needs documentation ;)

Answer 3

Have you tried simply maintaining two separate log configuration files? Each one would log at different levels from the root logger.

All logging disabled:

...
<root>
    <priority value="OFF"/>
    <appender-ref ref="LOCAL_CONSOLE"/>
</root>
...

All logging enabled:

...
<root>
    <priority value="ALL"/>
    <appender-ref ref="LOCAL_CONSOLE"/>
</root>
...

Execution would specify different configurations on the classpath via a system parameter:

-Dlog4j.configuration=path/to/logging-off.xml
-Dlog4j.configuration=path/to/logging-on.xml

Answer 4

eqbridges suggestion of simply running the tests twice with different logging contexts seems the simplest. You don't have to remember to code the logic in every blessed test, for one big advantage. The other is that you can see which logging level is to blame very easily.

That being said, there a couple of strategies if you just had to do this in one test run.

For 3.8 I would put everything in suites, and make two suites, one for each logging level, which sets the logging level before running the tests. This is functionally the same thing as running the whole test suite twice with different command line parameters, except that you get it with one run.

In JUnit 4.x a couple of additional options come to mind:

One is a custom runner. Although I can't think off hand of everything you would have to do to make this work, but a runner that actually runs the test twice and annotating the test with @RunWith your custom runner could work.

The other is parameterized tests. Although you would actually have to set up every test to take parameters (this requires a constructor which takes the arguments) and then set the log level according to the parameter.

EDIT: In response to your request for a how-to on the paramterized tests, here is the javadoc on the runner to get you started, and here is a more practical guide.

Answer 5

If you feel you have too much logging if you turn everything on, perhaps you could try to cut down the amount of logging. Its not very useful if it too much for the computer to procude never mind a human to read.