[jboss-user] [JBossCache] - Re: long wait when cache is started

gmeroz do-not-reply at jboss.com
Thu Mar 1 16:37:38 EST 2007


I use standard Jboss data source for pooling connections.

I noticed it's not always take that long. i still didn't feagure out the reason. We have several developers sharing a DB, so i'm not always aware about all changes in DB - it may happen when one AS start while another is during the process of initializing the cache. This senario won't happen in production. I'll investigate it.

I'll give the current trace, hoping it would help. If i'll have a better senario, i'll add the relevant log as well.

The log was very big, so i'll skip some in the middle:

  | 2007-03-01 23:08:49,489 INFO [org.jboss.cache.factories.InterceptorChainFactory] interceptor chain is:
  | class org.jboss.cache.interceptors.CallInterceptor
  | class org.jboss.cache.interceptors.PessimisticLockInterceptor
  | class org.jboss.cache.interceptors.CacheLoaderInterceptor
  | class org.jboss.cache.interceptors.UnlockInterceptor
  | class org.jboss.cache.interceptors.CacheStoreInterceptor
  | class org.jboss.cache.interceptors.NotificationInterceptor
  | class org.jboss.cache.interceptors.TxInterceptor
  | class org.jboss.cache.interceptors.CacheMgmtInterceptor
  | class org.jboss.cache.interceptors.InvocationContextInterceptor
  | 2007-03-01 23:08:51,067 DEBUG [org.jboss.cache.loader.CacheLoaderManager] preloading transient state from cache loader org.jboss.cache.loader.JDBCCacheLoader at 14ea4a2
  | 2007-03-01 23:08:51,067 DEBUG [org.jboss.cache.loader.CacheLoaderManager] preloading /
  | 2007-03-01 23:08:51,129 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:08:51,129 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:08:51,129 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as null
  | 2007-03-01 23:08:51,129 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/, bla, true)]
  | 2007-03-01 23:08:51,129 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 2007-03-01 23:08:51,129 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is null
  | 2007-03-01 23:08:51,129 DEBUG [org.jboss.cache.CacheImpl] created new GTX: GlobalTransaction:<null>:1, local TX=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16]
  | 2007-03-01 23:08:51,129 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Registering sync handler for tx TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], gtx GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:1, tx=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16]))
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] CacheStoreInterceptor called with meth MethodName: _get; MethodIdInteger: 26; Args: (/, bla, true)
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _get; MethodIdInteger: 26; Args: (/, bla, true)
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] must Load, uninitialized
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element / mustLoad=true
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache_application where fqn=? (/)
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists false
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] Setting dataLoaded to true
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/, WRITE, false)
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node / for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/, bla, true)
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node / for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/, bla, true) so it gets invoked on cache.
  | 2007-03-01 23:08:51,145 DEBUG [org.jboss.cache.CacheImpl] _get("/", "bla", "true")
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.NotificationInterceptor] Adding [] to transaction entry's notification list
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select fqn from jbosscache_application where parent=? (/)
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], globalTransaction=GlobalTransaction:<null>:1, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__, bla, true)]
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] is already registered.
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] CacheStoreInterceptor called with meth MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__, bla, true)
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__, bla, true)
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] mustLoad, node null
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /__JBossInternal__ mustLoad=true
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /__JBossInternal__
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache_application where fqn=? (/__JBossInternal__)
  | 2007-03-01 23:08:51,161 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists true
  | 2007-03-01 23:08:51,176 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] Node data is not null, loading
  | 2007-03-01 23:08:51,176 DEBUG [org.jboss.cache.UnversionedNode] created child: fqn=/__JBossInternal__
  | 2007-03-01 23:08:51,176 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/__JBossInternal__, WRITE, false)
  | 2007-03-01 23:08:51,176 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__ for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=<unlocked>
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=<unlocked>
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__, bla, true)
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__ for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__, bla, true) so it gets invoked on cache.
  | 2007-03-01 23:08:51,270 DEBUG [org.jboss.cache.CacheImpl] _get("/__JBossInternal__", "bla", "true")
  | 2007-03-01 23:08:51,286 DEBUG [org.jboss.cache.interceptors.NotificationInterceptor] Adding [] to transaction entry's notification list
  | 2007-03-01 23:08:51,286 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
  | 2007-03-01 23:08:51,286 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select fqn from jbosscache_application where parent=? (/__JBossInternal__)
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], globalTransaction=GlobalTransaction:<null>:1, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, bla, true)]
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] is already registered.
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] CacheStoreInterceptor called with meth MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, bla, true)
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, bla, true)
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] mustLoad, node null
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a mustLoad=true
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a
  | 2007-03-01 23:08:51,317 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache_application where fqn=? (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a)
  | 2007-03-01 23:08:51,379 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists true
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] Node data is not null, loading
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.UnversionedNode] created child: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, WRITE, false)
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, caller=GlobalTransaction:<null>:1, lock=<unlocked>
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, bla, true)
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a, bla, true) so it gets invoked on cache.
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.CacheImpl] _get("/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a", "bla", "true")
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.interceptors.NotificationInterceptor] Adding [] to transaction entry's notification list
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
  | 2007-03-01 23:08:51,489 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select fqn from jbosscache_application where parent=? (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrojzhn-a)
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], globalTransaction=GlobalTransaction:<null>:1, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, bla, true)]
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is GlobalTransaction:<null>:1
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] is already registered.
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] CacheStoreInterceptor called with meth MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, bla, true)
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, bla, true)
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] mustLoad, node null
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61 mustLoad=true
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61
  | 2007-03-01 23:08:51,520 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache_application where fqn=? (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61)
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists true
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] Node data is not null, loading
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.UnversionedNode] created child: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, WRITE, false)
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61 for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,348 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, caller=GlobalTransaction:<null>:1, lock=<unlocked>
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, bla, true)
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61 for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61, bla, true) so it gets invoked on cache.
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.CacheImpl] _get("/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61", "bla", "true")
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.NotificationInterceptor] Adding [] to transaction entry's notification list
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select fqn from jbosscache_application where parent=? (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftuca-61)
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], globalTransaction=GlobalTransaction:<null>:1, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, bla, true)]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] is already registered.
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] CacheStoreInterceptor called with meth MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, bla, true)
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, bla, true)
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] mustLoad, node null
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e mustLoad=true
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e
  | 2007-03-01 23:08:52,364 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache_application where fqn=? (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e)
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists true
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] Node data is not null, loading
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.UnversionedNode] created child: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, WRITE, false)
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, caller=GlobalTransaction:<null>:1, lock=<unlocked>
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, bla, true)
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e, bla, true) so it gets invoked on cache.
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.CacheImpl] _get("/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e", "bla", "true")
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.NotificationInterceptor] Adding [] to transaction entry's notification list
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select fqn from jbosscache_application where parent=? (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyrorc4h-5e)
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], globalTransaction=GlobalTransaction:<null>:1, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, bla, true)]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] is already registered.
  | 2007-03-01 23:08:52,395 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] CacheStoreInterceptor called with meth MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, bla, true)
  | 2007-03-01 23:08:52,411 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
  | 2007-03-01 23:08:52,411 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, bla, true)
  | 2007-03-01 23:08:52,411 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] mustLoad, node null
  | 2007-03-01 23:08:52,411 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60 mustLoad=true
  | 2007-03-01 23:08:52,411 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60
  | 2007-03-01 23:08:52,411 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache_application where fqn=? (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60)
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists true
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] Node data is not null, loading
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.UnversionedNode] created child: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, WRITE, false)
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60 for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, caller=GlobalTransaction:<null>:1, lock=<unlocked>
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, bla, true)
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60 for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60, bla, true) so it gets invoked on cache.
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.CacheImpl] _get("/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60", "bla", "true")
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.interceptors.NotificationInterceptor] Adding [] to transaction entry's notification list
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
  | 2007-03-01 23:08:52,426 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select fqn from jbosscache_application where parent=? (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrftubf-60)
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], globalTransaction=GlobalTransaction:<null>:1, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, bla, true)]
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] is already registered.
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] CacheStoreInterceptor called with meth MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, bla, true)
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, bla, true)
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] mustLoad, node null
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w mustLoad=true
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache_application where fqn=? (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w)
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists true
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] Node data is not null, loading
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.UnversionedNode] created child: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, WRITE, false)
  | 2007-03-01 23:08:52,442 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, caller=GlobalTransaction:<null>:1, lock=<unlocked>
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, bla, true)
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w, bla, true) so it gets invoked on cache.
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.CacheImpl] _get("/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w", "bla", "true")
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.NotificationInterceptor] Adding [] to transaction entry's notification list
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select fqn from jbosscache_application where parent=? (/__JBossInternal__/5c4oa2y-64ssue-eyro7iw5-1-eyroreif-5w)
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], globalTransaction=GlobalTransaction:<null>:1, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as GlobalTransaction:<null>:1
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/__JBossInternal__/5c4oa2y-4fydgh-eyrfhgzk-1-eyrg9460-fw, bla, true)]
  | 2007-03-01 23:08:52,458 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 
  | ...
  | ...
  | ... skip a lot of lines
  | ...
  | ...
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag/queries, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag/queries, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1, bla, true) so it gets invoked on cache.
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.CacheImpl] _get("/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1", "bla", "true")
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.interceptors.NotificationInterceptor] Adding [] to transaction entry's notification list
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
  | 2007-03-01 23:09:15,662 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select fqn from jbosscache_application where parent=? (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], globalTransaction=GlobalTransaction:<null>:1, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as GlobalTransaction:<null>:1
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, bla, true)]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is GlobalTransaction:<null>:1
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] is already registered.
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] CacheStoreInterceptor called with meth MethodName: _get; MethodIdInteger: 26; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, bla, true)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _get; MethodIdInteger: 26; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, bla, true)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] mustLoad, node null
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11 mustLoad=true
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache_application where fqn=? (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists true
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] Node data is not null, loading
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.UnversionedNode] created child: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, WRITE, false)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11 for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag/queries, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag/queries, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, caller=GlobalTransaction:<null>:1, lock=<unlocked>
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, bla, true)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11 for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag/queries, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag/queries, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11, bla, true) so it gets invoked on cache.
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.CacheImpl] _get("/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11", "bla", "true")
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.NotificationInterceptor] Adding [] to transaction entry's notification list
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select fqn from jbosscache_application where parent=? (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-6-SIBLINGS_IN_LEVEL-11-11)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{transaction=TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16], globalTransaction=GlobalTransaction:<null>:1, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, bypassInterceptorChain=false}, originLocal=true, txHasMods=false}]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] and gtx as GlobalTransaction:<null>:1
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-7-SIBLINGS_IN_LEVEL-7-7, bla, true)]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.TxInterceptor]  local transaction exists - registering global tx if not present for Thread[main,5,jboss]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is GlobalTransaction:<null>:1
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=gil-pc/16, BranchQual=, localId=16] is already registered.
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] CacheStoreInterceptor called with meth MethodName: _get; MethodIdInteger: 26; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-7-SIBLINGS_IN_LEVEL-7-7, bla, true)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _get; MethodIdInteger: 26; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-7-SIBLINGS_IN_LEVEL-7-7, bla, true)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] mustLoad, node null
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-7-SIBLINGS_IN_LEVEL-7-7 mustLoad=true
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-7-SIBLINGS_IN_LEVEL-7-7
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache_application where fqn=? (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-7-SIBLINGS_IN_LEVEL-7-7)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists true
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.CacheLoaderInterceptor] Node data is not null, loading
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.UnversionedNode] created child: fqn=/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-7-SIBLINGS_IN_LEVEL-7-7
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-7-SIBLINGS_IN_LEVEL-7-7, WRITE, false)
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /aag/queries/d1-2-d2-0-d3-41-d4-1527-d5-0-d6-0-d7-0-d8-84-24-1/queryDefinition3-7-SIBLINGS_IN_LEVEL-7-7 for owner GlobalTransaction:<null>:1
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquired RL: fqn=/aag, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
  | 2007-03-01 23:09:15,677 DEBUG [org.jboss.cache.lock.IdentityLock] acquiring RL: fqn=/aag/queries, caller=GlobalTransaction:<null>:1, lock=read owners=[Global

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

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



More information about the jboss-user mailing list