Asynchronous tests, the Awaitility and uncaught exceptions from other threads.

1. Intro

A couple of weeks ago I’m tried to run all tests in the spring-framework project and found that sometimes some of them do not pass. These were tests of asynchronous events and a thread pool.

Sometimes tests fall because an iteration takes a different time on different machines. But tests were written with the expectation for a specific value of delay - not more than 100 milliseconds.

Also I found some tests where the duration time of delay is hardcoded by using the Thread.sleep(1000).

This is not a good practice because each of these tests is waiting at least one second even if the test case completes after 10 ms. If we’ve a lot of such tests than we will wait a long time before they finishes

One example of such test:

@Test
public void asyncMethodListener() throws Exception {
	// Arrange
	originalThreadName = Thread.currentThread().getName();
	listenerCalled = 0;
	GenericApplicationContext context = new GenericApplicationContext();
	context.registerBeanDefinition("asyncTest",
								new RootBeanDefinition(AsyncMethodListener.class));
	context.registerBeanDefinition("autoProxyCreator",
								new RootBeanDefinition(DefaultAdvisorAutoProxyCreator.class));
	context.registerBeanDefinition("asyncAdvisor",
								new RootBeanDefinition(AsyncAnnotationAdvisor.class));
	// Act
	context.refresh();
	Thread.sleep(1000);
	assertEquals(1, listenerCalled);
}

There is a more efficient way to test asynchronous behavior - for example using the Awaitility library.

I found all the tests that could be refactored and started rewriting them.

When I replaced all the use of the Thread.sleep on the Awaitility.await and ran them, I was unpleasantly surprised, tests that were successful before began to fall, but not always.

Thus, the behavior became even more fragile.

2. Research

Most often the problem was reproduced in children tests of the AbstractSchedulingTaskExecutorTests

Test before using of the Awaitility:

@Test
public void submitFailingListenableRunnable() throws Exception {
	TestTask task = new TestTask(0);
	ListenableFuture<?> future = executor.submitListenable(task);
	future.addCallback(result -> outcome = result, ex -> outcome = ex);
	Thread.sleep(1000);
	assertTrue(future.isDone());
	assertSame(RuntimeException.class, outcome.getClass());
}

you can see full version here: AbstractSchedulingTaskExecutorTests.java

And the source code of this test with the Awaitility:

@Test
public void submitFailingListenableRunnable() throws Exception {
    TestTask task = new TestTask(0);
    ListenableFuture<?> future = executor.submitListenable(task);
    future.addCallback(result -> outcome = result, ex -> outcome = ex);

    Awaitility.await()
              .atMost(1, TimeUnit.SECONDS)
              .pollInterval(10, TimeUnit.MILLISECONDS)
              .until(() -> future.isDone() && outcome != null);

    assertSame(RuntimeException.class, outcome.getClass());
}

In this code executor is a ThreadPoolTaskExecutor instance with settings depends on the child test. Let’s look at the next implementation (DecoratedThreadPoolTaskExecutorTests)

@Override
protected AsyncListenableTaskExecutor buildExecutor() {
	ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
	executor.setTaskDecorator(runnable ->  (1)
			new DelegatingErrorHandlingRunnable(runnable, TaskUtils.LOG_AND_PROPAGATE_ERROR_HANDLER));
	executor.setThreadNamePrefix(THREAD_NAME_PREFIX);
	executor.setMaxPoolSize(1);
	executor.afterPropertiesSet();
	return executor;
}

1	execution of tasks will be decorated by handler and also if this task throws exception, then will propagate this exception to the next level.

3. Let’s compare results of this tests

The result of test with Thread.Sleep: thread_sleep_result

The result of test with the Awaitility: awaitility wrog test

I think this is unexpected behavior, the use of awaitility for tests breaks their result. However, when I run only failed test without inherited test suite, it may successful pass or not.

It’s also interesting that sometimes tests pass. I thought it depends on something what happened before this test, but really the reason of fail hide in a parallel thread for our test.

Let’s look on the test case in more detail:

@Test
public void submitFailingListenableRunnable() throws Exception {
	TestTask task = new TestTask(0); (1)
	ListenableFuture<?> future = executor.submitListenable(task); (2)
	future.addCallback(result -> outcome = result, ex -> outcome = ex);  (3)

	Thread.sleep(1000); (4)

	assertTrue(future.isDone());
	assertSame(RuntimeException.class, outcome.getClass());
}

1	creation of the new TestTask, with the failed setting (submit of this task will create a thread which will throw an error after a small delay)
2	submit of this task in the ThreadPoolTaskExecutor
3	add a handler for the result of execution of the task
4	the main thread of our test will sleep for a second

4. Isolate test problem

I don’t like working with unstable tests then I decided to isolate a problem and write a stable failed test.

@Test
public void catchUncaught() throws InterruptedException {

    ThreadPoolTaskExecutor taskExecutor = setUpExecutor();
    taskExecutor.execute(new ErrorTestTask());
    ListenableFuture<?> future = taskExecutor.submitListenable(new ErrorTestTask());
    Awaitility.await()
              .atMost(1, TimeUnit.SECONDS)
              .pollInterval(10, TimeUnit.MILLISECONDS)
              .until(future::isDone);
}

private ThreadPoolTaskExecutor setUpExecutor() {
    ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
    executor.setThreadNamePrefix(THREAD_NAME_PREFIX);
    executor.setMaxPoolSize(1);
    executor.afterPropertiesSet();
    return executor;
}

private static class ErrorTestTask implements Runnable {
    @Override
    public void run() {
        try {
            Thread.sleep(100);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        throw new RuntimeException(Thread.currentThread().getName() + " -> Error");
    }
}

ErrorTestTask sleeps 100 ms. and throws the RuntimeException. If you run this test, awaitility will catch all exceptions even if they are thrown in another thread and then test will be failed.

wrong test result

If you read a documentation of Awaitility, you can find a note about exception handling and the advice how to avoid this. But who reads the documentation?!

The right way to write our test case:

@Test
public void testSubmit() throws InterruptedException {

		ThreadPoolTaskExecutor taskExecutor = setUpExecutor();
		taskExecutor.execute(new ErrorTestTask());
		ListenableFuture<?> future = taskExecutor.submitListenable(new ErrorTestTask());

		Awaitility.await()
				  .dontCatchUncaughtExceptions() (1)
				  .atMost(1, TimeUnit.SECONDS)
				  .pollInterval(10, TimeUnit.MILLISECONDS)
				  .until(future::isDone);
}

1	awaitility must be ignored exceptions from other threads

5. Conclusion:

You need to understand the mechanics of the tools that you use for testing, especially if these are cases like asynchronous events and multithreading.

When I replaced all Thread.sleep(1000), asynchronous tests began to pass two-thirds faster, and I reduced the time of passage of all the tests in the Spring Framework about by twenty seconds.

After this small research I submitted a pull request in the SpringFramework (Spr-17211 - Async tests refactoring) and suggested to improve the documentation in Awaitility library (dontCatchUncaughtExceptions #119).

All of these are successfully done(thanks to Sam Brannen and Johan Haleby), and now I can published this article.