Hello,
We are implementing Terracotta Server Array 3.7.4 for distributed caching. I've found an odd problem with our NonStop cache configuration.
When setting a timeoutMillis of 3 seconds, we are getting an IllegalMonitorStateException. This seems to be happening on read operations which should be a non-blocking (not locking).
I'm seeing this exception on read operations within hibernate. You can see that in the CriteriaImpl.list part of the stack trace. Although, I'm puzzled with the reference to the EhcacheTransactionalDataRegion class in the stack trace. All of our hibernate caches are setup with a read/write strategy.
We had decided to set a timeout of 3 seconds for the cache to ensure the site doesn't get slow if there are network issues. I'd rather have cache return a null so that hibernate can pull the data from the database.
Here's the odd part. If I set the timeoutMillis to 30 seconds (the default), this error goes away. However, in that case I can see some intermittent slower requests. The statistics in developer console also report higher max get times also.
The IllegalMonitorStateException relates back to a thread wait() or notify() operation on a thread which you don't own the lock for. That seems very odd for a non-blocking read operation in a cache setup with an eventual consistency.
Any ideas? Why does lowering the NonStop cache timeout causing these problems?
tc-config.xml:
Code:
<?xml version="1.0" encoding="UTF-8"?>
<tc:tc-config xmlns:tc="http://www.terracotta.org/config"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://www.terracotta.org/schema/terracotta-6.xsd">
<servers>
<server host="172.28.32.40" name="prodcache1">
<data>/opt/cache/logs/server-data</data>
<logs>/opt/cache/logs/server-logs</logs>
</server>
<server host="172.28.32.47" name="prodcache2">
<data>/opt/cache/logs/server-data</data>
<logs>/opt/cache/logs/server-logs</logs>
</server>
<mirror-groups>
<mirror-group group-name="prodgroup1">
<members>
<member>prodcache1</member>
<member>prodcache2</member>
</members>
</mirror-group>
</mirror-groups>
<ha>
<mode>networked-active-passive</mode>
<networked-active-passive>
<election-time>5</election-time>
</networked-active-passive>
</ha>
</servers>
<clients>
<logs>/opt/cache/logs/client-logs</logs>
</clients>
</tc:tc-config>
cache config:
Code:
<defaultCache
maxEntriesLocalHeap="1000"
eternal="false"
timeToIdleSeconds="3600"
statistics="true"
>
<persistence strategy="distributed" synchronousWrites="false"/>
<terracotta clustered="true" consistency="eventual" synchronousWrites="false">
<nonstop immediateTimeout="false" timeoutMillis="3000">
<timeoutBehavior type="noop" />
</nonstop>
</terracotta>
<bootstrapCacheLoaderFactory class="net.sf.ehcache.terracotta.TerracottaBootstrapCacheLoaderFactory"
properties="bootstrapAsynchronously=true,
interval=3600,
immediateShutdown=true,
snapshotOnShutDown=false,
doKeySnapshot=true,
useDedicatedThread=false"/>
</defaultCache>
Exception:
Code:
Caused by: org.hibernate.cache.CacheException: net.sf.ehcache.CacheException: java.lang.IllegalMonitorStateException
at net.sf.ehcache.hibernate.regions.EhcacheTransactionalDataRegion.writeUnlock(EhcacheTransactionalDataRegion.java:219)
at net.sf.ehcache.hibernate.strategy.AbstractReadWriteEhcacheAccessStrategy.putFromLoad(AbstractReadWriteEhcacheAccessStrategy.java:99)
at net.sf.ehcache.hibernate.nonstop.NonstopAwareEntityRegionAccessStrategy.putFromLoad(NonstopAwareEntityRegionAccessStrategy.java:180)
at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:179)
at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:877)
at org.hibernate.loader.Loader.doQuery(Loader.java:752)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
at org.hibernate.loader.Loader.doList(Loader.java:2228)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2125)
at org.hibernate.loader.Loader.list(Loader.java:2120)
at org.hibernate.loader.criteria.CriteriaLoader.list(CriteriaLoader.java:118)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1596)
at org.hibernate.impl.CriteriaImpl.list(CriteriaImpl.java:306)
at com.liferay.portal.dao.orm.hibernate.DynamicQueryImpl.list(DynamicQueryImpl.java:95)
at com.liferay.portal.dao.orm.hibernate.DynamicQueryImpl.list(DynamicQueryImpl.java:91)
at com.liferay.portlet.calendar.service.persistence.CalEventPersistenceImpl.findWithDynamicQuery(CalEventPersistenceImpl.java:2061)
... 211 more
Caused by: net.sf.ehcache.CacheException: java.lang.IllegalMonitorStateException
at net.sf.ehcache.constructs.nonstop.NonstopExecutorServiceImpl.execute(NonstopExecutorServiceImpl.java:108)
at net.sf.ehcache.constructs.nonstop.store.ExecutorServiceStore.executeWithExecutor(ExecutorServiceStore.java:160)
at net.sf.ehcache.constructs.nonstop.store.ExecutorServiceStore.executeWithExecutor(ExecutorServiceStore.java:129)
at net.sf.ehcache.constructs.nonstop.store.ExecutorServiceStore.executeClusterOperation(ExecutorServiceStore.java:1185)
at net.sf.ehcache.constructs.nonstop.store.NonstopStoreImpl.executeClusterOperation(NonstopStoreImpl.java:704)
at net.sf.ehcache.constructs.nonstop.concurrency.NonstopSync.unlock(NonstopSync.java:115)
at net.sf.ehcache.hibernate.regions.EhcacheTransactionalDataRegion.writeUnlock(EhcacheTransactionalDataRegion.java:214)
... 226 more
Caused by: java.lang.IllegalMonitorStateException
at com.tc.object.locks.ClientLockImpl.release(ClientLockImpl.java:664)
at com.tc.object.locks.ClientLockImpl.unlock(ClientLockImpl.java:115)
at com.tc.object.locks.ClientLockManagerImpl.unlock(ClientLockManagerImpl.java:181)
at com.tc.object.bytecode.ManagerImpl.unlock(ManagerImpl.java:951)
at org.terracotta.locking.TerracottaLock.unlock(TerracottaLock.java:128)
at org.terracotta.modules.ehcache.concurrency.TcSync.unlock(TcSync.java:75)
at net.sf.ehcache.constructs.nonstop.concurrency.NonstopSync$LockOperationType$2.performOperation(NonstopSync.java:220)
at net.sf.ehcache.constructs.nonstop.concurrency.NonstopSync$ExplicitLockingClusterOperationImpl.performClusterOperation(NonstopSync.java:141)
at net.sf.ehcache.constructs.nonstop.concurrency.NonstopSync$ExplicitLockingClusterOperationImpl.performClusterOperation(NonstopSync.java:124)
at net.sf.ehcache.constructs.nonstop.store.ClusterOperationCallableImpl.call(ClusterOperationCallableImpl.java:46)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at net.sf.ehcache.constructs.nonstop.NonstopThreadPool$WorkerThreadLocal$1.run(NonstopThreadPool.java:193)
at net.sf.ehcache.constructs.nonstop.NonstopThreadPool$Worker.run(NonstopThreadPool.java:243)