[JBoss Cache: Core Edition] - Endless loop trying to obtain lock in 1.4.1.SP9 - jboss-user

Wednesday, 13 August 2008

Hi,

I've been trying to work around this problem but nothing I do seems to fix it. 
We're using jboss cache as hibernate's second level cache and have problems where
in predicatble behaviours in our application, the cache appears to go into an infinate
loop trying to lock an entity it already has a lock on.

I can provide full logging output, but it's quite large, and I can't attach it as
a file - however I've included two samples from the logs.  The first is a grep through
our logs for the key of that seems to be causing the problem "PeerOrgCode#4". 
The second is a full sample of the endless loop that is repeated in our logs forever.

Please, if anyone can suggest a solution or work around, I really need to get this
working. Thanks.

anonymous wrote : 
  | 2008-08-14 11:33:26,948 DEBUG [org.hibernate.loader.Loader] result row:
EntityKey[com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:26,948 TRACE [org.hibernate.loader.Loader] Initializing object from
ResultSet: [com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:26,948 TRACE [org.hibernate.persister.entity.AbstractEntityPersister]
Hydrating entity: [com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:27,010 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving
associations for [com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:27,057 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to
second-level cache: [com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:27,057 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call
on method [_get;
id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, true)]
  | 2008-08-14 11:33:27,057 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor
invoked for method _get;
id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, true)
  | 2008-08-14 11:33:27,057 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner GlobalTransaction::12
  | 2008-08-14 11:33:27,073 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] failed to find or create child
com.synyati.spurwing.security.entity.PeerOrgCode#4 of node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.interceptors.CallInterceptor] Invoking
method _get;
id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, true) on cache.
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.TreeCache]
_get("/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4",
item, "true")
  | 2008-08-14 11:33:27,073 DEBUG [org.hibernate.cache.TransactionalCache] caching:
com.synyati.spurwing.security.entity.PeerOrgCode#4
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call
on method [_put; id:4(null,
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, CacheEntry(com.synyati.spurwing.security.entity.PeerOrgCode)[1,true,2006-01-01
00:00:00.0,1,null,null,NTH,5,4,0], true, 0)]
  | 2008-08-14 11:33:27,073 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor
invoked for method _put; id:4(null,
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, CacheEntry(com.synyati.spurwing.security.entity.PeerOrgCode)[1,true,2006-01-01
00:00:00.0,1,null,null,NTH,5,4,0], true, 0)
  | 2008-08-14 11:33:27,073 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.Node] created child:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=write
owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.interceptors.CallInterceptor] Invoking
method _put; id:4(null,
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, CacheEntry(com.synyati.spurwing.security.entity.PeerOrgCode)[1,true,2006-01-01
00:00:00.0,1,null,null,NTH,5,4,0], true, 0) on cache.
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.TreeCache] _put(null,
"/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4",
item, CacheEntry(com.synyati.spurwing.security.entity.PeerOrgCode)[1,true,2006-01-01
00:00:00.0,1,null,null,NTH,5,4,0])
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.interceptors.EvictionInterceptor]
Adding event
EvictedEN[fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
event=3 diff=1] to region at /_default_/
  | 2008-08-14 11:33:27,073 TRACE [org.jboss.cache.interceptors.UnlockInterceptor]
releasing lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4:
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:27,073 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing
entity [com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:28,291 DEBUG [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding
element
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for a node that doesn't exist yet. Process as an add.
  | 2008-08-14 11:33:28,291 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding
node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
with 1 elements to eviction queue
  | 2008-08-14 11:33:28,291 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm]
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
added successfully to eviction queue
  | 2008-08-14 11:33:39,604 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=GlobalTransaction::14, lock=
  | 2008-08-14 11:33:39,604 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=GlobalTransaction::14, lock=write owner=GlobalTransaction::14
  | 2008-08-14 11:33:39,729 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=GlobalTransaction::14, lock=write owner=GlobalTransaction::14
  | 2008-08-14 11:33:39,729 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock():
caller already owns lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
(caller=GlobalTransaction::14)
  | 2008-08-14 11:33:39,729 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=GlobalTransaction::14, lock=write owner=GlobalTransaction::14
  | 2008-08-14 11:33:40,604 TRACE [org.jboss.cache.TransactionEntry] releasing lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
(write owner=GlobalTransaction::14)
  | 2008-08-14 11:33:49,620 DEBUG [org.hibernate.loader.Loader] result row:
EntityKey[com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:49,620 TRACE [org.hibernate.loader.Loader] Initializing object from
ResultSet: [com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:49,620 TRACE [org.hibernate.persister.entity.AbstractEntityPersister]
Hydrating entity: [com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:49,698 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving
associations for [com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:49,745 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to
second-level cache: [com.synyati.spurwing.security.entity.PeerOrgCode#4]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call
on method [_get;
id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, true)]
  | 2008-08-14 11:33:49,745 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor
invoked for method _get;
id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, true)
  | 2008-08-14 11:33:49,745 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner GlobalTransaction::15
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=GlobalTransaction::15, lock=
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=GlobalTransaction::15, lock=read owners=[GlobalTransaction::15]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.interceptors.CallInterceptor] Invoking
method _get;
id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, true) on cache.
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.TreeCache]
_get("/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4",
item, "true")
  | 2008-08-14 11:33:49,745 DEBUG [org.hibernate.cache.TransactionalCache] caching:
com.synyati.spurwing.security.entity.PeerOrgCode#4
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call
on method [_put; id:4(null,
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, CacheEntry(com.synyati.spurwing.security.entity.PeerOrgCode)[1,true,2006-01-01
00:00:00.0,1,null,null,NTH,5,4,0], true, 0)]
  | 2008-08-14 11:33:49,745 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor
invoked for method _put; id:4(null,
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
item, CacheEntry(com.synyati.spurwing.security.entity.PeerOrgCode)[1,true,2006-01-01
00:00:00.0,1,null,null,NTH,5,4,0], true, 0)
  | 2008-08-14 11:33:49,745 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock():
caller already owns lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
(caller=Thread[http-127.0.0.1-8080-1,5,jboss])
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock():
caller already owns lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
(caller=Thread[http-127.0.0.1-8080-1,5,jboss])
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock():
caller already owns lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
(caller=Thread[http-127.0.0.1-8080-1,5,jboss])
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock():
caller already owns lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
(caller=Thread[http-127.0.0.1-8080-1,5,jboss])
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock():
caller already owns lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
(caller=Thread[http-127.0.0.1-8080-1,5,jboss])
  | 2008-08-14 11:33:49,745 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 

anonymous wrote : 
  | 2008-08-14 11:33:51,760 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL: fqn=/,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock():
caller already owns lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode
(caller=Thread[http-127.0.0.1-8080-1,5,jboss])
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock():
caller already owns lock for
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
(caller=Thread[http-127.0.0.1-8080-1,5,jboss])
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired WL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15],
write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:51,760 TRACE
[org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node
/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode/com.synyati.spurwing.security.entity.PeerOrgCode#4
for owner Thread[http-127.0.0.1-8080-1,5,jboss]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL: fqn=/,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquired RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jboss]]
  | 2008-08-14 11:33:51,760 TRACE [org.jboss.cache.Node] acquiring RL:
fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security,
caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::15,
Thread[http-127.0.0.1-8080-1,5,jbo
  | 

View the original post :
http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4170468#...

Reply to the post :
http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&a...

2026

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

[JBoss Cache: Core Edition] - Endless loop trying to obtain lock in 1.4.1.SP9