org.jboss.cache.lock.TimeoutException in second instance of a cluster.
When we startup another one of our web applications on a second instance in a cluster we get an org.jboss.cache.lock.TimeoutException thrown by org.jboss.cache.lock.IdentityLock. It seems that IdentityLock is attempting to acquire a WL when attempting to cache the query below but there is already a lock on the node /org/hibernate/cache/StandardQueryCache/sql, probably in the first instance. This application is running on Resin 3.1.2. We are using Hibernate 3.2.3 and JBoss cache 1.4.0.SP1. We have Hibernate configured to use a query and second level cache which is org.hibernate.cache.TreeCacheProvider, the JBoss TreeCache. We have the JBoss TreeCache to use the pessimistic locking scheme, the node isolation level is REPEATABLE_READ and the cache mode is LOCAL.
How do we resolve this problem?
Please let me know if you need further information from me.
Stack trace:
[14:10:41,302] ERROR [pool-9-thread-8] IdentityLock : write lock for /org/hibernate/cache/StandardQueryCache/sql: select searchro
ut0_.ID as ID28_, searchrout0_.hotel_code as hotel2_28_, searchrout0_.hotel_lat as hotel3_28_, searchrout0_.hotel_long as hotel4_28_
, searchrout0_.destination_name as destinat5_28_, searchrout0_.destination_lat as destinat6_28_, searchrout0_.destination_long as de
stinat7_28_, searchrout0_.distance_miles as distance8_28_, searchrout0_.distance_km as distance9_28_, searchrout0_.route_type as rou
te10_28_ from UA_MQ_HOTEL_DESTINATION_ROUTE searchrout0_ where searchrout0_.hotel_code=? and searchrout0_.hotel_lat=? and searchrout
0_.hotel_long=? and searchrout0_.destination_lat=? and searchrout0_.destination_long=? and searchrout0_.route_type=?; parameters: ;
named parameters: {hotelCode=JMBNJ, hotelLong=-74.4783, routeType=2, hotelLat=40.3444, destinationLong=-75.164199, destinationLat=39
.952201} could not be acquired after 0 ms. Locks: Read lock owners: []
Write lock owner: null
(caller=Thread[pool-9-thread-8,5,main], lock info: <unlocked> (activeReaders=0, activeWriter=null, waitingReaders=0, waitingWriters
=0, waitingUpgrader=0))
[14:10:41,305] INFO [pool-9-thread-8] TxInterceptor : There was a problem handling this request
org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/org/hibernate/cache/StandardQueryCache/sql: select searchrout0_.
ID as ID28_, searchrout0_.hotel_code as hotel2_28_, searchrout0_.hotel_lat as hotel3_28_, searchrout0_.hotel_long as hotel4_28_, sea
rchrout0_.destination_name as destinat5_28_, searchrout0_.destination_lat as destinat6_28_, searchrout0_.destination_long as destina
t7_28_, searchrout0_.distance_miles as distance8_28_, searchrout0_.distance_km as distance9_28_, searchrout0_.route_type as route10_
28_ from UA_MQ_HOTEL_DESTINATION_ROUTE searchrout0_ where searchrout0_.hotel_code=? and searchrout0_.hotel_lat=? and searchrout0_.ho
tel_long=? and searchrout0_.destination_lat=? and searchrout0_.destination_long=? and searchrout0_.route_type=?; parameters: ; named
parameters: {hotelCode=JMBNJ, hotelLong=-74.4783, routeType=2, hotelLat=40.3444, destinationLong=-75.164199, destinationLat=39.9522
01}, caller=Thread[pool-9-thread-8,5,main], lock=<unlocked> (activeReaders=0, activeWriter=null, waitingReaders=0, waitingWriters=0,
waitingUpgrader=0)
at org.jboss.cache.Node.acquire(Node.java:407)
at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:228)
at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:160)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
at org.jboss.cache.interceptors.UnlockInterceptor.invoke(UnlockInterceptor.java:32)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:345)
at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:156)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:157)
at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5520)
at org.jboss.cache.TreeCache.putFailFast(TreeCache.java:3643)
at org.hibernate.cache.TreeCache.put(TreeCache.java:74)
at org.hibernate.cache.StandardQueryCache.put(StandardQueryCache.java:87)
at org.hibernate.loader.Loader.putResultInQueryCache(Loader.java:2194)
at org.hibernate.loader.Loader.listUsingQueryCache(Loader.java:2138)
at org.hibernate.loader.Loader.list(Loader.java:2096)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:378)
at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
at com.ihg.dec.framework.dataAccessServices.hibernate.HibernateOperation.execGetListNamedQuery(HibernateOperation.java:208)
at com.ihg.dec.framework.dataAccessServices.hibernate.destination.search.HibernateSearchResultDAO.getSearchRoute(HibernateSe
archResultDAO.java:219)
at com.ihg.dec.framework.dataAccessServices.cacheable.destination.search.CacheableSearchResultDAO$4.retreiveCachedObject(Cac
heableSearchResultDAO.java:156)
at com.ihg.dec.framework.dataAccessServices.cacheable.destination.search.CacheableSearchResultDAO$4.retreiveCachedObject(Cac
heableSearchResultDAO.java:153)
at com.ihg.dec.framework.dataAccessServices.cacheable.AbstractCacheableDAO.getCachedObject(AbstractCacheableDAO.java:429)
at com.ihg.dec.framework.dataAccessServices.cacheable.AbstractProxiedCacheableDAO.getProxiedCachedObject(AbstractProxiedCach
eableDAO.java:56)
at com.ihg.dec.framework.dataAccessServices.cacheable.destination.search.CacheableSearchResultDAO.getSearchRoute(CacheableSe
archResultDAO.java:150)
at com.ihg.dec.framework.businessServices.hotel.delegates.SearchDelegate.fillDistanceFromSearchResultDAO(SearchDelegate.java
:975)
at com.ihg.dec.framework.businessServices.hotel.delegates.SearchDelegate.fillDistanceInformation(SearchDelegate.java:904)
at com.ihg.dec.framework.businessServices.hotel.delegates.SearchDelegate.fillHotelInformation(SearchDelegate.java:792)
at com.ihg.dec.framework.businessServices.hotel.delegates.SearchDelegate.constructHotelSearchResultSet(SearchDelegate.java:1
250)
at com.ihg.dec.framework.businessServices.hotel.delegates.SearchDelegate.search(SearchDelegate.java:159)
at com.ihg.dec.framework.businessServices.hotel.delegates.SearchDelegate.searchWithFilterAndSort(SearchDelegate.java:1448)
at com.ihg.dec.framework.businessServices.hotel.HotelSearchBO.findHotels(HotelSearchBO.java:65)
at sun.reflect.GeneratedMethodAccessor195.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at com.ihg.dec.framework.businessServices.BusinessObjectProxy.invoke_aroundBody0(BusinessObjectProxy.java:111)
at com.ihg.dec.framework.businessServices.BusinessObjectProxy$AjcClosure1.run(BusinessObjectProxy.java:1)
at com.ihg.dec.aop.statistics.businessServices.BusinessObjectProxyStatisticCollector.ajc$around$com_ihg_dec_aop_statistics_b
usinessServices_BusinessObjectProxyStatisticCollector$1$640f34fproceed(BusinessObjectProxyStatisticCollector.aj:1)
at com.ihg.dec.aop.statistics.businessServices.BusinessObjectProxyStatisticCollector$1.callProceed(BusinessObjectProxyStatis
ticCollector.aj:39)
at com.ihg.dec.aop.statistics.AbstractStatisticCollector.callObjectProxy(AbstractStatisticCollector.aj:49)
at com.ihg.dec.aop.statistics.businessServices.BusinessObjectProxyStatisticCollector.ajc$around$com_ihg_dec_aop_statistics_b
usinessServices_BusinessObjectProxyStatisticCollector$1$640f34f(BusinessObjectProxyStatisticCollector.aj:36)
at com.ihg.dec.framework.businessServices.BusinessObjectProxy.invoke(BusinessObjectProxy.java:94)
at $Proxy15.findHotels(Unknown Source)
at com.ihg.dec.framework.runtime.cacheWarmer.HotelSearchCacheWarmer$HotelSearchWarmTask.call(HotelSearchCacheWarmer.java:168
)
at com.ihg.dec.framework.runtime.cacheWarmer.HotelSearchCacheWarmer$HotelSearchWarmTask.call(HotelSearchCacheWarmer.java:128
)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
at java.util.concurrent.FutureTask.run(FutureTask.java:123)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
Caused by: org.jboss.cache.lock.TimeoutException: write lock for /org/hibernate/cache/StandardQueryCache/sql: select searchrout0_.ID
as ID28_, searchrout0_.hotel_code as hotel2_28_, searchrout0_.hotel_lat as hotel3_28_, searchrout0_.hotel_long as hotel4_28_, searc
hrout0_.destination_name as destinat5_28_, searchrout0_.destination_lat as destinat6_28_, searchrout0_.destination_long as destinat7
_28_, searchrout0_.distance_miles as distance8_28_, searchrout0_.distance_km as distance9_28_, searchrout0_.route_type as route10_28
_ from UA_MQ_HOTEL_DESTINATION_ROUTE searchrout0_ where searchrout0_.hotel_code=? and searchrout0_.hotel_lat=? and searchrout0_.hote
l_long=? and searchrout0_.destination_lat=? and searchrout0_.destination_long=? and searchrout0_.route_type=?; parameters: ; named p
arameters: {hotelCode=JMBNJ, hotelLong=-74.4783, routeType=2, hotelLat=40.3444, destinationLong=-75.164199, destinationLat=39.952201
} could not be acquired after 0 ms. Locks: Read lock owners: []
Write lock owner: null
(caller=Thread[pool-9-thread-8,5,main], lock info: <unlocked> (activeReaders=0, activeWriter=null, waitingReaders=0, waitingWriters
=0, waitingUpgrader=0))
at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:202)
at org.jboss.cache.Node.acquireWriteLock(Node.java:431)
at org.jboss.cache.Node.acquire(Node.java:386)
Hibernate configuration:
Code:
<!DOCTYPE hibernate-configuration PUBLIC
"-//Hibernate/Hibernate Configuration DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd">
<hibernate-configuration>
<session-factory>
<property name="show_sql">false</property>
<property name="connection.datasource">java:comp/env/jdbc/oracle</property>
<property name="dialect">
org.hibernate.dialect.Oracle9Dialect
</property>
<property name="cache.provider_class">
org.hibernate.cache.TreeCacheProvider
</property>
<property name="cache.use_query_cache">true</property>
<property name="cache.use_second_level_cache">true</property>
<property name="transaction.manager_lookup_class">
org.hibernate.transaction.ResinTransactionManagerLookup
</property>
<property name="transaction.factory_class">
org.hibernate.transaction.JTATransactionFactory
</property>
</session-factory>
</hibernate-configuration>
JBoss TreeCache configuration:
Code:
<?xml version="1.0" encoding="UTF-8"?>
<!-- ===================================================================== -->
<!-- -->
<!-- TreeCache Service Configuration -->
<!-- -->
<!-- ===================================================================== -->
<server>
<classpath codebase="./lib" archives="jboss-cache.jar" />
<!-- ==================================================================== -->
<!-- Defines TreeCache configuration -->
<!-- ==================================================================== -->
<mbean code="org.jboss.cache.TreeCache"
name="jboss.cache:service=TreeCache">
<depends>jboss:service=Naming</depends>
<!--
Configure the TransactionManager
-->
<!--
Node locking scheme:
OPTIMISTIC
PESSIMISTIC (default)
-->
<attribute name="NodeLockingScheme">PESSIMISTIC</attribute>
<attribute name="FetchInMemoryState">false</attribute>
<attribute name="FetchPersistentState">false</attribute>
<!--
Node isolation level : SERIALIZABLE
REPEATABLE_READ (default)
READ_COMMITTED
READ_UNCOMMITTED
NONE
-->
<attribute name="IsolationLevel">REPEATABLE_READ</attribute>
<!--
Valid modes are LOCAL
REPL_ASYNC
REPL_SYNC
-->
<attribute name="CacheMode">LOCAL</attribute>
<!-- Whether each interceptor should have an mbean
registered to capture and display its statistics. -->
<attribute name="UseInterceptorMbeans">true</attribute>
<!--
The max amount of time (in milliseconds) we wait until the
initial state (ie. the contents of the cache) are retrieved from
existing members in a clustered environment
-->
<attribute name="InitialStateRetrievalTimeout">
100000
</attribute>
<!--
Number of milliseconds to wait until all responses for a
synchronous call have been received.
-->
<attribute name="SyncReplTimeout">10000</attribute>
<!-- Max number of milliseconds to wait for a lock acquisition -->
<attribute name="LockAcquisitionTimeout">60000</attribute>
<!-- Name of the eviction policy class. -->
<attribute name="EvictionPolicyClass">
org.jboss.cache.eviction.LRUPolicy
</attribute>
<!-- Specific eviction policy configurations. This is LRU -->
<attribute name="EvictionPolicyConfig">
<config>
<attribute name="wakeUpIntervalSeconds">5</attribute>
<!-- Cache wide default -->
<region name="/_default_">
<attribute name="maxNodes">5000</attribute>
<attribute name="timeToLiveSeconds">3600</attribute>
<attribute name="maxAgeSeconds">43200</attribute>
</region>
<region name="/cro/numbers">
<attribute name="maxNodes">50000</attribute>
<attribute name="timeToLiveSeconds">3600</attribute>
<attribute name="maxAgeSeconds">43200</attribute>
</region>
<region name="/hotels/detail">
<attribute name="maxNodes">2000</attribute>
<attribute name="timeToLiveSeconds">
14400
</attribute>
<attribute name="maxAgeSeconds">43200</attribute>
</region>
<!-- Vales based on that we are not properly clearing the cache after a data load -->
<region name="/hotels/sales/features">
<attribute name="maxNodes">5000</attribute>
<attribute name="timeToLiveSeconds">
14400
</attribute>
<attribute name="maxAgeSeconds">21600</attribute>
</region>
<region name="/hotels/sales/help">
<attribute name="maxNodes">5000</attribute>
<attribute name="timeToLiveSeconds">
14400
</attribute>
<attribute name="maxAgeSeconds">21600</attribute>
</region>
<region name="/hotels/geocode">
<attribute name="maxNodes">5000</attribute>
<attribute name="timeToLiveSeconds">86400</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<region name="/hotels/search/addresses">
<attribute name="maxNodes">5000</attribute>
<attribute name="timeToLiveSeconds">
14400
</attribute>
<attribute name="maxAgeSeconds">43200</attribute>
</region>
<region name="/destination/searchResult">
<attribute name="maxNodes">5000</attribute>
<attribute name="timeToLiveSeconds">
14400
</attribute>
<attribute name="maxAgeSeconds">43200</attribute>
</region>
<region name="/destination/searchRoute">
<attribute name="maxNodes">5000</attribute>
<attribute name="timeToLiveSeconds">
14400
</attribute>
<attribute name="maxAgeSeconds">43200</attribute>
</region>
<region name="/hotels/search/hotels">
<attribute name="maxNodes">50000</attribute>
<attribute name="timeToLiveSeconds">
14400
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<region name="/lookup/countryCollections">
<attribute name="maxNodes">50000</attribute>
<attribute name="timeToLiveSeconds">
21600
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<region name="/lookup/stateCollections">
<attribute name="maxNodes">50000</attribute>
<attribute name="timeToLiveSeconds">
21600
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<region name="/lookup/pointsOfInterests">
<attribute name="maxNodes">50000</attribute>
<attribute name="timeToLiveSeconds">
21600
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<region name="/teasers">
<attribute name="maxNodes">50000</attribute>
<attribute name="timeToLiveSeconds">3600</attribute>
<attribute name="maxAgeSeconds">259200</attribute>
</region>
<region name="/urlmanager">
<attribute name="maxNodes">50000</attribute>
<attribute name="timeToLiveSeconds">3600</attribute>
<attribute name="maxAgeSeconds">43200</attribute>
</region>
<region name="/rate/RateCategory">
<attribute name="maxNodes">1500</attribute>
<attribute name="timeToLiveSeconds">
604800
</attribute>
<attribute name="maxAgeSeconds">604800</attribute>
</region>
<region name="/b2b/displayableText">
<attribute name="maxNodes">1000</attribute>
<attribute name="timeToLiveSeconds">
604800
</attribute>
<attribute name="maxAgeSeconds">604800</attribute>
</region>
<region name="/b2b/client">
<attribute name="maxNodes">1000</attribute>
<attribute name="timeToLiveSeconds">
604800
</attribute>
<attribute name="maxAgeSeconds">604800</attribute>
</region>
<region name="/b2b/codes">
<attribute name="maxNodes">1000</attribute>
<attribute name="timeToLiveSeconds">
604800
</attribute>
<attribute name="maxAgeSeconds">604800</attribute>
</region>
<region name="/b2b/errors">
<attribute name="maxNodes">1000</attribute>
<attribute name="timeToLiveSeconds">
604800
</attribute>
<attribute name="maxAgeSeconds">604800</attribute>
</region>
<!--
This region should be used for caching transaction errors from
external systems such as 500 errors from Content servres. Nodes should
not be stored directly to this region but should be stored in sub-regions
such as /transactionErrors/
-->
<region name="/transactionErrors">
<attribute name="maxNodes">1000</attribute>
<attribute name="timeToLiveSeconds">60</attribute>
<attribute name="maxAgeSeconds">60</attribute>
</region>
<!--
This region is used as an in-memory cache for avail cache. Items in avail cache should
not live beyond 15 minutes.
-->
<region name="/availCache">
<attribute name="maxNodes">5000</attribute>
<attribute name="timeToLiveSeconds">900</attribute>
<attribute name="maxAgeSeconds">900</attribute>
</region>
<!-- Region to store the collection of Brand objects -->
<region name="/lookup/brand">
<attribute name="maxNodes">50</attribute>
<attribute name="timeToLiveSeconds">0</attribute>
<attribute name="maxAgeSeconds">0</attribute>
</region>
<!-- Region to store the collection of FeatureType objects -->
<region name="/lookup/featureType">
<attribute name="maxNodes">2000</attribute>
<attribute name="timeToLiveSeconds">
21600
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<!-- Region to store geo destination objects -->
<region name="/hotels/search/geoDestinations">
<attribute name="maxNodes">5000</attribute>
<attribute name="timeToLiveSeconds">
14400
</attribute>
<attribute name="maxAgeSeconds">43200</attribute>
</region>
<!-- Region to store the RoomType objects -->
<region name="/lookup/roomType">
<attribute name="maxNodes">100</attribute>
<attribute name="timeToLiveSeconds">
21600
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<!-- Region to store hotel name objects, the maxAge is 24 hours and timeToLive is 12 hours -->
<region name="/hotels/search/hotelName">
<attribute name="maxNodes">50000</attribute>
<attribute name="timeToLiveSeconds">
43200
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<!-- Region to store city nick name, the maxAge is 24 hours and timeToLive is 12 hours -->
<region name="/hotels/search/cityNickname">
<attribute name="maxNodes">50000</attribute>
<attribute name="timeToLiveSeconds">
43200
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<!-- Region to store the Currency objects -->
<region name="/lookup/currency">
<attribute name="maxNodes">200</attribute>
<attribute name="timeToLiveSeconds">
21600
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<!-- Region to store the CurrencyDetail objects -->
<region name="/lookup/currencyDetail">
<attribute name="maxNodes">200</attribute>
<attribute name="timeToLiveSeconds">3600</attribute>
<attribute name="maxAgeSeconds">7200</attribute>
</region>
<!-- Region to store credit card identifiers -->
<region name="/lookup/creditCard">
<attribute name="maxNodes">10</attribute>
<attribute name="timeToLiveSeconds">
86400
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<!-- Region to store contact centers -->
<region name="/lookup/contactCenter">
<attribute name="maxNodes">20</attribute>
<attribute name="timeToLiveSeconds">
86400
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
<!-- Region to store contact centers -->
<region name="/proxy/proxyClasses">
<attribute name="maxNodes">2000</attribute>
<attribute name="timeToLiveSeconds">
86400
</attribute>
<attribute name="maxAgeSeconds">86400</attribute>
</region>
</config>
</attribute>
</mbean>
</server>