-
1. Re: Passivation false problem
manik Jun 26, 2008 6:27 AM (in response to rachna_agg)The ActivationInterceptor *is* associated with passivation being set to true.
The ActivationInterceptor is a subclass of the CacheLoaderInterceptor, which should be present and should be recording loading of objects from the DB.
The only difference between the ActivationInterceptor and the CacheLoaderInterceptor is that the AI will *remove* objects from the DB if it is loaded from memory, while the CLI *just* loads stuff into memory if needed. -
2. Re: Passivation false problem
rachna_agg Jun 26, 2008 7:12 AM (in response to rachna_agg)Thanks for the reply.
But I think Activation is reading data from the database if it is not found in the memory which is the case even when passivation is set to false. So why Activation is associated with passivation being set to true only and not false?
Also, why the no of "Hits" is always zero even when "CacheLoaderLoads" in "CacheLoaderInterceptor" is increased. Moreover, everytime I retrieve the same record, my no of "Misses" increases" and not "Hits".
Regards,
Rachna -
3. Re: Passivation false problem
manik Jun 26, 2008 7:59 AM (in response to rachna_agg)"rachna_agg" wrote:
But I think Activation is reading data from the database if it is not found in the memory which is the case even when passivation is set to false.
No, that's what the CLI does. The AI just removes it from the DB if it's superclass (the CLI) has loaded it. Have a look at the src code if you don't believe me. ;)"rachna_agg" wrote:
So why Activation is associated with passivation being set to true only and not false?
Because if passivation is false you don't want to remove state from the store when loaded in memory. You only want to do that when passivation is true."rachna_agg" wrote:
Also, why the no of "Hits" is always zero even when "CacheLoaderLoads" in "CacheLoaderInterceptor" is increased. Moreover, everytime I retrieve the same record, my no of "Misses" increases" and not "Hits".
Because for some reason the CLI needs to load state from the store again. Could be because an aggressive eviction policy is removing state from memory before it can be reloaded again. I'd have a look at TRACE level eviction logs. -
4. Re: Passivation false problem
rachna_agg Jun 27, 2008 4:39 AM (in response to rachna_agg)Thanks again for the reply.
My understanding about activation was wrong but now I am able to understand why the attribute "Activations" was not visible if passivation is false.
But I am still not clear about the "Hits" and "Misses" attributes. Let me explain my situation with the following steps and their corresponding attribute values:1) Insert /A
2) Retrieve /A
3) Retrieve /A
Output
1) CL Loads = 0, Hits = 0, Misses = 0, CL Misses = 0, Evictions = 0
2) CL Loads = 1, Hits = 0, Misses = 1, CL Misses = 0, Evictions = 0
3) CL Loads = 1, Hits = 0, Misses = 2, CL Misses = 0, Evictions = 0
Here, I think that when I retrieve the same record in Step 3, then instead of the attribute "Misses" being increased, I think the attribute "Hits" should have been increased which is not happening in my case. I also enabled the DEBUG logging for jboss cache and I got the following output after Step 2:Jun 27, 2008 01:59:27.500 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=true, cache=, modificationType=null, data=null, fqn=/4528@rachna, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_CREATED} Jun 27, 2008 01:59:27.500 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=false, cache=/4528@rachna 0 , modificationType=null, data=null, fqn=/4528@rachna, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_CREATED} Jun 27, 2008 01:59:27.500 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=true, cache=/4528@rachna 0 , modificationType=null, data=null, fqn=/4528@rachna/42, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_CREATED} Jun 27, 2008 01:59:27.500 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=false, cache=/4528@rachna 0 /42 0 , modificationType=null, data=null, fqn=/4528@rachna/42, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_CREATED} Jun 27, 2008 01:59:27.500 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=true, cache=/4528@rachna 0 /42 0 , modificationType=null, data=null, fqn=/4528@rachna/42/1214554449967, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_CREATED} Jun 27, 2008 01:59:27.500 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=false, cache=/4528@rachna 0 /42 0 /1214554449967 0 , modificationType=null, data=null, fqn=/4528@rachna/42/1214554449967, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_CREATED} Jun 27, 2008 01:59:27.500 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=true, cache=/4528@rachna 0 /42 0 /1214554449967 0 , modificationType=null, data=null, fqn=/4528@rachna/42/1214554449967/10156252448681560289, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_CREATED} Jun 27, 2008 01:59:27.500 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=false, cache=/4528@rachna 0 /42 0 /1214554449967 0 /10156252448681560289 0 , modificationType=null, data=null, fqn=/4528@rachna/42/1214554449967/10156252448681560289, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_CREATED} Jun 27, 2008 01:59:27.532 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=true, cache=/4528@rachna 0 /42 0 /1214554449967 0 /10156252448681560289 0 , modificationType=null, data={}, fqn=/4528@rachna/42/1214554449967/10156252448681560289, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_LOADED} Jun 27, 2008 01:59:27.532 PM DEBUG JBOSSCACHEEVENT_LOGGER - EventImpl{pre=false, cache=/4528@rachna 0 /42 0 /1214554449967 0 /10156252448681560289 4 , modificationType=null, data={somedata}, fqn=/4528@rachna/42/1214554449967/10156252448681560289, transaction=null, originLocal=true, targetFqn=null, successful=false, newView=null, type=NODE_LOADED}
and after executing Step 3, no logging appeared in jboss cache logs. -
5. Re: Passivation false problem
manik Jun 27, 2008 6:47 AM (in response to rachna_agg)I'm guessing something must have removed the node between steps 2 and 3.
The log you posted is not a JBoss Cache log, but some custom logging from a cache listener which is of limited use. Specifically, I'd want to see the CacheLoaderInterceptor logs and any eviction component logs at TRACE level. -
6. Re: Passivation false problem
rachna_agg Jun 27, 2008 7:43 AM (in response to rachna_agg)Sorry, here are the logs after Step 2:
Jun 27, 2008 05:09:02.046 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:02.046 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:09:02.046 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:02.046 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 50090ms Jun 27, 2008 05:09:02.046 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:02.046 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 50090ms Jun 27, 2008 05:09:02.046 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:03.108 PM DEBUG org.apache.catalina.session.ManagerBase - Start expire sessions StandardManager at 1214566743108 sessioncount 0 Jun 27, 2008 05:09:03.108 PM DEBUG org.apache.catalina.session.ManagerBase - End expire sessions StandardManager processingTime 0 expired sessions: 0 Jun 27, 2008 05:09:07.046 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:07.046 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:09:07.046 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:07.046 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 55090ms Jun 27, 2008 05:09:07.046 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:07.046 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 55090ms Jun 27, 2008 05:09:07.046 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185)] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3256@rachna/42/1214566690893/1883577710211620771185 for owner Thread[http-8080-Processor24,5,main] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - don't load, key requested is null Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - load element /3256@rachna/42/1214566690893/1883577710211620771185 mustLoad=false Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) so it gets invoked on cache. Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Adding event EvictedEN[fqn=/3256@rachna/42/1214566690893/1883577710211620771185 event=VISIT_NODE_EVENT diff=0] to region at / Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished updating node Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[http-8080-Processor24,5,main]=[read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]]]} Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42/1214566690893/1883577710211620771185: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42/1214566690893: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true)] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true) Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3256@rachna/42/1214566690893/1883577710211620771185 for owner Thread[http-8080-Processor24,5,main] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true) Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - must Load, uninitialized Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - load element /3256@rachna/42/1214566690893/1883577710211620771185 mustLoad=true Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _lock; MethodIdInteger: 33; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, WRITE, false)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _lock; MethodIdInteger: 33; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, WRITE, false)] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, WRITE, false) Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3256@rachna/42/1214566690893/1883577710211620771185 for owner Thread[http-8080-Processor24,5,main] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for / Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for /3256@rachna Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for /3256@rachna/42 Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for /3256@rachna/42/1214566690893 Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for /3256@rachna/42/1214566690893/1883577710211620771185 Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - loadNode /3256@rachna/42/1214566690893/1883577710211620771185 Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.loader.JDBCCacheLoader - executing sql: select node from jbosscache where fqn=? (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.loader.ManagedConnectionFactory - Connection checked out: org.apache.tomcat.dbcp.dbcp.PoolableConnection@423606 Jun 27, 2008 05:09:07.186 PM DEBUG org.jboss.cache.marshall.VersionAwareMarshaller - Read version 20 Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.marshall.CacheMarshaller200 - Unmarshalled object {somedata} Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - nodeExists true Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - Node data is not null, loading Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - Setting dataLoaded to true Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true) Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true) so it gets invoked on cache. Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.CacheImpl.JBossCache-Cluster - _get("/3256@rachna/42/1214566690893/1883577710211620771185", "", "true") Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - No event added. Element does not exist Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[http-8080-Processor24,5,main]=[read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]]]} Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42/1214566690893/1883577710211620771185: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42/1214566690893: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185)] Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - bypassed locking as method _getData() doesn't require locking Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) so it gets invoked on cache. Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Adding event EvictedEN[fqn=/3256@rachna/42/1214566690893/1883577710211620771185 event=VISIT_NODE_EVENT diff=0] to region at / Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished updating node Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {} Jun 27, 2008 05:09:07.202 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 05:09:12.061 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:12.061 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 2 node events in region: / Jun 27, 2008 05:09:12.061 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:12.061 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 0ms Jun 27, 2008 05:09:12.061 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:12.061 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 0ms Jun 27, 2008 05:09:12.061 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:17.061 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:17.061 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:09:17.061 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:17.061 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 5000ms Jun 27, 2008 05:09:17.061 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:17.061 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 5000ms Jun 27, 2008 05:09:17.061 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted
and after Step 3:Jun 27, 2008 05:09:32.091 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:32.091 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:09:32.091 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:32.091 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 20030ms Jun 27, 2008 05:09:32.091 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:32.091 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 20030ms Jun 27, 2008 05:09:32.091 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:37.106 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:37.106 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:09:37.106 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:37.106 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 25045ms Jun 27, 2008 05:09:37.106 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:37.106 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 25045ms Jun 27, 2008 05:09:37.106 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:42.106 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:42.106 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:09:42.106 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:42.106 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 30045ms Jun 27, 2008 05:09:42.106 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:42.106 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 30045ms Jun 27, 2008 05:09:42.106 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:47.121 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:47.121 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:09:47.121 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:47.121 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 35060ms Jun 27, 2008 05:09:47.121 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:47.121 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 35060ms Jun 27, 2008 05:09:47.121 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:52.121 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:52.121 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:09:52.121 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:52.121 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 40060ms Jun 27, 2008 05:09:52.121 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:52.121 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 40060ms Jun 27, 2008 05:09:52.121 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:57.136 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:09:57.136 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:09:57.136 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:09:57.136 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 45075ms Jun 27, 2008 05:09:57.136 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:09:57.136 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 45075ms Jun 27, 2008 05:09:57.136 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:02.136 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:10:02.136 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:10:02.136 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:10:02.136 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 50075ms Jun 27, 2008 05:10:02.136 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:02.136 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 50075ms Jun 27, 2008 05:10:02.136 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:03.151 PM DEBUG org.apache.catalina.session.ManagerBase - Start expire sessions StandardManager at 1214566803151 sessioncount 0 Jun 27, 2008 05:10:03.151 PM DEBUG org.apache.catalina.session.ManagerBase - End expire sessions StandardManager processingTime 0 expired sessions: 0 Jun 27, 2008 05:10:07.151 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:10:07.151 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:10:07.151 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:10:07.151 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 55090ms Jun 27, 2008 05:10:07.151 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:07.151 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 55090ms Jun 27, 2008 05:10:07.151 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:12.151 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:10:12.151 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:10:12.151 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:10:12.151 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 60090ms Jun 27, 2008 05:10:12.151 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:12.151 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 60090ms Jun 27, 2008 05:10:12.151 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:17.166 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:10:17.166 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:10:17.166 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:10:17.166 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 65105ms Jun 27, 2008 05:10:17.166 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:17.166 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 65105ms Jun 27, 2008 05:10:17.166 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:22.181 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:10:22.181 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:10:22.181 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:10:22.181 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 70120ms Jun 27, 2008 05:10:22.181 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:22.181 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 70120ms Jun 27, 2008 05:10:22.181 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:27.181 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:10:27.181 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:10:27.181 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:10:27.181 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 75120ms Jun 27, 2008 05:10:27.181 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:27.181 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 75120ms Jun 27, 2008 05:10:27.181 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185)] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3256@rachna/42/1214566690893/1883577710211620771185 for owner Thread[http-8080-Processor25,5,main] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - don't load, key requested is null Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - load element /3256@rachna/42/1214566690893/1883577710211620771185 mustLoad=false Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) so it gets invoked on cache. Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Adding event EvictedEN[fqn=/3256@rachna/42/1214566690893/1883577710211620771185 event=VISIT_NODE_EVENT diff=0] to region at / Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished updating node Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[http-8080-Processor25,5,main]=[read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]]]} Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42/1214566690893/1883577710211620771185: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42/1214566690893: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true)] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3256@rachna/42/1214566690893/1883577710211620771185 for owner Thread[http-8080-Processor25,5,main] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3256@rachna/42/1214566690893/1883577710211620771185, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - load element /3256@rachna/42/1214566690893/1883577710211620771185 mustLoad=false Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/3256@rachna/42/1214566690893/1883577710211620771185, , true) so it gets invoked on cache. Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.CacheImpl.JBossCache-Cluster - _get("/3256@rachna/42/1214566690893/1883577710211620771185", "", "true") Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - No event added. Element does not exist Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[http-8080-Processor25,5,main]=[read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]]]} Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42/1214566690893/1883577710211620771185: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42/1214566690893: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna/42: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3256@rachna: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185)] Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - bypassed locking as method _getData() doesn't require locking Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _getData; MethodIdInteger: 24; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) so it gets invoked on cache. Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Adding event EvictedEN[fqn=/3256@rachna/42/1214566690893/1883577710211620771185 event=VISIT_NODE_EVENT diff=0] to region at / Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished updating node Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {} Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 05:10:32.196 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:10:32.196 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 2 node events in region: / Jun 27, 2008 05:10:32.196 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:10:32.196 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 0ms Jun 27, 2008 05:10:32.196 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:32.196 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 0ms Jun 27, 2008 05:10:32.196 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:37.196 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 05:10:37.196 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 05:10:37.196 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 05:10:37.196 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 5000ms Jun 27, 2008 05:10:37.196 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted Jun 27, 2008 05:10:37.196 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 has been idle for 5000ms Jun 27, 2008 05:10:37.196 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3256@rachna/42/1214566690893/1883577710211620771185 should not be evicted
-
7. Re: Passivation false problem
rachna_agg Jun 27, 2008 7:45 AM (in response to rachna_agg)Here are the Evictoin Policy Details:
<attribute name="EvictionPolicyConfig"> <config> <attribute name="wakeUpIntervalSeconds">5</attribute> <attribute name="eventQueueSize">200000</attribute> <attribute name="policyClass"> org.jboss.cache.eviction.LRUPolicy </attribute> <region name="/"> <attribute name="maxNodes">500</attribute> <attribute name="timeToLiveSeconds">1000</attribute> </region> <region name="/_default_"> <attribute name="maxNodes">500</attribute> <attribute name="timeToLiveSeconds">1000</attribute> </region> </config> </attribute>
-
8. Re: Passivation false problem
manik Jun 27, 2008 7:59 AM (in response to rachna_agg)Umm, I don't think the cache loader is loading the node from the DB for step 3.
... Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke Meth odName: _get; MethodIdInteger: 31; Args: (/3256@rachna/42/1214566690893/1883577710211620771185) Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - don't load, key requested is null Jun 27, 2008 05:10:31.290 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - load elemen t /3256@rachna/42/1214566690893/1883577710211620771185 mustLoad=false ...
Could be that the statistics are inaccurate. Which version of JBC is this? -
9. Re: Passivation false problem
rachna_agg Jun 27, 2008 9:21 AM (in response to rachna_agg)Which statistics are you talking about? We are using JBossCache-core-2.0.0.GA.
-
10. Re: Passivation false problem
manik Jun 27, 2008 9:51 AM (in response to rachna_agg)I'm guessing you are getting your statistics on hits and misses from JMX?
Have you tried a newer version, 2.1.1.GA or 2.2.0.CR4? -
11. Re: Passivation false problem
rachna_agg Jun 27, 2008 12:09 PM (in response to rachna_agg)Yes we have enabled JMX in tomcat and are retrieving the statistics from the MBeans "jboss.cache:service=TreeCache,cache-interceptor=CacheLoaderInterceptor" and "jboss.cache:service=TreeCache,cache-interceptor=CacheMgmtInterceptor".
I tried using the newer version 2.1.1.GA but got same results. Here are the logs after Step 2:Jun 27, 2008 09:36:11.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 09:36:11.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 09:36:11.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 09:36:11.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 10000ms Jun 27, 2008 09:36:11.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted Jun 27, 2008 09:36:11.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 10000ms Jun 27, 2008 09:36:11.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted Jun 27, 2008 09:36:16.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 09:36:16.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 09:36:16.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 09:36:16.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 15000ms Jun 27, 2008 09:36:16.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted Jun 27, 2008 09:36:16.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 15000ms Jun 27, 2008 09:36:16.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136)] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3520@rachna/42/1214582760875/8501033611511983927136 for owner Thread[http-8080-Processor24,5,main] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - don't load, key requested is null Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - load element /3520@rachna/42/1214582760875/8501033611511983927136 mustLoad=false Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) so it gets invoked on cache. Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Adding event EvictedEN[fqn=/3520@rachna/42/1214582760875/8501033611511983927136 event=VISIT_NODE_EVENT diff=0] to region at / Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished updating node Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[http-8080-Processor24,5,main]=[read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]]]} Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42/1214582760875/8501033611511983927136: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42/1214582760875: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true)] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true) Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3520@rachna/42/1214582760875/8501033611511983927136 for owner Thread[http-8080-Processor24,5,main] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor24,5,main], lock=<unlocked> Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true) Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - must Load, uninitialized Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - load element /3520@rachna/42/1214582760875/8501033611511983927136 mustLoad=true Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _lock; MethodIdInteger: 33; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, WRITE, false)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _lock; MethodIdInteger: 33; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, WRITE, false)] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _lock; MethodIdInteger: 33; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, WRITE, false) Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3520@rachna/42/1214582760875/8501033611511983927136 for owner Thread[http-8080-Processor24,5,main] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for / Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for /3520@rachna Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for /3520@rachna/42 Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for /3520@rachna/42/1214582760875 Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller Thread[http-8080-Processor24,5,main] already owns lock for /3520@rachna/42/1214582760875/8501033611511983927136 Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor24,5,main], lock=read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - loadNode /3520@rachna/42/1214582760875/8501033611511983927136 Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.loader.JDBCCacheLoader - executing sql: select node from jbosscache where fqn=? (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:36:20.765 PM DEBUG org.jboss.cache.loader.ManagedConnectionFactory - Connection checked out: org.apache.tomcat.dbcp.dbcp.PoolableConnection@1e2f6b0 Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.marshall.VersionAwareMarshaller - Read version 20 Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.marshall.CacheMarshaller200 - Unmarshalled object {somedata} Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - nodeExists true Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - Node data is not null, loading Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - Setting dataLoaded to true Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true) Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true) so it gets invoked on cache. Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.CacheImpl.JBossCache-Cluster - _get("/3520@rachna/42/1214582760875/8501033611511983927136", "", "true") Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - No event added. Element does not exist Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[http-8080-Processor24,5,main]=[read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]], read owners=[Thread[http-8080-Processor24,5,main]]]} Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42/1214582760875/8501033611511983927136: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42/1214582760875: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /: read owners=[Thread[http-8080-Processor24,5,main]] Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136)] Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - bypassed locking as method _getData() doesn't require locking Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) so it gets invoked on cache. Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Adding event EvictedEN[fqn=/3520@rachna/42/1214582760875/8501033611511983927136 event=VISIT_NODE_EVENT diff=0] to region at / Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished updating node Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {} Jun 27, 2008 09:36:20.781 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 09:36:21.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 09:36:21.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 2 node events in region: / Jun 27, 2008 09:36:21.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 09:36:21.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 0ms Jun 27, 2008 09:36:21.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted Jun 27, 2008 09:36:21.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 0ms Jun 27, 2008 09:36:21.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted Jun 27, 2008 09:36:26.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 09:36:26.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 0 node events in region: / Jun 27, 2008 09:36:26.531 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 09:36:26.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 5000ms Jun 27, 2008 09:36:26.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted Jun 27, 2008 09:36:26.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 5000ms Jun 27, 2008 09:36:26.531 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted
and after Step 3:Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136)] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3520@rachna/42/1214582760875/8501033611511983927136 for owner Thread[http-8080-Processor25,5,main] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - don't load, key requested is null Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - load element /3520@rachna/42/1214582760875/8501033611511983927136 mustLoad=false Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _get; MethodIdInteger: 31; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) so it gets invoked on cache. Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Adding event EvictedEN[fqn=/3520@rachna/42/1214582760875/8501033611511983927136 event=VISIT_NODE_EVENT diff=0] to region at / Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished updating node Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[http-8080-Processor25,5,main]=[read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]]]} Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42/1214582760875/8501033611511983927136: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42/1214582760875: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true)] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true) Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /3520@rachna/42/1214582760875/8501033611511983927136 for owner Thread[http-8080-Processor25,5,main] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquiring RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor25,5,main], lock=<unlocked> Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.lock.IdentityLock - acquired RL: fqn=/3520@rachna/42/1214582760875/8501033611511983927136, caller=Thread[http-8080-Processor25,5,main], lock=read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true) Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - load element /3520@rachna/42/1214582760875/8501033611511983927136 mustLoad=false Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true) Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _get; MethodIdInteger: 26; Args: (/3520@rachna/42/1214582760875/8501033611511983927136, , true) so it gets invoked on cache. Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.CacheImpl.JBossCache-Cluster - _get("/3520@rachna/42/1214582760875/8501033611511983927136", "", "true") Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - No event added. Element does not exist Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[http-8080-Processor25,5,main]=[read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]], read owners=[Thread[http-8080-Processor25,5,main]]]} Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42/1214582760875/8501033611511983927136: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42/1214582760875: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna/42: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /3520@rachna: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /: read owners=[Thread[http-8080-Processor25,5,main]] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting up transactional context. Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136)] Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - bypassed locking as method _getData() doesn't require locking Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CacheLoaderInterceptor - invoke MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CacheStoreInterceptor - invoke MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.CallInterceptor - Passing up method MethodName: _getData; MethodIdInteger: 24; Args: (/3520@rachna/42/1214582760875/8501033611511983927136) so it gets invoked on cache. Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Invoking EvictionInterceptor Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Updating node/element events with no tx Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Adding event EvictedEN[fqn=/3520@rachna/42/1214582760875/8501033611511983927136 event=VISIT_NODE_EVENT diff=0] to region at / Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished updating node Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.EvictionInterceptor - Finished invoking EvictionInterceptor Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {} Jun 27, 2008 09:40:33.765 PM DEBUG org.jboss.cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options Jun 27, 2008 09:40:36.593 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - process(): region: / Jun 27, 2008 09:40:36.593 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - processed 2 node events in region: / Jun 27, 2008 09:40:36.593 PM DEBUG org.jboss.cache.eviction.BaseEvictionAlgorithm - Recycle queue is empty Jun 27, 2008 09:40:36.593 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 0ms Jun 27, 2008 09:40:36.593 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted Jun 27, 2008 09:40:36.593 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 has been idle for 0ms Jun 27, 2008 09:40:36.593 PM DEBUG org.jboss.cache.eviction.LRUAlgorithm - Node /3520@rachna/42/1214582760875/8501033611511983927136 should not be evicted