Integration Test - AKKA Actor With Awaitility

Abstract : Ever had an impression you're changing what you're observing by simply observing it? If you so, you may have hit a Heisenbug ([1], [2]). Well, OK, I agree that a more precise definition of "observing" is needed and that we can differentiate between active and passive observing. The thing is one can hardly be a fully passive observer, especially when it comes to testing multi-threaded programs. Assuming you're really working on the program and not simply looking a video tutorial in which case you will be a fully passive observer (and I would be wondering how the heck you've tumbled on my article). In short, when working on (including testing) a program we may introduce Heisenbugs through levels of indirection which are usually hard to spot. In C/C++ such a level of indirection represents uninitialized auto variables which can change every time you run you program. In Java a source of many indirection levels is the platform independence provided by the JVM. In JavaScript a source of Heisenbugs can be processing uncontrolled (browser dependent) events such as the scroll event.

Goal : Chase and fix a Heisenbug within an AKKA actor integration test using Awaitility

Acknowledgement: My gratitude goes to the open source community

An AKKA actor based program : I've already given an example of an AKKA actor base program here and you can find the source code here. So to save you and me some time, I'm going to re-use it.

Naïve test case : First we are going to build a test case which is prone to Heisenbugs and then we are going to fix it. I'm going to use JUnit, Spring Test Framework, Mockito, FEST-Assert, and FEST-Reflect to build up the following integration test case (access article's full source code):

import akka.actor.ActorRef;
import org.honeysoft.akka.Bootstrap;
import org.honeysoft.akka.service.IBusinessService;
import org.junit.Before;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.Mock;
import org.mockito.MockitoAnnotations;
import org.slf4j.Logger;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.beans.factory.annotation.Qualifier;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;

import static org.fest.reflect.core.Reflection.field;
import static org.mockito.Matchers.anyString;
import static org.mockito.Matchers.eq;
import static org.mockito.Mockito.times;
import static org.mockito.Mockito.verify;

@ContextConfiguration(classes = {Bootstrap.class})
@RunWith(SpringJUnit4ClassRunner.class)
public class BusinessActorTest {

    @Autowired
    @Qualifier(Bootstrap.BUSINESS_ACTOR)
    private ActorRef businessActorRef;

    @Autowired
    private IBusinessService businessService;

    @Mock
    private Logger mockBusinessServiceLogger;

    @Before
    public void beforeEach() {
        MockitoAnnotations.initMocks(this);
    }

    @Test
    public void shouldBeValidWhenNoOneIsNull() {
        //GIVEN
        field("logger").ofType(Logger.class).in(businessService).postDecorateWith(mockBusinessServiceLogger);

        //WHEN
        String testString = "test-string";
        businessActorRef.tell(testString);

        //THEN
        verify(mockBusinessServiceLogger, times(1)).info(anyString(), eq(testString));
    }
}

The thing is that this test case is prone to Heisenbugs. More precisely, the verification (at line 50) may pass some times and may fail others. Depending on the speed of execution and thread priority it can happen that the verification comes before the businessService receives the testString for processing. Luckily we have Awaitility at our disposal so the fix is straightforward:

import akka.actor.ActorRef;
import com.jayway.awaitility.Awaitility;
import com.jayway.awaitility.Duration;
import org.fest.assertions.Assertions;
import org.honeysoft.akka.Bootstrap;
import org.honeysoft.akka.service.IBusinessService;
import org.junit.Before;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.MockitoAnnotations;
import org.slf4j.Logger;
import org.slf4j.Marker;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.beans.factory.annotation.Qualifier;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;

import java.util.concurrent.Callable;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentMap;

import static org.fest.reflect.core.Reflection.field;

@ContextConfiguration(classes = {Bootstrap.class})
@RunWith(SpringJUnit4ClassRunner.class)
public class BusinessActorTest {

    @Autowired
    @Qualifier(Bootstrap.BUSINESS_ACTOR)
    private ActorRef businessActorRef;

    @Autowired
    private IBusinessService businessService;

    @Before
    public void beforeEach() {
        MockitoAnnotations.initMocks(this);
    }

    @Test
    public void shouldBeValidWhenNoOneIsNull() throws Exception {
        //GIVEN
        final ConcurrentMap<String, Object> threadSafeMap = new ConcurrentHashMap<String, Object>(1);
        field("logger").ofType(Logger.class).in(businessService).postDecorateWith(new TestLogger(threadSafeMap));

        //WHEN
        String testString = "test-string";
        businessActorRef.tell(testString);

        //THEN
        Awaitility.waitAtMost(Duration.FIVE_SECONDS).until(new Callable<Boolean>() {
            @Override
            public Boolean call() throws Exception {
                return !threadSafeMap.isEmpty();
            }
        });

        Assertions.assertThat(threadSafeMap).hasSize(1);
        Assertions.assertThat(threadSafeMap.values().iterator().next()).isEqualTo(testString);
    }

    private static final class TestLogger implements Logger {

        private final ConcurrentMap<String, Object> map;

        private TestLogger(ConcurrentMap<String, Object> map) {
            this.map = map;
        }

        @Override
        public void info(String format, Object arg) {
            map.put(format, arg);
        }

        //Other overridden methods go here
    }
}

So what happened is that instead of mocking our logger target we've created a thread-safe TestLogger to help us. Then we've added an awaitility block to either wait for at most 5 secs or until our piggy-bag map is not empty. Well, that was all. Not too painful right?