why java concurrency test fails?

Question

I have a simple class:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class DummyService {
    private final Logger logger = LoggerFactory.getLogger(getClass());
    private boolean dataIndexing = false;

    public boolean isDataIndexing() {
        logger.info("isDataIndexing: {}", dataIndexing);
        return dataIndexing;
    }

    public void cancelIndexing() {
        logger.info("cancelIndexing: {}", dataIndexing);
        dataIndexing = false;
    }

    public void createIndexCorp() {
        logger.info("createIndexCorp: {}", dataIndexing);
        createIndex();
    }

    public void createIndexEntr() {
        logger.info("createIndexEntr: {}", dataIndexing);
        createIndex();
    }

    private void createIndex() {
        logger.info("createIndex: {}", dataIndexing);
        if(dataIndexing)
            throw new IllegalStateException("Service is busy!");
        dataIndexing = true;
        try {
            while(dataIndexing) {
                Thread.sleep(100);
                logger.debug("I am busy...");
            }
            logger.info("Indexing canceled");
        } catch (InterruptedException e) {
            logger.error("Error during sleeping", e);
        } finally {
            dataIndexing = false;
        }
    }
}

and a unit test, with which i want to test object behavior:

public class CommonUnitTest
{
    @Test
    public void testCreateIndexWithoutAsync() throws InterruptedException {
        final long sleepMillis = 500;
        final DummyService indexService = new DummyService();
        assertFalse(indexService.isDataIndexing());
        new Thread(() -> {
                    indexService.createIndexCorp();
                }
        ).start();
        Thread.sleep(sleepMillis);
        assertTrue(indexService.isDataIndexing());
        // TaskExecutor should fails here
        new Thread(() -> {
                    indexService.createIndexEntr();
                    logger.error("Exception expected but not occurred");
                }
        ).start();
        assertTrue(indexService.isDataIndexing());
        indexService.cancelIndexing();
        Thread.sleep(sleepMillis);
        assertFalse(indexService.isDataIndexing());
    }
}

The behaviour of object must be: If the method createIndexCorp or createIndexEntr is called by one thread, then another thread must get exception by trying to call one of this methods. But this does not happens! Here is the log:

2015-10-15 17:15:06.277  INFO   --- [           main] c.c.o.test.DummyService                  : isDataIndexing: false
2015-10-15 17:15:06.318  INFO   --- [       Thread-0] c.c.o.test.DummyService                  : createIndexCorp: false
2015-10-15 17:15:06.319  INFO   --- [       Thread-0] c.c.o.test.DummyService                  : createIndex: false
2015-10-15 17:15:06.419 DEBUG   --- [       Thread-0] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:06.524 DEBUG   --- [       Thread-0] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:06.624 DEBUG   --- [       Thread-0] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:06.724 DEBUG   --- [       Thread-0] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:06.818  INFO   --- [           main] c.c.o.test.DummyService                  : isDataIndexing: true
2015-10-15 17:15:06.820  INFO   --- [           main] c.c.o.test.DummyService                  : isDataIndexing: true
2015-10-15 17:15:06.820  INFO   --- [       Thread-1] c.c.o.test.DummyService                  : createIndexEntr: true
2015-10-15 17:15:06.820  INFO   --- [           main] c.c.o.test.DummyService                  : cancelIndexing: true
2015-10-15 17:15:06.820  INFO   --- [       Thread-1] c.c.o.test.DummyService                  : createIndex: true
2015-10-15 17:15:06.824 DEBUG   --- [       Thread-0] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:06.921 DEBUG   --- [       Thread-1] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:06.924 DEBUG   --- [       Thread-0] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:07.021 DEBUG   --- [       Thread-1] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:07.024 DEBUG   --- [       Thread-0] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:07.121 DEBUG   --- [       Thread-1] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:07.124 DEBUG   --- [       Thread-0] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:07.221 DEBUG   --- [       Thread-1] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:07.224 DEBUG   --- [       Thread-0] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:07.321 DEBUG   --- [       Thread-1] c.c.o.test.DummyService                  : I am busy...
2015-10-15 17:15:07.321  INFO   --- [           main] c.c.o.test.DummyService                  : isDataIndexing: true

You can see that second thread can start process, but it should get the exception. Also the last assertion in the test code fails. How can that happen ? I dont understand this behavior. I tried to use volatile and synchronized keyword, but nothing helps. What is wrong with DummyService ?

Answer 1

Not an answer to your question, but this is completely unsynchronized:

if (dataIndexing)
    throw new IllegalStateException("Service is busy!");
dataIndexing = true;

Is the service busy if your execution reaches the throw statement? Not necessarily! Another thread could have changed the value of dataIndexing from true to false in between the test and the throw.

What's worse, maybe much worse, is that two threads might both reach the statement after the throw at the same time:

Thread A                           Thread B

tests dataIndexing, finds it to
be false.

                                   Tests dataIndexing, finds it to be false.

sets dataIndexing = true;           sets dataIndexing = true;
...                                ...

---

Also, this is unreliable, and it takes time.

Thread.sleep(sleepMillis);
assertTrue(indexService.isDataIndexing());

Better to design your classes for testability. If your test needs to wait until isDataIndexing(), then your class should provide a means for the test to wait()...

Also, don't underestimate the importance of making tests that complete in the least amount of time possible. When you have a system that has thousands or tens of thousands of test cases, the seconds really start to add up.

Answer 2

It seems you're hitting the difference between logging and the actual execution. The threads can conceivably run cancel and create index in the space between logging and and the exception, thus the second thread slipping by and preventing cancelling of the first and the second.

It is not advisable to allow simultaneous changes to shared resource, namely private boolean dataIndexing. There are two solutions (at least):

1.A syncronized method to allow for change of the shared resource (thus limiting access to only one thread at a time)

private synchronized void setDataIndexing(boolean value) {
    dataIndexing = value;
}

2.Guarding each change of this value in a syncronized section (in both the = true and the = false places):

syncronized (this) {
    dataIndexing = /* the relevant value */;
}

I would advise a separate method, but good to know the alternatives.

Answer 3

You have 3 threads, t0, t1 and tm (main). The order of operations is like this:

tm starts t0
t0 checks dataIndexing flag - false, goes into the loop, sets flag to true
tm sleeps
tm starts t1
tm sets indexing flag to false
t1 checks dataIndexing flag - false, goes into the loop, sets flag to true
t0 continues the loop because it missed that brief period when indexing was cancelled

If you sleep in the main tm before setting indexing flag to false, then t1 will get the exception. You need to synchronize access to variables shared between multiple threads. I.e. checking the state of the flag and changing it needs to be done while holding a mutex.