Hi, please could anyone give me a hint with this? I've tried seemingly every
combination of configuration, and can't get past this lock timeout.
After committing a transaction containing a single UPDATE statement, Hibernate's
CacheSynchronization.afterCompletion tries to evict the entire entity region. This goes
through JBossCache's removeAll, where the lock timeout occurs.
org.jboss.cache.lock.TimeoutException: Unable to acquire lock on Fqn [/com/foo/Bar/ENTITY]
after [10000] milliseconds for requestor [Thread[main,5,main]]! Lock held by
[GlobalTransaction::2]
Here is the Hibernate/JBossCache trace leading up to the lock timeout. It shows
Hibernate's CacheSynchronization beforeCompletion callback and afterCompletion
callback. You can see that the transaction is null in afterCompletion (makes sense since
it's completed at that point), yet Hibernate is writing to JBossCache anyway. It seems
to update the timestamps cache successfully before deadlocking on the entity region
eviction:
09-02-25 22:41:10,888 TRACE [org.hibernate.transaction.CacheSynchronization] -
<transaction before completion callback>
2009-02-25 22:41:10,889 TRACE [org.jboss.cache.interceptors.TxInterceptor] - <Running
beforeCompletion on gtx GlobalTransaction::2>
2009-02-25 22:41:10,889 TRACE [org.jboss.cache.interceptors.TxInterceptor] - <Setting
up transactional context.>
2009-02-25 22:41:10,889 TRACE [org.jboss.cache.interceptors.TxInterceptor] - <Setting
tx as tx0000200056 and gtx as GlobalTransaction::2>
2009-02-25 22:41:10,889 TRACE [org.jboss.cache.interceptors.TxInterceptor] - <Setting
up transactional context.>
2009-02-25 22:41:10,889 TRACE [org.jboss.cache.interceptors.TxInterceptor] - <Setting
tx as tx0000200056 and gtx as GlobalTransaction::2>
2009-02-25 22:41:10,889 TRACE [org.jboss.cache.interceptors.CallInterceptor] -
<Suppressing invocation of method handlePrepareCommand.>
2009-02-25 22:41:10,889 TRACE [org.jboss.cache.interceptors.MVCCLockingInterceptor] -
<Nothing to do since there is a transaction in scope.>
2009-02-25 22:41:10,889 TRACE [org.jboss.cache.interceptors.TxInterceptor] - <Setting
up transactional context.>
2009-02-25 22:41:10,889 TRACE [org.jboss.cache.interceptors.TxInterceptor] - <Setting
tx as null and gtx as null>
2009-02-25 22:41:10,904 TRACE [org.hibernate.transaction.CacheSynchronization] -
<transaction after completion callback, status: 3>
2009-02-25 22:41:10,905 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor]
- <Invoked with command RemoveNodeCommand{fqn=/com/foo/Bar/ENTITY, dataVersion=null,
globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null} and
InvocationContext [InvocationContext{transaction=null, globalTransaction=null,
transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false,
dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1,
forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false,
forceSynchronous=false, suppressPersistence=false, suppressEventNotification=false},
originLocal=true}]>
2009-02-25 22:41:10,905 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor]
- <Setting up transactional context.>
2009-02-25 22:41:10,905 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor]
- <Setting tx as null and gtx as null>
2009-02-25 22:41:10,905 TRACE [org.jboss.cache.lock.MVCCLockManager] - <Attempting to
lock /com/foo/Bar/ENTITY>
2009-02-25 22:41:20,906 TRACE [org.jboss.cache.interceptors.MVCCLockingInterceptor] -
<Nothing to do since there are no modifications in scope.>
2009-02-25 22:41:20,907 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor]
- <Resetting invocation-scope options>
2009-02-25 22:41:20,907 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor]
- <Invoked with command
PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/bars,
dataVersion=null, globalTransaction=null, key=item, value=12356196809} and
InvocationContext [InvocationContext{transaction=null, globalTransaction=null,
transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false,
dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1,
forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=true,
forceSynchronous=false, suppressPersistence=false, suppressEventNotification=false},
originLocal=true}]>
2009-02-25 22:41:20,907 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor]
- <Setting up transactional context.>
2009-02-25 22:41:20,907 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor]
- <Setting tx as null and gtx as null>
2009-02-25 22:41:20,907 TRACE [org.jboss.cache.lock.MVCCLockManager] - <Attempting to
lock /TS/org/hibernate/cache/UpdateTimestampsCache/bars>
2009-02-25 22:41:20,908 TRACE [org.jboss.cache.interceptors.MVCCLockingInterceptor] -
<Releasing lock on [/TS/org/hibernate/cache/UpdateTimestampsCache/bars] for owner
Thread[main,5,main]>
2009-02-25 22:41:20,908 TRACE [org.jboss.cache.lock.MVCCLockManager] - <Attempting to
unlock /TS/org/hibernate/cache/UpdateTimestampsCache/bars>
2009-02-25 22:41:20,908 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor]
- <Resetting invocation-scope options>
2009-02-25 22:41:20,910 ERROR [org.hibernate.engine.ActionQueue] - <could not release a
cache lock>
org.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: Unable to
acquire lock on Fqn [/com/foo/Bar/ENTITY] after [10000] milliseconds for requestor
[Thread[main,5,main]]! Lock held by [GlobalTransaction::2]
Any help is greatly appreciated. I can dig in more if I just know where to look...
View the original post :
http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4213233#...
Reply to the post :
http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&a...