Ehcache Deadlock in ehcache 2.9.0

328 views
Skip to first unread message

Nivedita Dixit

unread,
May 22, 2017, 7:36:29 AM5/22/17
to ehcache-users
  1. What version of Ehcache you are currently using; 2.9.0
  2. Paste the configuration for the Cache/CacheManager you have an issue with;
  3. <ehcache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
             xsi:noNamespaceSchemaLocation="../config/ehcache.xsd" updateCheck="false" monitoring="autodetect"
             dynamicConfig="true">
        <diskStore path="java.io.tmpdir/data_cache"/>
        <defaultCache
                maxElementsInMemory="100000"
                eternal="false"
                timeToIdleSeconds="360"
                timeToLiveSeconds="360"
                overflowToDisk="true"
                diskPersistent="false"
                maxElementsOnDisk="10"
                diskExpiryThreadIntervalSeconds="360"
                memoryStoreEvictionPolicy="FIFO"
                />

        <cache name="PDCache"
               maxElementsInMemory="50000"
               eternal="false"
               overflowToDisk="true"
               timeToLiveSeconds="150"
               diskPersistent="false"
               maxElementsOnDisk="80000"
               memoryStoreEvictionPolicy="LRU"/>
              
    </ehcache>
  4. Add any name and version of other library or framework you use Ehcache with (e.g. Hibernate);
  5. Providing JDK and OS versions maybe useful as well.  jdk1.8 , ubuntu

We are having app using ehcache 2.9.0. Lately we have observed deadlocks related to ehcache get/put operations weekly once, and once we clear the cache the issue goes away.

we observe the lock on the RandomAccessFile during cache get operation and ReentrantReadWriteLock during put operation.

Request insight from ehcache experts on what could be possible issue ?

PFB the threads from the thread dumps

"HTTP938" #25950 daemon prio=5 os_prio=0 tid=0x0000000002614000 nid=0x5a64 waiting on condition [0x00007fcd36965000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000005cbbc6768> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:967) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1283) at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:727) at net.sf.ehcache.store.disk.Segment.flush(Segment.java:1010) at net.sf.ehcache.store.disk.DiskStore.flush(DiskStore.java:248) at net.sf.ehcache.store.CacheStore$1.evicted(CacheStore.java:99) at net.sf.ehcache.store.CacheStore$1.evicted(CacheStore.java:96) at net.sf.ehcache.store.cachingtier.OnHeapCachingTier$1.evicted(OnHeapCachingTier.java:86) at net.sf.ehcache.store.cachingtier.CountBasedBackEnd$1.removed(CountBasedBackEnd.java:103) at net.sf.ehcache.util.concurrent.ConcurrentHashMap.internalReplace(ConcurrentHashMap.java:1346) at net.sf.ehcache.util.concurrent.ConcurrentHashMap.removeAndNotify(ConcurrentHashMap.java:2647) at net.sf.ehcache.store.cachingtier.CountBasedBackEnd.remove(CountBasedBackEnd.java:115) at net.sf.ehcache.store.cachingtier.OnHeapCachingTier.remove(OnHeapCachingTier.java:206) at net.sf.ehcache.store.CacheStore.put(CacheStore.java:134) at net.sf.ehcache.Cache.putInternal(Cache.java:1600) at net.sf.ehcache.Cache.put(Cache.java:1526) at net.sf.ehcache.Cache.put(Cache.java:1491) at org.springframework.cache.ehcache.EhCacheCache.put(EhCacheCache.java:82) at org.springframework.cache.interceptor.AbstractCacheInvoker.doPut(AbstractCacheInvoker.java:82) at org.springframework.cache.interceptor.CacheAspectSupport$CachePutRequest.apply(CacheAspectSupport.java:651) at org.springframework.cache.interceptor.CacheAspectSupport.execute(CacheAspectSupport.java:358) at org.springframework.cache.interceptor.CacheAspectSupport.execute(CacheAspectSupport.java:299) at org.springframework.cache.interceptor.CacheInterceptor.invoke(CacheInterceptor.java:61) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653)

"HTTP927" #25855 daemon prio=5 os_prio=0 tid=0x00007fce685c9000 nid=0x4fb6 waiting for monitor entry [0x00007fcd359e8000] java.lang.Thread.State: BLOCKED (on object monitor) at net.sf.ehcache.store.disk.DiskStorageFactory.read(DiskStorageFactory.java:362) - waiting to lock <0x00000005cbdfb538> (a java.io.RandomAccessFile) at net.sf.ehcache.store.disk.DiskStorageFactory.retrieve(DiskStorageFactory.java:864) at net.sf.ehcache.store.disk.Segment.decode(Segment.java:171) at net.sf.ehcache.store.disk.Segment.remove(Segment.java:644) at net.sf.ehcache.store.disk.DiskStore.remove(DiskStore.java:625) at net.sf.ehcache.store.CacheStore.remove(CacheStore.java:236) at net.sf.ehcache.Cache.removeInternal(Cache.java:2401) at net.sf.ehcache.Cache.tryRemoveImmediately(Cache.java:2162) at net.sf.ehcache.Cache.get(Cache.java:1739) at org.springframework.cache.ehcache.EhCacheCache.get(EhCacheCache.java:65) at org.springframework.cache.interceptor.AbstractCacheInvoker.doGet(AbstractCacheInvoker.java:68) at org.springframework.cache.interceptor.CacheAspectSupport.findInCaches(CacheAspectSupport.java:461) at org.springframework.cache.interceptor.CacheAspectSupport.findCachedItem(CacheAspectSupport.java:432) at org.springframework.cache.interceptor.CacheAspectSupport.execute(CacheAspectSupport.java:333) at org.springframework.cache.interceptor.CacheAspectSupport.execute(CacheAspectSupport.java:299) at org.springframework.cache.interceptor.CacheInterceptor.invoke(CacheInterceptor.java:61) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653)

Thanks, Nivedita

Henri Tremblay

unread,
May 22, 2017, 10:49:09 AM5/22/17
to ehcach...@googlegroups.com
Hi,

As mentioned on Stackoverflow, I suggest that you first upgrade your ehcache version. It might be a fixed bug or a new optimisation. I've answered your comment. The question is: Who is locking 0x00000005cbdfb538?



--
You received this message because you are subscribed to the Google Groups "ehcache-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ehcache-users+unsubscribe@googlegroups.com.
To post to this group, send email to ehcach...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/ehcache-users/f837efe3-be17-4c0b-9d5a-d91bcaa2cac0%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Nivedita Dixit

unread,
May 24, 2017, 5:59:42 AM5/24/17
to ehcache-users
Hi Henri,

we cannot upgrade immediately as it is in production and unless proper regression test is completed, we will not be able to do it.
I find the 0x00000005cbdfb538 is locked by Cache Put operation 

Thread Name HTTP762
State Runnable
Monitor Owns Monitor Lock on 0x00000005cbdfb538
Java Stack at java.io.RandomAccessFile.readBytes(Native Method)
at java.io.RandomAccessFile.read(RandomAccessFile.java:377)
at java.io.RandomAccessFile.readFully(RandomAccessFile.java:436)
at java.io.RandomAccessFile.readFully(RandomAccessFile.java:416)
at net.sf.ehcache.store.disk.DiskStorageFactory.read(DiskStorageFactory.java:365)
- locked [0x00000005cbdfb538] (a java.io.RandomAccessFile)
at net.sf.ehcache.store.disk.DiskStorageFactory.retrieve(DiskStorageFactory.java:864)
at net.sf.ehcache.store.disk.Segment.decode(Segment.java:171)
at net.sf.ehcache.store.disk.Segment.evict(Segment.java:858)
at net.sf.ehcache.store.disk.Segment.evict(Segment.java:830)
at net.sf.ehcache.store.disk.Segment.flush(Segment.java:1034)
at net.sf.ehcache.store.disk.DiskStore.flush(DiskStore.java:248)
at net.sf.ehcache.store.CacheStore$1.evicted(CacheStore.java:99)
at net.sf.ehcache.store.CacheStore$1.evicted(CacheStore.java:96)
at net.sf.ehcache.store.cachingtier.OnHeapCachingTier$1.evicted(OnHeapCachingTier.java:86)
at net.sf.ehcache.store.cachingtier.CountBasedBackEnd$1.removed(CountBasedBackEnd.java:103)
at net.sf.ehcache.util.concurrent.ConcurrentHashMap.internalReplace(ConcurrentHashMap.java:1346)
at net.sf.ehcache.util.concurrent.ConcurrentHashMap.removeAndNotify(ConcurrentHashMap.java:2647)
at net.sf.ehcache.store.cachingtier.CountBasedBackEnd.remove(CountBasedBackEnd.java:115)
at net.sf.ehcache.store.cachingtier.OnHeapCachingTier.remove(OnHeapCachingTier.java:206)
at net.sf.ehcache.store.CacheStore.put(CacheStore.java:134)
at net.sf.ehcache.Cache.putInternal(Cache.java:1600)
at net.sf.ehcache.Cache.put(Cache.java:1526)
at net.sf.ehcache.Cache.put(Cache.java:1491)
at org.springframework.cache.ehcache.EhCacheCache.put(EhCacheCache.java:82)
at org.springframework.cache.interceptor.AbstractCacheInvoker.doPut(AbstractCacheInvoker.java:82)
at org.springframework.cache.interceptor.CacheAspectSupport$CachePutRequest.apply(CacheAspectSupport.java:651)
at org.springframework.cache.interceptor.CacheAspectSupport.execute(CacheAspectSupport.java:358)
at org.springframework.cache.interceptor.CacheAspectSupport.execute(CacheAspectSupport.java:299)
at org.springframework.cache.interceptor.CacheInterceptor.invoke(CacheInterceptor.java:61)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653)


Thanks,
Nivedita
To unsubscribe from this group and stop receiving emails from it, send an email to ehcache-user...@googlegroups.com.

Henri Tremblay

unread,
May 24, 2017, 1:13:27 PM5/24/17
to ehcach...@googlegroups.com
It really looks like a disk slowness. Possibly due to do concurrent access. Ideally, caching shouldn't hit the disk too frequently. Most access should be on or off heap. 

Is it possible that at some point, the cache is full and eviction starts to heavily kick in?

To unsubscribe from this group and stop receiving emails from it, send an email to ehcache-users+unsubscribe@googlegroups.com.

To post to this group, send email to ehcach...@googlegroups.com.

Manish Narula

unread,
Sep 27, 2019, 5:55:37 AM9/27/19
to ehcache-users
Hi Nivedita
was this resolved?

Regards
Manish
To unsubscribe from this group and stop receiving emails from it, send an email to ehcach...@googlegroups.com.

To post to this group, send email to ehcach...@googlegroups.com.

Daksh Verma

unread,
Jun 28, 2020, 7:19:02 AM6/28/20
to ehcache-users
Hi,

Anybody got around this thread BLOCKED issue.

Reply all
Reply to author
Forward
0 new messages