net.sf.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4

Hibernate JIRA | Catalin Sanda | 1 decade ago
  1. 0

    Hibernate runs within JBoss application server as a registered MBean. It uses JBossTree cache as its cache provider. The UseQueryCache is enabled (when it is disabled the problem doesn't manifest itself) the cache is set to transactional. The first update to a cached table succeeds, but the second fails, because it seems that Hibernate leaves the TreeCache (UpdateTimestampsCache) in a locked state. This can be viewed from the following log. 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.cache.TransactionalCache] cache lookup: 81 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] get(, "//ro/siveco/bdne/model/nomenclatoare/JudetDef/81", item, "true") 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.Node] acquired RL: fqn=//ro/siveco/bdne/model/nomenclatoare/JudetDef, owner=<null>:5, lock=read owners=[<null>:5] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.cache.TransactionalCache] cache miss 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] object not resolved in any cache [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.persister.EntityPersister] Materializing entity: [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.SQL] select judetdef0_.ID_JUDET as ID_JUDET0_, judetdef0_.COD as COD0_, judetdef0_.COD_NUMERIC as COD_NUME3_0_, judetdef0_.DENUMIRE as DENUMIRE0_, judetdef0_.DE_LA as DE_LA0_, judetdef0_.PANA_LA as PANA_LA0_ from NOM_JUDET judetdef0_ where judetdef0_.ID_JUDET=? 2004-10-29 18:22:08,693 INFO [STDOUT] Hibernate: select judetdef0_.ID_JUDET as ID_JUDET0_, judetdef0_.COD as COD0_, judetdef0_.COD_NUMERIC as COD_NUME3_0_, judetdef0_.DENUMIRE as DENUMIRE0_, judetdef0_.DE_LA as DE_LA0_, judetdef0_.PANA_LA as PANA_LA0_ from NOM_JUDET judetdef0_ where judetdef0_.ID_JUDET=? 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.BatcherImpl] preparing statement 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.LongType] binding '81' to parameter: 1 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] processing result set 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] result row: 81 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] Initializing object from ResultSet: 81 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] Hydrating entity: ro.siveco.bdne.model.nomenclatoare.JudetDef#81 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.StringType] returning 'BC' as column: COD0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.LongType] returning '4' as column: COD_NUME3_0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.StringType] returning 'BACAU' as column: DENUMIRE0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.TimestampType] returning '21 September 2004 18:52:07' as column: DE_LA0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.TimestampType] returning null as column: PANA_LA0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] done processing result set (1 rows) 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.BatcherImpl] closing statement 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] total objects hydrated: 1 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] resolving associations for [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] adding entity to second-level cache [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.cache.TransactionalCache] caching: 81 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] _put(<null>:5, "//ro/siveco/bdne/model/nomenclatoare/JudetDef/81", item, net.sf.hibernate.impl.CacheEntry@1829c6b) 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.lock.IdentityLock] caller already owns lock. 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.Node] acquired RL: fqn=//ro/siveco/bdne/model/nomenclatoare/JudetDef, owner=<null>:5, lock=read owners=[<null>:5] 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.Node] createChild: fqn=//ro/siveco/bdne/model/nomenclatoare/JudetDef/81 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.Node] acquired WL: fqn=//ro/siveco/bdne/model/nomenclatoare/JudetDef/81, owner=<null>:5, lock=write owner=<null>:5 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] done materializing entity [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] initializing non-lazy collections 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] flushing session 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushing entities and processing referenced collections 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Processing unreferenced collections 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Scheduling collection removes/(re)creates/updates 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.Printer] listing entities: 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.Printer] ro.siveco.bdne.model.nomenclatoare.JudetDef{cod=BC, deLa=21 September 2004 18:52:07, panaLa=null, codNumeric=4, idNomenclator=81, denumire=BACAU} 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] executing flush 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] post flush 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.engine.CacheSynchronization] transaction before completion callback 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] closing session 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] disconnecting session 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] commit(): called to commit cache with gtx <null>:5 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] commit(): releasing lock write owner=<null>:5 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] commit(): releasing lock read owners=[<null>:5] 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] commit(): removing local transaction key TransactionImpl:XidImpl[FormatId=257, GlobalId=CatalinSa/17, BranchQual=, localId=17] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.engine.CacheSynchronization] transaction after completion callback, status: 3 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] transaction completion 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionFactoryObjectFactory] JNDI lookup: hibernate/HibernateFactory 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=2c9481c6ffe5467d00ffe5467f9b0000 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] opened session 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.engine.Cascades] id unsaved-value strategy NULL 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] saveOrUpdate() previously saved instance with id: 81 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] updating [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] flushing session 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushing entities and processing referenced collections 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Updating entity: [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Processing unreferenced collections 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Scheduling collection removes/(re)creates/updates 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.Printer] listing entities: 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.Printer] ro.siveco.bdne.model.nomenclatoare.JudetDef{cod=BC, deLa=21 September 2004 18:52:07, panaLa=null, codNumeric=23, idNomenclator=81, denumire=BACAU} 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] executing flush 2004-10-29 18:22:08,709 DEBUG [org.jboss.cache.TreeCache] _put(<null>:6, "//net/sf/hibernate/cache/UpdateTimestampsCache/NOM_JUDET", item, 10990633887) 2004-10-29 18:22:08,709 DEBUG [org.jboss.cache.Node] acquired RL: fqn=//net/sf/hibernate/cache/UpdateTimestampsCache, owner=<null>:6, lock=read owners=[<null>:4, <null>:6] 2004-10-29 18:22:20,693 DEBUG [net.sf.hibernate.impl.SessionImpl] running Session.finalize() 2004-10-29 18:22:20,693 DEBUG [net.sf.hibernate.impl.SessionImpl] running Session.finalize() 2004-10-29 18:22:20,693 DEBUG [net.sf.hibernate.impl.SessionImpl] running Session.finalize() 2004-10-29 18:22:23,709 ERROR [org.jboss.cache.lock.IdentityLock] lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4 2004-10-29 18:22:23,709 DEBUG [org.jboss.cache.Node] failure acquiring lock: fqn=//net/sf/hibernate/cache/UpdateTimestampsCache/NOM_JUDET, owner=<null>:6, lock=write owner=<null>:4 2004-10-29 18:22:23,709 DEBUG [org.jboss.cache.lock.IdentityLock] release(): lock map owner <null>:6 not found. Could have been released. 2004-10-29 18:22:23,725 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.parentTraceEnabled=true 2004-10-29 18:22:23,725 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.nestedTraceEnabled=false 2004-10-29 18:22:23,725 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.detectDuplicateNesting=true 2004-10-29 18:22:23,709 ERROR [net.sf.hibernate.impl.SessionImpl] Could not synchronize database state with session net.sf.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4 at net.sf.hibernate.cache.TreeCache.put(TreeCache.java:70) at net.sf.hibernate.cache.UpdateTimestampsCache.preinvalidate(UpdateTimestampsCache.java:42) at net.sf.hibernate.impl.SessionImpl.executeAll(SessionImpl.java:2413) at net.sf.hibernate.impl.SessionImpl.execute(SessionImpl.java:2368) at net.sf.hibernate.impl.SessionImpl.flush(SessionImpl.java:2236) at org.jboss.hibernate.session.TransactionSynch.beforeCompletion(Unknown Source) at org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:1383) at org.jboss.tm.TransactionImpl.beforePrepare(TransactionImpl.java:1075) at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:296) at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:457) at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:325) at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:149) at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:128) at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191) at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122) at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624) at org.jboss.ejb.Container.invoke(Container.java:854) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:141) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80) at org.jboss.mx.server.Invocation.invoke(Invocation.java:72) at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:242) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:642) at org.jboss.invocation.jrmp.server.JRMPInvoker$MBeanServerAction.invoke(JRMPInvoker.java:775) at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:382) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:261) at sun.rmi.transport.Transport$1.run(Transport.java:148) at java.security.AccessController.doPrivileged(Native Method) at sun.rmi.transport.Transport.serviceCall(Transport.java:144) at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701) at java.lang.Thread.run(Thread.java:534) Caused by: org.jboss.cache.lock.TimeoutException: lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4 at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:146) at org.jboss.cache.Node.acquireWriteLock(Node.java:422) at org.jboss.cache.Node.acquire(Node.java:388) at org.jboss.cache.TreeCache.findNode(TreeCache.java:3284) at org.jboss.cache.TreeCache._put(TreeCache.java:2335) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:236) at org.jboss.cache.interceptors.CallInterceptor.invoke(CallInterceptor.java:14) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:39) at org.jboss.cache.interceptors.TransactionInterceptor.invoke(TransactionInterceptor.java:53) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3171) at org.jboss.cache.TreeCache.put(TreeCache.java:1735) at net.sf.hibernate.cache.TreeCache.put(TreeCache.java:67) ... 38 more 2004-10-29 18:22:23,771 WARN [org.jboss.hibernate.session.TransactionSynch] Error flushing session 2004-10-29 18:22:23,771 DEBUG [net.sf.hibernate.impl.SessionImpl] closing session 2004-10-29 18:22:23,771 DEBUG [org.jboss.cache.TreeCache] commit(): called to commit cache with gtx <null>:6 2004-10-29 18:22:23,771 DEBUG [org.jboss.cache.TreeCache] commit(): releasing lock read owners=[<null>:4] 2004-10-29 18:22:23,771 DEBUG [org.jboss.cache.lock.IdentityLock] release(): lock map owner <null>:6 not found. Could have been released. 2004-10-29 18:22:23,771 DEBUG [org.jboss.cache.TreeCache] commit(): removing local transaction key TransactionImpl:XidImpl[FormatId=257, GlobalId=CatalinSa/18, BranchQual=, localId=18] 2004-10-29 18:23:21,005 DEBUG [net.sf.hibernate.impl.SessionImpl] running Session.finalize() The test case I developed is a simple 3-tier application composed of: 1. client 2. common module 3. a SLSB 4. Hibernate SAR module 1. Client - a simple client which does a JNDI lookup and executes 2 updates on a table. try { InitialContext ctx = new InitialContext(); TestHome home = ( TestHome ) ctx.lookup( "java:/TestEJB" ); Test test = (Test) home.create(); JudetDef judetDef = test.getJudet( new Long(6) ); judetDef.setCodNumeric( new Long (12) ); test.setJudet( judetDef ); judetDef = test.getJudet( new Long(81) ); judetDef.setCodNumeric( new Long (23) ); test.setJudet( judetDef ); } catch .... 2. Common Module - contains a simple persistant class (JudeteDef). 3. Simple SLSB - I will only post the relevant parts. (Transactions are required on all methods). public class TestEJB implements SessionBean { public static final String hibernateFactoryJNDIName = "java:/hibernate/HibernateFactory"; ..... the SLSB stuff. public JudetDef getJudet( Long id ) { try { Session session = HibernateContext.getSession( hibernateFactoryJNDIName ); return ( JudetDef ) session.load( JudetDef.class, id ); } catch ( HibernateException e ) { } return null; } public void setJudet( JudetDef judetDef ) { try { Session session = HibernateContext.getSession( hibernateFactoryJNDIName ); session.saveOrUpdate( judetDef ); } catch ( HibernateException e ) { } } } 4. Hibernate SAR Jboss-service.xml <?xml version="1.0" encoding="UTF-8"?> <!DOCTYPE server> <server> <mbean code="net.sf.hibernate.jmx.HibernateService" name="jboss.jca:service=Hibernate"> <depends>jboss.jca:service=RARDeployer</depends> <attribute name="MapResources">ro/siveco/bdne/model/nomenclatoare/JudetDef.hbm.xml</attribute> <attribute name="JndiName">java:/hibernate/HibernateFactory</attribute> <attribute name="Datasource">java:/BDNEDS</attribute> <attribute name="Dialect">net.sf.hibernate.dialect.OracleDialect</attribute> <attribute name="UseOuterJoin">true</attribute> <attribute name="ShowSql">true</attribute> <attribute name="UserTransactionName">UserTransaction</attribute> <attribute name="TransactionStrategy">net.sf.hibernate.transaction.JTATransactionFactory</attribute> <attribute name="TransactionManagerLookupStrategy">net.sf.hibernate.transaction.JBossTransactionManagerLookup</attribute> <attribute name="CacheProvider">net.sf.hibernate.cache.TreeCacheProvider</attribute> <attribute name="UseQueryCache">true</attribute> </mbean> </server> treecache.xml <?xml version="1.0" encoding="UTF-8"?> <server> <classpath codebase="./lib" archives="jboss-cache.jar, jgroups.jar"/> <mbean code="org.jboss.cache.TreeCache" name="jboss.cache:service=TreeCache"> <depends>jboss:service=Naming</depends> <depends>jboss:service=TransactionManager</depends> <attribute name="TransactionManagerLookupClass">org.jboss.cache.DummyTransactionManagerLookup</attribute> <attribute name="IsolationLevel">REPEATABLE_READ</attribute> <attribute name="CacheMode">LOCAL</attribute> <attribute name="MaxCapacity">20000</attribute> <attribute name="InitialStateRetrievalTimeout">20000</attribute> <attribute name="SyncReplTimeout">10000</attribute> <attribute name="LockAcquisitionTimeout">15000</attribute> <attribute name="LockLeaseTimeout">60000</attribute> <attribute name="EvictionPolicyClass"></attribute> </mbean> </server> JudetDef.hbm.xml <?xml version="1.0" encoding="UTF-8"?> <!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 2.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd"> <hibernate-mapping > <class name="ro.siveco.bdne.model.nomenclatoare.JudetDef" table="NOM_JUDET" dynamic-update="false" dynamic-insert="false" select-before-update="false" optimistic-lock="version" > <cache usage="transactional" /> <id name="idNomenclator" column="ID_JUDET" type="java.lang.Long" > <generator class="sequence"> <param name="sequence">NOM_JUDET_SEQ</param> <!-- To add non XDoclet generator parameters, create a file named hibernate-generator-params-JudetDef.xml containing the additional parameters and place it in your merge dir. --> </generator> </id> <property name="cod" type="java.lang.String" update="true" insert="true" access="property" column="COD" length="2" not-null="true" /> <property name="codNumeric" type="java.lang.Long" update="true" insert="true" access="property" column="COD_NUMERIC" length="2" not-null="true" /> <property name="denumire" type="java.lang.String" update="true" insert="true" access="property" column="DENUMIRE" length="50" not-null="true" /> <property name="deLa" type="java.sql.Timestamp" update="true" insert="true" access="property" column="DE_LA" length="11" not-null="true" /> <property name="panaLa" type="java.sql.Timestamp" update="true" insert="true" access="property" column="PANA_LA" length="11" /> <!-- To add non XDoclet property mappings, create a file named hibernate-properties-JudetDef.xml containing the additional properties and place it in your merge dir. --> </class> </hibernate-mapping> This is the test case. If you need further information do not hesitate to contact me at "catalinsanda@siveco.ro"

    Hibernate JIRA | 1 decade ago | Catalin Sanda
    net.sf.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4
  2. 0

    Hibernate / Mailing Lists

    sourceforge.net | 5 months ago
    net.sf.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4
  3. 0

    Hibernate runs within JBoss application server as a registered MBean. It uses JBossTree cache as its cache provider. The UseQueryCache is enabled (when it is disabled the problem doesn't manifest itself) the cache is set to transactional. The first update to a cached table succeeds, but the second fails, because it seems that Hibernate leaves the TreeCache (UpdateTimestampsCache) in a locked state. This can be viewed from the following log. 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.cache.TransactionalCache] cache lookup: 81 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] get(, "//ro/siveco/bdne/model/nomenclatoare/JudetDef/81", item, "true") 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.Node] acquired RL: fqn=//ro/siveco/bdne/model/nomenclatoare/JudetDef, owner=<null>:5, lock=read owners=[<null>:5] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.cache.TransactionalCache] cache miss 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] object not resolved in any cache [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.persister.EntityPersister] Materializing entity: [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.BatcherImpl] about to open: 0 open PreparedStatements, 0 open ResultSets 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.SQL] select judetdef0_.ID_JUDET as ID_JUDET0_, judetdef0_.COD as COD0_, judetdef0_.COD_NUMERIC as COD_NUME3_0_, judetdef0_.DENUMIRE as DENUMIRE0_, judetdef0_.DE_LA as DE_LA0_, judetdef0_.PANA_LA as PANA_LA0_ from NOM_JUDET judetdef0_ where judetdef0_.ID_JUDET=? 2004-10-29 18:22:08,693 INFO [STDOUT] Hibernate: select judetdef0_.ID_JUDET as ID_JUDET0_, judetdef0_.COD as COD0_, judetdef0_.COD_NUMERIC as COD_NUME3_0_, judetdef0_.DENUMIRE as DENUMIRE0_, judetdef0_.DE_LA as DE_LA0_, judetdef0_.PANA_LA as PANA_LA0_ from NOM_JUDET judetdef0_ where judetdef0_.ID_JUDET=? 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.BatcherImpl] preparing statement 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.LongType] binding '81' to parameter: 1 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] processing result set 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] result row: 81 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] Initializing object from ResultSet: 81 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] Hydrating entity: ro.siveco.bdne.model.nomenclatoare.JudetDef#81 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.StringType] returning 'BC' as column: COD0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.LongType] returning '4' as column: COD_NUME3_0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.StringType] returning 'BACAU' as column: DENUMIRE0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.TimestampType] returning '21 September 2004 18:52:07' as column: DE_LA0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.type.TimestampType] returning null as column: PANA_LA0_ 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] done processing result set (1 rows) 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.BatcherImpl] done closing: 0 open PreparedStatements, 0 open ResultSets 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.BatcherImpl] closing statement 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.loader.Loader] total objects hydrated: 1 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] resolving associations for [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] adding entity to second-level cache [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.cache.TransactionalCache] caching: 81 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] _put(<null>:5, "//ro/siveco/bdne/model/nomenclatoare/JudetDef/81", item, net.sf.hibernate.impl.CacheEntry@1829c6b) 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.lock.IdentityLock] caller already owns lock. 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.Node] acquired RL: fqn=//ro/siveco/bdne/model/nomenclatoare/JudetDef, owner=<null>:5, lock=read owners=[<null>:5] 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.Node] createChild: fqn=//ro/siveco/bdne/model/nomenclatoare/JudetDef/81 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.Node] acquired WL: fqn=//ro/siveco/bdne/model/nomenclatoare/JudetDef/81, owner=<null>:5, lock=write owner=<null>:5 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] done materializing entity [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] initializing non-lazy collections 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] flushing session 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushing entities and processing referenced collections 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Processing unreferenced collections 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Scheduling collection removes/(re)creates/updates 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.Printer] listing entities: 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.Printer] ro.siveco.bdne.model.nomenclatoare.JudetDef{cod=BC, deLa=21 September 2004 18:52:07, panaLa=null, codNumeric=4, idNomenclator=81, denumire=BACAU} 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] executing flush 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] post flush 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.engine.CacheSynchronization] transaction before completion callback 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] closing session 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] disconnecting session 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] commit(): called to commit cache with gtx <null>:5 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] commit(): releasing lock write owner=<null>:5 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] commit(): releasing lock read owners=[<null>:5] 2004-10-29 18:22:08,693 DEBUG [org.jboss.cache.TreeCache] commit(): removing local transaction key TransactionImpl:XidImpl[FormatId=257, GlobalId=CatalinSa/17, BranchQual=, localId=17] 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.engine.CacheSynchronization] transaction after completion callback, status: 3 2004-10-29 18:22:08,693 DEBUG [net.sf.hibernate.impl.SessionImpl] transaction completion 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionFactoryObjectFactory] JNDI lookup: hibernate/HibernateFactory 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=2c9481c6ffe5467d00ffe5467f9b0000 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] opened session 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.engine.Cascades] id unsaved-value strategy NULL 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] saveOrUpdate() previously saved instance with id: 81 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] updating [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] flushing session 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushing entities and processing referenced collections 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Updating entity: [ro.siveco.bdne.model.nomenclatoare.JudetDef#81] 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Processing unreferenced collections 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Scheduling collection removes/(re)creates/updates 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.Printer] listing entities: 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.Printer] ro.siveco.bdne.model.nomenclatoare.JudetDef{cod=BC, deLa=21 September 2004 18:52:07, panaLa=null, codNumeric=23, idNomenclator=81, denumire=BACAU} 2004-10-29 18:22:08,709 DEBUG [net.sf.hibernate.impl.SessionImpl] executing flush 2004-10-29 18:22:08,709 DEBUG [org.jboss.cache.TreeCache] _put(<null>:6, "//net/sf/hibernate/cache/UpdateTimestampsCache/NOM_JUDET", item, 10990633887) 2004-10-29 18:22:08,709 DEBUG [org.jboss.cache.Node] acquired RL: fqn=//net/sf/hibernate/cache/UpdateTimestampsCache, owner=<null>:6, lock=read owners=[<null>:4, <null>:6] 2004-10-29 18:22:20,693 DEBUG [net.sf.hibernate.impl.SessionImpl] running Session.finalize() 2004-10-29 18:22:20,693 DEBUG [net.sf.hibernate.impl.SessionImpl] running Session.finalize() 2004-10-29 18:22:20,693 DEBUG [net.sf.hibernate.impl.SessionImpl] running Session.finalize() 2004-10-29 18:22:23,709 ERROR [org.jboss.cache.lock.IdentityLock] lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4 2004-10-29 18:22:23,709 DEBUG [org.jboss.cache.Node] failure acquiring lock: fqn=//net/sf/hibernate/cache/UpdateTimestampsCache/NOM_JUDET, owner=<null>:6, lock=write owner=<null>:4 2004-10-29 18:22:23,709 DEBUG [org.jboss.cache.lock.IdentityLock] release(): lock map owner <null>:6 not found. Could have been released. 2004-10-29 18:22:23,725 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.parentTraceEnabled=true 2004-10-29 18:22:23,725 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.nestedTraceEnabled=false 2004-10-29 18:22:23,725 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.detectDuplicateNesting=true 2004-10-29 18:22:23,709 ERROR [net.sf.hibernate.impl.SessionImpl] Could not synchronize database state with session net.sf.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4 at net.sf.hibernate.cache.TreeCache.put(TreeCache.java:70) at net.sf.hibernate.cache.UpdateTimestampsCache.preinvalidate(UpdateTimestampsCache.java:42) at net.sf.hibernate.impl.SessionImpl.executeAll(SessionImpl.java:2413) at net.sf.hibernate.impl.SessionImpl.execute(SessionImpl.java:2368) at net.sf.hibernate.impl.SessionImpl.flush(SessionImpl.java:2236) at org.jboss.hibernate.session.TransactionSynch.beforeCompletion(Unknown Source) at org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:1383) at org.jboss.tm.TransactionImpl.beforePrepare(TransactionImpl.java:1075) at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:296) at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:457) at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:325) at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:149) at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:128) at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191) at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122) at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624) at org.jboss.ejb.Container.invoke(Container.java:854) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:141) at org.jboss.mx.server.Invocation.dispatch(Invocation.java:80) at org.jboss.mx.server.Invocation.invoke(Invocation.java:72) at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:242) at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:642) at org.jboss.invocation.jrmp.server.JRMPInvoker$MBeanServerAction.invoke(JRMPInvoker.java:775) at org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:382) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:261) at sun.rmi.transport.Transport$1.run(Transport.java:148) at java.security.AccessController.doPrivileged(Native Method) at sun.rmi.transport.Transport.serviceCall(Transport.java:144) at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701) at java.lang.Thread.run(Thread.java:534) Caused by: org.jboss.cache.lock.TimeoutException: lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4 at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:146) at org.jboss.cache.Node.acquireWriteLock(Node.java:422) at org.jboss.cache.Node.acquire(Node.java:388) at org.jboss.cache.TreeCache.findNode(TreeCache.java:3284) at org.jboss.cache.TreeCache._put(TreeCache.java:2335) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:236) at org.jboss.cache.interceptors.CallInterceptor.invoke(CallInterceptor.java:14) at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:39) at org.jboss.cache.interceptors.TransactionInterceptor.invoke(TransactionInterceptor.java:53) at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3171) at org.jboss.cache.TreeCache.put(TreeCache.java:1735) at net.sf.hibernate.cache.TreeCache.put(TreeCache.java:67) ... 38 more 2004-10-29 18:22:23,771 WARN [org.jboss.hibernate.session.TransactionSynch] Error flushing session 2004-10-29 18:22:23,771 DEBUG [net.sf.hibernate.impl.SessionImpl] closing session 2004-10-29 18:22:23,771 DEBUG [org.jboss.cache.TreeCache] commit(): called to commit cache with gtx <null>:6 2004-10-29 18:22:23,771 DEBUG [org.jboss.cache.TreeCache] commit(): releasing lock read owners=[<null>:4] 2004-10-29 18:22:23,771 DEBUG [org.jboss.cache.lock.IdentityLock] release(): lock map owner <null>:6 not found. Could have been released. 2004-10-29 18:22:23,771 DEBUG [org.jboss.cache.TreeCache] commit(): removing local transaction key TransactionImpl:XidImpl[FormatId=257, GlobalId=CatalinSa/18, BranchQual=, localId=18] 2004-10-29 18:23:21,005 DEBUG [net.sf.hibernate.impl.SessionImpl] running Session.finalize() The test case I developed is a simple 3-tier application composed of: 1. client 2. common module 3. a SLSB 4. Hibernate SAR module 1. Client - a simple client which does a JNDI lookup and executes 2 updates on a table. try { InitialContext ctx = new InitialContext(); TestHome home = ( TestHome ) ctx.lookup( "java:/TestEJB" ); Test test = (Test) home.create(); JudetDef judetDef = test.getJudet( new Long(6) ); judetDef.setCodNumeric( new Long (12) ); test.setJudet( judetDef ); judetDef = test.getJudet( new Long(81) ); judetDef.setCodNumeric( new Long (23) ); test.setJudet( judetDef ); } catch .... 2. Common Module - contains a simple persistant class (JudeteDef). 3. Simple SLSB - I will only post the relevant parts. (Transactions are required on all methods). public class TestEJB implements SessionBean { public static final String hibernateFactoryJNDIName = "java:/hibernate/HibernateFactory"; ..... the SLSB stuff. public JudetDef getJudet( Long id ) { try { Session session = HibernateContext.getSession( hibernateFactoryJNDIName ); return ( JudetDef ) session.load( JudetDef.class, id ); } catch ( HibernateException e ) { } return null; } public void setJudet( JudetDef judetDef ) { try { Session session = HibernateContext.getSession( hibernateFactoryJNDIName ); session.saveOrUpdate( judetDef ); } catch ( HibernateException e ) { } } } 4. Hibernate SAR Jboss-service.xml <?xml version="1.0" encoding="UTF-8"?> <!DOCTYPE server> <server> <mbean code="net.sf.hibernate.jmx.HibernateService" name="jboss.jca:service=Hibernate"> <depends>jboss.jca:service=RARDeployer</depends> <attribute name="MapResources">ro/siveco/bdne/model/nomenclatoare/JudetDef.hbm.xml</attribute> <attribute name="JndiName">java:/hibernate/HibernateFactory</attribute> <attribute name="Datasource">java:/BDNEDS</attribute> <attribute name="Dialect">net.sf.hibernate.dialect.OracleDialect</attribute> <attribute name="UseOuterJoin">true</attribute> <attribute name="ShowSql">true</attribute> <attribute name="UserTransactionName">UserTransaction</attribute> <attribute name="TransactionStrategy">net.sf.hibernate.transaction.JTATransactionFactory</attribute> <attribute name="TransactionManagerLookupStrategy">net.sf.hibernate.transaction.JBossTransactionManagerLookup</attribute> <attribute name="CacheProvider">net.sf.hibernate.cache.TreeCacheProvider</attribute> <attribute name="UseQueryCache">true</attribute> </mbean> </server> treecache.xml <?xml version="1.0" encoding="UTF-8"?> <server> <classpath codebase="./lib" archives="jboss-cache.jar, jgroups.jar"/> <mbean code="org.jboss.cache.TreeCache" name="jboss.cache:service=TreeCache"> <depends>jboss:service=Naming</depends> <depends>jboss:service=TransactionManager</depends> <attribute name="TransactionManagerLookupClass">org.jboss.cache.DummyTransactionManagerLookup</attribute> <attribute name="IsolationLevel">REPEATABLE_READ</attribute> <attribute name="CacheMode">LOCAL</attribute> <attribute name="MaxCapacity">20000</attribute> <attribute name="InitialStateRetrievalTimeout">20000</attribute> <attribute name="SyncReplTimeout">10000</attribute> <attribute name="LockAcquisitionTimeout">15000</attribute> <attribute name="LockLeaseTimeout">60000</attribute> <attribute name="EvictionPolicyClass"></attribute> </mbean> </server> JudetDef.hbm.xml <?xml version="1.0" encoding="UTF-8"?> <!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 2.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd"> <hibernate-mapping > <class name="ro.siveco.bdne.model.nomenclatoare.JudetDef" table="NOM_JUDET" dynamic-update="false" dynamic-insert="false" select-before-update="false" optimistic-lock="version" > <cache usage="transactional" /> <id name="idNomenclator" column="ID_JUDET" type="java.lang.Long" > <generator class="sequence"> <param name="sequence">NOM_JUDET_SEQ</param> <!-- To add non XDoclet generator parameters, create a file named hibernate-generator-params-JudetDef.xml containing the additional parameters and place it in your merge dir. --> </generator> </id> <property name="cod" type="java.lang.String" update="true" insert="true" access="property" column="COD" length="2" not-null="true" /> <property name="codNumeric" type="java.lang.Long" update="true" insert="true" access="property" column="COD_NUMERIC" length="2" not-null="true" /> <property name="denumire" type="java.lang.String" update="true" insert="true" access="property" column="DENUMIRE" length="50" not-null="true" /> <property name="deLa" type="java.sql.Timestamp" update="true" insert="true" access="property" column="DE_LA" length="11" not-null="true" /> <property name="panaLa" type="java.sql.Timestamp" update="true" insert="true" access="property" column="PANA_LA" length="11" /> <!-- To add non XDoclet property mappings, create a file named hibernate-properties-JudetDef.xml containing the additional properties and place it in your merge dir. --> </class> </hibernate-mapping> This is the test case. If you need further information do not hesitate to contact me at "catalinsanda@siveco.ro"

    Hibernate JIRA | 1 decade ago | Catalin Sanda
    net.sf.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4
  4. Speed up your debug routine!

    Automated exception search integrated into your IDE

  5. 0

    Using JBOSS optimistic tree cache and Websphere 6.1.0.13 (Object Relational Mapping forum at JavaRanch)

    coderanch.com | 11 months ago
    org.jboss.cache.lock.TimeoutException: write lock for / could not be acquired after 15000 ms. Locks: Read lock owners: {} Write lock owner: GlobalTransaction:<null>:1 (caller=GlobalTransaction:<null>:2, lock info: write owner=GlobalTransaction:<null>:1 (activeReaders=0, activeWriter=Thread[QTMSessionPool,5,], waitingReaders=0, waitingWriters=1, waitingUpgrader=0))) at org.jboss.cache.interceptors.TxInterceptor$LocalSynchronizationHandler.beforeCompletion( TxInterceptor.java:1022) at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynch ronizationHandler.java:72) at com.ibm.ws.Transaction.JTA.RegisteredSyncs.distributeBefore(RegisteredSyncs.java:242) at com.ibm.ws.Transaction.JTA.TransactionImpl.prePrepare(TransactionImpl.java:2389) at com.ibm.ws.Transaction.JTA.TransactionImpl.stage1CommitProcessing(TransactionImpl.java:1 622) at com.ibm.ws.Transaction.JTA.TransactionImpl.processCommit(TransactionImpl.java:1593)
  6. 0

    Cache locking issue after one node of the clust... | JBoss Developer

    jboss.org | 11 months ago
    org.jboss.cache.lock.TimeoutException: read lock for /zcapitalspreads_ear,services_jar,capital_spreads/com/chaucerdigital/capitalspreads/account could not be acquired by Thread[main,5,jboss] after 15000 ms. Locks: Read lock owners: [] Write lock owner: GlobalTransaction:<10.0.0.23:3336>:40235 , lock info: write owner=GlobalTransaction:<10.0.0.23:3336>:40235 (activeReaders=0, activeWriter=Thread[Multiplexer,udp,10.0.0.24:1723,10,MultiplexerThreads], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)

    Not finding the right solution?
    Take a tour to get the most out of Samebug.

    Tired of useless tips?

    Automated exception search integrated into your IDE

    Root Cause Analysis

    1. org.jboss.cache.lock.TimeoutException

      lock could not be acquired after 15000 ms. Lock map ownership Read lock owners: [] Write lock owner: <null>:4

      at org.jboss.cache.lock.IdentityLock.acquireWriteLock()
    2. org.jboss.cache
      TreeCache._put
      1. org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:146)
      2. org.jboss.cache.Node.acquireWriteLock(Node.java:422)
      3. org.jboss.cache.Node.acquire(Node.java:388)
      4. org.jboss.cache.TreeCache.findNode(TreeCache.java:3284)
      5. org.jboss.cache.TreeCache._put(TreeCache.java:2335)
      5 frames
    3. Java RT
      Method.invoke
      1. sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      2. sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      3. sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      4. java.lang.reflect.Method.invoke(Method.java:324)
      4 frames
    4. JGroups
      MethodCall.invoke
      1. org.jgroups.blocks.MethodCall.invoke(MethodCall.java:236)
      1 frame
    5. org.jboss.cache
      TreeCache.put
      1. org.jboss.cache.interceptors.CallInterceptor.invoke(CallInterceptor.java:14)
      2. org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:39)
      3. org.jboss.cache.interceptors.TransactionInterceptor.invoke(TransactionInterceptor.java:53)
      4. org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:3171)
      5. org.jboss.cache.TreeCache.put(TreeCache.java:1735)
      5 frames
    6. net.sf.hibernate
      SessionImpl.flush
      1. net.sf.hibernate.cache.TreeCache.put(TreeCache.java:67)
      2. net.sf.hibernate.cache.UpdateTimestampsCache.preinvalidate(UpdateTimestampsCache.java:42)
      3. net.sf.hibernate.impl.SessionImpl.executeAll(SessionImpl.java:2413)
      4. net.sf.hibernate.impl.SessionImpl.execute(SessionImpl.java:2368)
      5. net.sf.hibernate.impl.SessionImpl.flush(SessionImpl.java:2236)
      5 frames
    7. org.jboss.hibernate
      TransactionSynch.beforeCompletion
      1. org.jboss.hibernate.session.TransactionSynch.beforeCompletion(Unknown Source)
      1 frame
    8. JBoss Transaction 7.1.0 SPI
      TransactionImpl.commit
      1. org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:1383)
      2. org.jboss.tm.TransactionImpl.beforePrepare(TransactionImpl.java:1075)
      3. org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:296)
      3 frames
    9. JBoss Application Server Server
      Container.invoke
      1. org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:457)
      2. org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:325)
      3. org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:149)
      4. org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:128)
      5. org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
      6. org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
      7. org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624)
      8. org.jboss.ejb.Container.invoke(Container.java:854)
      8 frames
    10. Java RT
      Method.invoke
      1. sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      2. sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      3. sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      4. java.lang.reflect.Method.invoke(Method.java:324)
      4 frames
    11. org.jboss.mx
      ReflectedDispatcher.invoke
      1. org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:141)
      1 frame
    12. JBoss Application Server J2SE
      MBeanServerImpl.invoke
      1. org.jboss.mx.server.Invocation.dispatch(Invocation.java:80)
      2. org.jboss.mx.server.Invocation.invoke(Invocation.java:72)
      3. org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:242)
      4. org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:642)
      4 frames
    13. JBoss Application Server Server
      JRMPInvoker.invoke
      1. org.jboss.invocation.jrmp.server.JRMPInvoker$MBeanServerAction.invoke(JRMPInvoker.java:775)
      2. org.jboss.invocation.jrmp.server.JRMPInvoker.invoke(JRMPInvoker.java:382)
      2 frames
    14. Java RT
      Thread.run
      1. sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      2. sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      3. sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      4. java.lang.reflect.Method.invoke(Method.java:324)
      5. sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:261)
      6. sun.rmi.transport.Transport$1.run(Transport.java:148)
      7. java.security.AccessController.doPrivileged(Native Method)
      8. sun.rmi.transport.Transport.serviceCall(Transport.java:144)
      9. sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:460)
      10. sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:701)
      11. java.lang.Thread.run(Thread.java:534)
      11 frames