I recently added the following test to ensure any runtime exceptions thrown during multi-threaded report generation were being logged correctly.

1    public void testExceptionHandling() {
2       CloverExecutor executor = CloverExecutors.newCloverExecutor(10, "CLOVER-EXCEPTION-TEST");
3        Logger logger = Logger.getInstance();
4        try {
5            RecordingLogger bufferLogger = new RecordingLogger();
6            Logger.setInstance(bufferLogger);
7
8            executor.submit(new ExceptionCallable());
9
10           assertTrue(bufferLogger.contains(runtimeException));
11           assertTrue(bufferLogger.contains(runtimeException.getMessage()));
12       } catch (Exception e) {
13           fail("Exception thrown, which should have been caught and logged." + e);
14       } finally {
15           Logger.setInstance(logger);
16       }
17}

RecordingLogger is a test utility class that stores any log messages in a list. The #contains methods return true if the given argument was logged during execution.

This test initially failed and not because I was doing TDD ;) The assertion on line 10 was throwing an AssertionFailedError.

Can you spot the bug?

Bugger.

Instead of diving into the debugger, I had a look at the code coverage of the RecordingLogger class:

#find is a method that gets called by #contains to do the actual lookup in the list.
Viewing the coverage made it clear that the buffer was empty for both calls to #find.
This lead me to the reason why the test was failing - the executor did not have enough time to fire up its thread, pop my Callable on the queue and execute it.

The one line fix was easy:

        executor.awaitTermination(1000, TimeUnit.MILLISECONDS);

Viewing code coverage often provides enough insight into the cause of a failing test and is a cheap alternative to adding printlns or firing up the debugger. During testing, I think of it as a "static debugger". In fact, when stepping through the above code in a debugger, the test passes.