BlockingCache.get sometimes returns null without holding lock

Type: Bug
Status: Resolved
Priority: 2 Major
Resolution: As Designed
Component/s: ehcache-core
Labels:

Assignee: alexsnaps
Reporter: petur
Created: April 12, 2012
Votes: 1
Watchers: 3
Updated:
March 01, 2013
Resolved:
November 14, 2012

Description

There appears to be a bug in BlockingCache.get in this block:

    if (element == null) {
        acquiredLockForKey(key, lock, LockType.WRITE);
        element = underlyingCache.getQuiet(key);
        if (element != null) {
            if (underlyingCache.isStatisticsEnabled()) {
                element = underlyingCache.get(key);
            }
            lock.unlock(LockType.WRITE);
        }
    }

It is possible for the element to expire, be evicted or removed by another thread between the calls to underlyingCache.getQuiet and underlyingCache.get. In that case, element will be null, but the lock is unlocked anyway.

This could be fixed by adding an extra if (element != null) before calling lock.unlock, or by not assigning the result of underlyingCache.get to element.

Here is a test that demonstrates the problem:

public class BlockingCacheTest extends BlockingCache { public BlockingCacheTest(Ehcache cache) throws CacheException { super(cache); }

public static void main(String[] args) throws Exception {
    Configuration config = ConfigurationFactory.parseConfiguration();
    config.getDefaultCacheConfiguration().setStatistics(true);
    CacheManager cm = CacheManager.create(config);
    cm.addCache("test");
    final Cache cache = cm.getCache("test");
    System.out.println("statistics=" + cache.isStatisticsEnabled());
    final BlockingCacheTest bc = new BlockingCacheTest(cache);

    Thread[] threads = new Thread[10];
    for (int j = 0; j < threads.length; j++) {
        Thread t = new Thread() {
            public void run() {
                Object key = "key";
                for (int i = 0; i < 1000000; i++) {

                    Element element = bc.get(key);
                    if (element == null) {
                        if (!bc.getLockForKey(key).isHeldByCurrentThread(LockType.WRITE)) {
                            System.err.println("FAIL: i=" + i);
                            System.exit(1);
                        }
                        bc.put(new Element(key, i));
                    }
                    if (i % 7 == 3)
                        cache.removeAll();
                }
            }
        };
        t.start();
        threads[j] = t;
    }

    for (Thread t : threads)
        t.join();
    System.out.println("SUCCESS");
    System.exit(0);
} \}

Comments

Fiona OShea 2012-04-12

I’m not sure if this relates to EHC-715. Alex can you confirm?

Martin JANDA 2012-06-06

I see that lock.unlock(WRITE) is not called in all paths when element = null. I have deadlock in FJ pool. I don’t see any unlock in EhCache 2.5.2 sources.

“ForkJoinPool-1-worker-4” - Thread t@34 java.lang.Thread.State: WAITING at sun.misc.Unsafe.park(Native Method) - parking to wait for <65786232> (a java.util.concurrent.ForkJoinPool) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.ForkJoinPool.tryAwaitWork(ForkJoinPool.java:864) at java.util.concurrent.ForkJoinPool.work(ForkJoinPool.java:647) at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:398)

Locked ownable synchronizers: - locked <674eceb2> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)

“ForkJoinPool-1-worker-1” - Thread t@17 java.lang.Thread.State: WAITING at sun.misc.Unsafe.park(Native Method) - waiting to lock <674eceb2> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) owned by “ForkJoinPool-1-worker-4” t@34 at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197) at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:945) at net.sf.ehcache.concurrent.ReadWriteLockSync.lock(ReadWriteLockSync.java:50) at net.sf.ehcache.constructs.blocking.BlockingCache.acquiredLockForKey(BlockingCache.java:186) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:159) at net.sf.ehcache.constructs.blocking.SelfPopulatingCache.get(SelfPopulatingCache.java:68) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:243)

“ForkJoinPool-1-worker-2” - Thread t@23 java.lang.Thread.State: WAITING at sun.misc.Unsafe.park(Native Method) - waiting to lock <674eceb2> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) owned by “ForkJoinPool-1-worker-4” t@34 at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197) at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:945) at net.sf.ehcache.concurrent.ReadWriteLockSync.lock(ReadWriteLockSync.java:50) at net.sf.ehcache.constructs.blocking.BlockingCache.acquiredLockForKey(BlockingCache.java:186) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:159) at net.sf.ehcache.constructs.blocking.SelfPopulatingCache.get(SelfPopulatingCache.java:68) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:243)

“ForkJoinPool-1-worker-3” - Thread t@33 java.lang.Thread.State: WAITING at sun.misc.Unsafe.park(Native Method) - waiting to lock <674eceb2> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) owned by “ForkJoinPool-1-worker-4” t@34 at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:964) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282) at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:731) at net.sf.ehcache.concurrent.ReadWriteLockSync.lock(ReadWriteLockSync.java:50) at net.sf.ehcache.constructs.blocking.BlockingCache.acquiredLockForKey(BlockingCache.java:186) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:151) at net.sf.ehcache.constructs.blocking.SelfPopulatingCache.get(SelfPopulatingCache.java:68) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:243)

Alexander Snaps 2012-06-06

Martin, that’s the purpose of BlockingCache, the unlocking of the key only happens when you put a value for the key that returned null…

Martin JANDA 2012-06-07

Threaddump comment is another bug - EHC-947 - Write lock leak

Fiona OShea 2012-11-14

Closing as we do not see a bug here. Please open a new Jira if there is still an existing problem.