Concurrent access to a TreeSet doesn't seem to work

Viewed 266

I'm creating a Java class IdGenerator that allocates a unique integer ID each time one is requested. It uses a TreeSet to store ranges of free IDs, and each time an ID is requested it looks in the set to find a range, allocates the first ID in the range, deletes the range, and adds a new range that is one smaller. The whole allocation process is synchronized on the set to ensure that different threads don't collide.

This worked fine when I was unit testing the class, but I have just run a test of a different class where an instance of the IdGenerator class is called ten times in quick succession, by different threads, and it returns the same value every time. Logging reveals that on each invocation, the set holding the free ranges has the same contents, although the lastId variable is different: -1 on the first invocation, 0 on the others. This seems to suggest that the different threads are using different copies of the set, although that's not what I would expect from the code.

I'm running using JRE 1.8.0_191, within Eclipse Neon 4.6.3 on Windows 10.

I've tried synchronizing on the generator object rather than the set, wrapping the TreeSet in a synchronizedSortedSet, and using a Lock object instead of the synchronized keyword. None of it made any difference.

private final SortedSet<Range> freeRanges = new TreeSet<>();
private int lastId;


public int allocateId() throws IllegalStateException
{
    int answer;
    synchronized (freeRanges)
    {
        LOG.debug("lastId = {}, freeRanges = {}", lastId, freeRanges);
        if (freeRanges.isEmpty())
            throw new IllegalStateException("All possible IDs are allocated");
        Range range = Stream
                .of(freeRanges.tailSet(new Range(lastId + 1)), freeRanges)
                .filter(s -> !s.isEmpty())
                .map(SortedSet::first)
                .findFirst()
                .get();
        answer = lastId = range.start;
        freeRanges.remove(range);
        if (range.start != range.end)
            freeRanges.add(new Range(range.start + 1, range.end));
        LOG.debug("Allocated {}, freeRanges = {}", answer, freeRanges);
    }
    return answer;
}

The log output is as shown below. I expect that on the nth invocation, the number allocated is n-1 and the set of free ranges is updated to show a range starting at n and ending at 100. But instead, what I see is this:

16:03:18.554 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = -1, freeRanges = [Range [start=0, end=100]]
16:03:18.570 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = 0, freeRanges = [Range [start=0, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = 0, freeRanges = [Range [start=0, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = 0, freeRanges = [Range [start=0, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = 0, freeRanges = [Range [start=0, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = 0, freeRanges = [Range [start=0, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = 0, freeRanges = [Range [start=0, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = 0, freeRanges = [Range [start=0, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = 0, freeRanges = [Range [start=0, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - lastId = 0, freeRanges = [Range [start=0, end=100]]
16:03:18.586 [main] DEBUG uk.org.thehickses.idgenerator.IdGenerator - Allocated 0, freeRanges = [Range [start=1, end=100]]
1 Answers

Thank you to everyone who responded. I'm afraid that I may have misled you - I realised, while cycling home last night, that the problem is nothing to do with multiple calls to the allocateId method from different threads. The log I posted clearly shows that all those calls are made in the same thread (it is called "main").

And while cycling to work this morning, I realised what the problem was - it is that other threads are calling the freeId method which returns IDs to the freeRanges set. And in particular, the ID allocated by each call to allocateId is being freed before the next call to allocateId. That explains why freeRanges has the same contents each time allocateId is called.

I've made a simple change to ensure that when this happens, if the range that is found contains lastId + 1 then that is the value allocated, even if it is not at the start of the range. And of course, if it isn't at the start of that range, the range is replaced in freeRanges with up to two new ranges - one containing all the numbers in the range that are less than the allocated number, and one containing all those that are more than it. This ensures that we cycle through all the available numbers as far as possible, and only if there are no free numbers that are greater than the last one allocated do we go back to the beginning.

Amended code is below. Clearly I should spend more time on my bike, and less in front of my computer!

public int allocateId() throws IllegalStateException
{
    int answer;
    synchronized (freeRanges)
    {
        LOG.debug("Allocating: lastId = {}, freeRanges = {}", lastId, freeRanges);
        if (freeRanges.isEmpty())
            throw new IllegalStateException("All possible IDs are allocated");
        int nextId = lastId + 1;
        Range range = Stream
                .of(freeRanges.tailSet(new Range(nextId)), freeRanges)
                .filter(s -> !s.isEmpty())
                .map(SortedSet::first)
                .findFirst()
                .get();
        answer = lastId = range.contains(nextId) ? nextId : range.start;
        freeRanges.remove(range);
        range.splitAround(answer).forEach(freeRanges::add);
        LOG.debug("Allocated {}, freeRanges = {}", answer, freeRanges);
    }
    return answer;
}
Related