[jboss-user] [JBossCache] - Re: Timeout/Lock exception in single user/single thread envi
doubble
do-not-reply at jboss.com
Wed Jan 23 10:24:13 EST 2008
Hi Manik,
enclosed is a big log which hopefully gives you a clue what's going in there when using isolation level REPEATABLE_READ
That's what it says in the end...
Caused by: org.jboss.cache.lock.TimeoutException: write lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01 could not be acquired after 10000 ms. Locks: Read lock owners: [GlobalTransaction::2]
Write lock owner: null
(caller=Thread[http-0.0.0.0-8080-2,5,jboss], lock info: read owners=[GlobalTransaction::2] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:206)
at org.jboss.cache.Node.acquireWriteLock(Node.java:529)
at org.jboss.cache.Node.acquire(Node.java:476)
... 257 more
nearly complete log till excpetion ...
16:18:04,977 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, valueMap, true)]
16:18:04,977 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, valueMap, true)
16:18:04,977 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] failed to find or create child portalSession of node /
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, valueMap, true) on cache.
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", valueMap, "true")
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: valueMap returned:null
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] no valueMap found, creating new one
16:18:05,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] set: valueMap to: {} for session [D44653CF8598B06D8CA8AC86E0619A01]
16:18:11,618 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_put; id:3(null, /portalSession/D44653CF8598B06D8CA8AC86E0619A01, valueMap, {}, true)]
16:18:11,618 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _put; id:3(null, /portalSession/D44653CF8598B06D8CA8AC86E0619A01, valueMap, {}, true)
16:18:11,618 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:11,618 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=
16:18:11,618 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:11,618 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] created child: fqn=/portalSession
16:18:11,618 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=
16:18:11,633 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:11,649 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] created child: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01
16:18:11,649 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring WL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=
16:18:11,649 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired WL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=write owner=Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:18,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _put; id:3(null, /portalSession/D44653CF8598B06D8CA8AC86E0619A01, valueMap, {}, true) on cache.
16:18:18,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _put(null, "/portalSession/D44653CF8598B06D8CA8AC86E0619A01", valueMap, {})
16:18:18,899 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[Thread[http-0.0.0.0-8080-1,5,jboss]], write owner=Thread[http-0.0.0.0-8080-1,5,jboss]]}
16:18:18,899 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: write owner=Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:18,915 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:18,930 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:20,008 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT, NAVIGATION_CONTEXT, true)]
16:18:20,008 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:20,008 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] Associated gtx in txTable is null
16:18:20,008 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] created new GTX: GlobalTransaction::1, local TX=TransactionImpl:XidImpl[FormatId=257, GlobalId=dbn3f84/193, BranchQual=, localId=193]
16:18:20,024 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] Registering sync handler for tx TransactionImpl:XidImpl[FormatId=257, GlobalId=dbn3f84/193, BranchQual=, localId=193], gtx GlobalTransaction::1
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction::1, tx=org.jboss.tm.TransactionImpl at 24841074))
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT, NAVIGATION_CONTEXT, true)
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT for owner GlobalTransaction::1
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=GlobalTransaction::1, lock=
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=GlobalTransaction::1, lock=read owners=[GlobalTransaction::1]
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=GlobalTransaction::1, lock=
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=GlobalTransaction::1, lock=read owners=[GlobalTransaction::1]
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=GlobalTransaction::1, lock=
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=GlobalTransaction::1, lock=read owners=[GlobalTransaction::1]
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] failed to find or create child NAVIGATION_CONTEXT of node /portalSession/D44653CF8598B06D8CA8AC86E0619A01
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT, NAVIGATION_CONTEXT, true) on cache.
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT", NAVIGATION_CONTEXT, "true")
16:18:20,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: NAVIGATION_CONTEXT returned:null
16:18:23,836 [http-0.0.0.0-8080-1] INFO (D44653CF8598B06D8CA8AC86E0619A01) [BspPortalCommandFactory] creating navigation context in global session
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] set: NAVIGATION_CONTEXT to: DefaultNavigationContext[[]] for session [D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT]
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_put; id:3(GlobalTransaction::1, /portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT, NAVIGATION_CONTEXT, DefaultNavigationContext[[]], true)]
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] Associated gtx in txTable is GlobalTransaction::1
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=dbn3f84/193, BranchQual=, localId=193] is already registered.
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _put; id:3(GlobalTransaction::1, /portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT, NAVIGATION_CONTEXT, DefaultNavigationContext[[]], true)
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT for owner GlobalTransaction::1
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=GlobalTransaction::1, lock=read owners=[GlobalTransaction::1]
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [IdentityLock] acquireReadLock(): caller GlobalTransaction::1 already owns lock for /
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=GlobalTransaction::1, lock=read owners=[GlobalTransaction::1]
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=GlobalTransaction::1, lock=read owners=[GlobalTransaction::1]
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [IdentityLock] acquireReadLock(): caller GlobalTransaction::1 already owns lock for /portalSession
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=GlobalTransaction::1, lock=read owners=[GlobalTransaction::1]
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=GlobalTransaction::1, lock=read owners=[GlobalTransaction::1]
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [IdentityLock] acquireReadLock(): caller GlobalTransaction::1 already owns lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=GlobalTransaction::1, lock=read owners=[GlobalTransaction::1]
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] created child: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring WL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT, caller=GlobalTransaction::1, lock=
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired WL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT, caller=GlobalTransaction::1, lock=write owner=GlobalTransaction::1
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _put; id:3(GlobalTransaction::1, /portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT, NAVIGATION_CONTEXT, DefaultNavigationContext[[]], true) on cache.
16:18:23,883 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _put(GlobalTransaction::1, "/portalSession/D44653CF8598B06D8CA8AC86E0619A01/NAVIGATION_CONTEXT", NAVIGATION_CONTEXT, DefaultNavigationContext[[]])
16:18:23,883 [http-0.0.0.0-8080-1] INFO (D44653CF8598B06D8CA8AC86E0619A01) [BspPortalCommandFactory] Sending Command to Prozess 0.
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true)]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true)
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true) on cache.
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", navigationEvent, "true")
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,493 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,524 [http-0.0.0.0-8080-1] INFO (D44653CF8598B06D8CA8AC86E0619A01) [RvpSessionListener] sessionCreated
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true)]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true)
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true) on cache.
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", navigationEvent, "true")
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:24,571 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,165 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationPath, true)]
16:18:27,165 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationPath, true)
16:18:27,165 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:27,165 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationPath, true) on cache.
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", navigationPath, "true")
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,196 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: navigationPath returned:null
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, MEA_EXCEPTION, true)]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, MEA_EXCEPTION, true)
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, MEA_EXCEPTION, true) on cache.
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", MEA_EXCEPTION, "true")
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,368 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: MEA_EXCEPTION returned:null
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true)]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true)
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true) on cache.
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", navigationEvent, "true")
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true)]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true)
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, navigationEvent, true) on cache.
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", navigationEvent, "true")
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,477 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true) on cache.
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", preview, "true")
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: preview returned:null
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true) on cache.
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", preview, "true")
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:27,680 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: preview returned:null
16:18:29,258 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)]
16:18:29,258 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)
16:18:29,258 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:29,258 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:29,258 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,274 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:29,274 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true) on cache.
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", preview, "true")
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: preview returned:null
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true) on cache.
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", preview, "true")
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:29,290 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: preview returned:null
16:18:29,352 [http-0.0.0.0-8080-1] INFO (D44653CF8598B06D8CA8AC86E0619A01) [RvpRefreshBean] startRefresh
16:18:29,352 [http-0.0.0.0-8080-1] INFO (D44653CF8598B06D8CA8AC86E0619A01) [RvpRefreshBean] first call, trying to schedule RVP refresh
16:18:29,352 [http-0.0.0.0-8080-1] INFO (D44653CF8598B06D8CA8AC86E0619A01) [RvpRefreshBean] account is federated, RVP refresh needed
16:18:29,368 [http-0.0.0.0-8080-1] INFO (D44653CF8598B06D8CA8AC86E0619A01) [RvpRefreshBean] RVP-Refresher scheduled. First callTime=2008-01-23 16:32:29.352+0100 interval=14min
16:18:30,399 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)]
16:18:30,399 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)
16:18:30,399 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:30,399 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:30,415 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true) on cache.
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", preview, "true")
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: preview returned:null
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true) on cache.
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", preview, "true")
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:30,430 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: preview returned:null
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true) on cache.
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", preview, "true")
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,040 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [GlobalSession] get: preview returned:null
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TxInterceptor] (null) call on method [_get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)]
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true)
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [PessimisticLockInterceptor] Attempting to lock node /portalSession/D44653CF8598B06D8CA8AC86E0619A01 for owner Thread[http-0.0.0.0-8080-1,5,jboss]
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquiring RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1]
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [Node] acquired RL: fqn=/portalSession/D44653CF8598B06D8CA8AC86E0619A01, caller=Thread[http-0.0.0.0-8080-1,5,jboss], lock=read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [CallInterceptor] Invoking method _get; id:26(/portalSession/D44653CF8598B06D8CA8AC86E0619A01, preview, true) on cache.
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [TreeCache] _get("/portalSession/D44653CF8598B06D8CA8AC86E0619A01", preview, "true")
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] Attempting to release locks on current thread. Lock table is {Thread[http-0.0.0.0-8080-1,5,jboss]=[read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]], read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]]}
16:18:31,055 [http-0.0.0.0-8080-1] DEBUG (D44653CF8598B06D8CA8AC86E0619A01) [UnlockInterceptor] releasing lock for /portalSession/D44653CF8598B06D8CA8AC86E0619A01: read owners=[GlobalTransaction::1, Thread[http-0.0.0.0-8080-1,5,jboss]]
16:18:31,055
View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4122672#4122672
Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4122672
More information about the jboss-user
mailing list