[jboss-user] [JBoss Cache Users] - Can't acquire lock in 0 ms

rs1050 do-not-reply at jboss.com
Sat Nov 14 23:17:13 EST 2009


Hi, 

Version 3.2.1GA, problem happens with two processes working with cache at the same time. Both processes use JOTM for tx management. I am getting this message: 


  | Nov 14 18:49:13,248 [OOB-1,192.168.1.104:61141] TRACE CacheMarshaller300:objectFromObjectStream:162 - Unmarshalled object org.jboss.cache.lock.TimeoutException: Unable to acquire lock on Fqn [/hphRTp4/0:0_2] after [0] milliseconds for requestor [Thread[Incoming-1,192.168.1.104:61140,10,Thread Pools]]! Lock held by [Thread[org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1,5,main]]
  | 


more detailed log:

  | Nov 14 18:49:13,32 [Incoming-1,192.168.1.104:61141] TRACE CacheMarshaller300:objectFromObjectStream:162 - Unmarshalled object ReplicateCommand{cmds=InvalidateCommand{fqn=/m/1:575}}
  | Nov 14 18:49:13,33 [Incoming-1,192.168.1.104:61141] TRACE CommandAwareRpcDispatcher:executeCommand:270 - Executing command: ReplicateCommand{cmds=InvalidateCommand{fqn=/m/1:575}} [sender=192.168.1.104:61140]
  | Nov 14 18:49:13,33 [Incoming-1,192.168.1.104:61141] TRACE CommandAwareRpcDispatcher:executeCommand:312 - This is a non-visitable command - so performing directly and not via the invoker.
  | Nov 14 18:49:13,33 [Incoming-1,192.168.1.104:61141] TRACE ComponentRegistry:invocationsAllowed:880 - Testing if invocations are allowed.
  | Nov 14 18:49:13,34 [Incoming-1,192.168.1.104:61141] TRACE ReplicateCommand:processSingleCommand:135 - Invoking command InvalidateCommand{fqn=/m/1:575}, with originLocal flag set to false.
  | Nov 14 18:49:13,34 [Incoming-1,192.168.1.104:61141] TRACE InvocationContextInterceptor:handleAll:141 - Invoked with command InvalidateCommand{fqn=/m/1:575} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false, suppressPersistence=false, suppressEventNotification=false}, originLocal=false, bypassUnmarshalling=false}]
  | Nov 14 18:49:13,35 [Incoming-1,192.168.1.104:61141] TRACE InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional context.
  | Nov 14 18:49:13,35 [Incoming-1,192.168.1.104:61141] TRACE InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as null
  | Nov 14 18:49:13,35 [Incoming-1,192.168.1.104:61141] TRACE MVCCLockManager:lockAndRecord:131 - Attempting to lock /m/1:575
  | Nov 14 18:49:13,35 [Incoming-1,192.168.1.104:61141] TRACE CallInterceptor:handleDefault:98 - Executing command: InvalidateCommand{fqn=/m/1:575}.
  | Nov 14 18:49:13,37 [Incoming-1,192.168.1.104:61141] TRACE ComponentRegistry:invocationsAllowed:880 - Testing if invocations are allowed.
  | Nov 14 18:49:13,38 [Incoming-1,192.168.1.104:61141] TRACE InvocationContextInterceptor:handleAll:141 - Invoked with command GetNodeCommand{fqn=/m/1:575} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=0, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false, suppressPersistence=false, suppressEventNotification=false}, originLocal=false, bypassUnmarshalling=false}]
  | Nov 14 18:49:13,39 [Incoming-1,192.168.1.104:61141] TRACE InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional context.
  | Nov 14 18:49:13,39 [Incoming-1,192.168.1.104:61141] TRACE InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as null
  | Nov 14 18:49:13,39 [Incoming-1,192.168.1.104:61141] TRACE MVCCNodeHelper:wrapNodeForReading:129 - Node /m/1:575 is not in context, fetching from container.
  | Nov 14 18:49:13,40 [Incoming-1,192.168.1.104:61141] TRACE CacheLoaderInterceptor:mustLoad:421 - Node [/m/1:575] is null in memory.  Must load? true
  | Nov 14 18:49:13,41 [Incoming-1,192.168.1.104:61141] TRACE CacheLoaderInterceptor:loadIfNeeded:293 - load element /m/1:575 mustLoad=true
  | Nov 14 18:49:13,42 [Incoming-1,192.168.1.104:61141] TRACE TcpDelegatingCacheLoader:invokeWithRetries:129 - About to invoke operation protected boolean org.jboss.cache.loader.TcpDelegatingCacheLoader._exists(org.jboss.cache.Fqn) throws java.lang.Exception
  | Nov 14 18:49:13,32 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /rdp4
  | Nov 14 18:49:13,43 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,43 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,43 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,44 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/rdp1].  Queue size is 0
  | Nov 14 18:49:13,44 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /rdp1
  | Nov 14 18:49:13,44 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,44 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,44 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,48 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/rXY].  Queue size is 0
  | Nov 14 18:49:13,48 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /rXY
  | Nov 14 18:49:13,48 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,50 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,50 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,55 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/].  Queue size is 0
  | Nov 14 18:49:13,56 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /
  | Nov 14 18:49:13,56 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,56 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,56 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,57 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/rDCB].  Queue size is 0
  | Nov 14 18:49:13,57 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /rDCB
  | Nov 14 18:49:13,57 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,57 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,57 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,58 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/uF].  Queue size is 0
  | Nov 14 18:49:13,58 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /uF
  | Nov 14 18:49:13,58 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,58 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,58 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,59 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMLp5].  Queue size is 0
  | Nov 14 18:49:13,59 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMLp5
  | Nov 14 18:49:13,59 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,61 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,61 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,61 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,61 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 1
  | Nov 14 18:49:13,62 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphRRp3].  Queue size is 0
  | Nov 14 18:49:13,62 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphRRp3
  | Nov 14 18:49:13,62 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,62 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,62 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,63 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,63 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 1
  | Nov 14 18:49:13,63 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMLp4].  Queue size is 0
  | Nov 14 18:49:13,63 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMLp4
  | Nov 14 18:49:13,63 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,64 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,64 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,65 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/test].  Queue size is 0
  | Nov 14 18:49:13,65 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /test
  | Nov 14 18:49:13,65 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,65 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,65 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,66 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMVp2].  Queue size is 0
  | Nov 14 18:49:13,67 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMVp2
  | Nov 14 18:49:13,71 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,71 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,71 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,70 [main] TRACE TcpDelegatingCacheLoader:invokeWithRetries:131 - Completed invocation of protected java.lang.Object org.jboss.cache.loader.TcpDelegatingCacheLoader._put(org.jboss.cache.Fqn,java.lang.Object,java.lang.Object) throws java.lang.Exception
  | Nov 14 18:49:13,72 [main] TRACE ReadCommittedNode:commitUpdate:136 - Updating node [/hphRTp3/0:0_2].  deleted=false valid=true changed=true created=false
  | Nov 14 18:49:13,73 [main] TRACE MVCCLockingInterceptor:cleanupLocks:374 - Releasing lock on [/hphRTp3/0:0_2] for owner Thread[main,5,main]
  | Nov 14 18:49:13,73 [main] TRACE MVCCLockManager:unlock:145 - Attempting to unlock /hphRTp3/0:0_2
  | Nov 14 18:49:13,73 [main] DEBUG InvalidationInterceptor:handleWriteMethod:244 - Is a CRUD method
  | Nov 14 18:49:13,74 [main] DEBUG InvalidationInterceptor:invalidateAcrossCluster:381 - Cache [192.168.1.104:61141] replicating InvalidateCommand{fqn=/hphRTp3/0:0_2}
  | Nov 14 18:49:13,74 [main] TRACE InvalidationInterceptor:replicateCall:140 - Broadcasting call InvalidateCommand{fqn=/hphRTp3/0:0_2} to recipient list null
  | Nov 14 18:49:13,74 [main] TRACE InvalidationInterceptor:replicateCall:156 - Setting call recipients to null since the original list of recipients passed in is null.
  | Nov 14 18:49:13,77 [main] TRACE RPCManagerImpl:callRemoteMethods:736 - callRemoteMethods(): valid members are null methods: ReplicateCommand{cmds=InvalidateCommand{fqn=/hphRTp3/0:0_2}} Using OOB? false modeToUse: 2
  | Nov 14 18:49:13,77 [main] TRACE CommandAwareRpcDispatcher:invokeRemoteCommands:205 - dests=null, command=ReplicateCommand{cmds=InvalidateCommand{fqn=/hphRTp3/0:0_2}}, mode=2, timeout=15000
  | Nov 14 18:49:13,78 [main] TRACE CacheMarshaller300:objectToObjectStream:169 - Marshalling object ReplicateCommand{cmds=InvalidateCommand{fqn=/hphRTp3/0:0_2}}
  | Nov 14 18:49:13,78 [main] TRACE CacheMarshaller300:objectToObjectStream:200 - Done serializing object: ReplicateCommand{cmds=InvalidateCommand{fqn=/hphRTp3/0:0_2}}
  | Nov 14 18:49:13,79 [main] TRACE CommandAwareRpcDispatcher:castMessage:456 - real_dests=[192.168.1.104:61140]
  | Nov 14 18:49:13,71 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMLp3].  Queue size is 0
  | Nov 14 18:49:13,80 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMLp3
  | Nov 14 18:49:13,81 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,82 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,83 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,85 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphRTp1].  Queue size is 0
  | Nov 14 18:49:13,85 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphRTp1
  | Nov 14 18:49:13,85 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,89 [Incoming-1,192.168.1.104:61141] TRACE TcpDelegatingCacheLoader:invokeWithRetries:131 - Completed invocation of protected boolean org.jboss.cache.loader.TcpDelegatingCacheLoader._exists(org.jboss.cache.Fqn) throws java.lang.Exception
  | Nov 14 18:49:13,89 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,90 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,90 [Incoming-1,192.168.1.104:61141] TRACE MVCCNodeFactory:createChildNode:175 - Created new child with fqn [/m/1:575]
  | Nov 14 18:49:13,90 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,91 [Incoming-1,192.168.1.104:61141] TRACE MVCCNodeHelper:wrapNodeForReading:136 - Node /m is already in context.
  | Nov 14 18:49:13,92 [Incoming-1,192.168.1.104:61141] TRACE MVCCNodeHelper:wrapNodeForReading:136 - Node /m/1:575 is already in context.
  | Nov 14 18:49:13,91 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 1
  | Nov 14 18:49:13,92 [Incoming-1,192.168.1.104:61141] TRACE CallInterceptor:handleDefault:98 - Executing command: GetNodeCommand{fqn=/m/1:575}.
  | Nov 14 18:49:13,94 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/ibPREVIEW].  Queue size is 0
  | Nov 14 18:49:13,96 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /ibPREVIEW
  | Nov 14 18:49:13,96 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,96 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,97 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,97 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/mC].  Queue size is 0
  | Nov 14 18:49:13,97 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /mC
  | Nov 14 18:49:13,97 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,97 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,95 [Incoming-1,192.168.1.104:61141] TRACE GetNodeCommand:perform:70 - Found node, returning NodeReference{delegate=UnversionedNode[ /m/1:575]}
  | Nov 14 18:49:13,98 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,100 [Incoming-1,192.168.1.104:61141] TRACE RegionManagerImpl:getRegion:223 - Contents of RegionsRegistry: {/hphRRp1=RegionImpl{fqn=/hphRRp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /uN=RegionImpl{fqn=/uN; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp2=RegionImpl{fqn=/rdp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp1=RegionImpl{fqn=/hphMRp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp4=RegionImpl{fqn=/hphRRp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp4=RegionImpl{fqn=/rdp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp1=RegionImpl{fqn=/rdp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rXY=RegionImpl{fqn=/rXY; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /=RegionImpl{fqn=/; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rDCB=RegionImpl{fqn=/rDCB; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /uF=RegionImpl{fqn=/uF; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp5=RegionImpl{fqn=/hphMLp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp3=RegionImpl{fqn=/hphRRp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp4=RegionImpl{fqn=/hphMLp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /test=RegionImpl{fqn=/test; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp2=RegionImpl{fqn=/hphMVp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp3=RegionImpl{fqn=/hphMLp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp1=RegionImpl{fqn=/hphRTp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /ibPREVIEW=RegionImpl{fqn=/ibPREVIEW; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /mC=RegionImpl{fqn=/mC; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /u=RegionImpl{fqn=/u; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp3=RegionImpl{fqn=/hphMVp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp5=RegionImpl{fqn=/hphRRp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp2=RegionImpl{fqn=/hphMLp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /v=RegionImpl{fqn=/v; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp2=RegionImpl{fqn=/hphMTp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp4=RegionImpl{fqn=/hphMRp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp1=RegionImpl{fqn=/hphMLp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /m=RegionImpl{fqn=/m; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=1}, /hphMVp4=RegionImpl{fqn=/hphMVp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp2=RegionImpl{fqn=/hphRTp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /i=RegionImpl{fqn=/i; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp1=RegionImpl{fqn=/hphMVp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp5=RegionImpl{fqn=/hphMRp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /cN=RegionImpl{fqn=/cN; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /ibTHUMB=RegionImpl{fqn=/ibTHUMB; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp5=RegionImpl{fqn=/hphMVp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp2=RegionImpl{fqn=/hphMRp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /aC=RegionImpl{fqn=/aC; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /mR=RegionImpl{fqn=/mR; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp3=RegionImpl{fqn=/hphMTp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp5=RegionImpl{fqn=/hphRTp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=2}, /pN=RegionImpl{fqn=/pN; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp5=RegionImpl{fqn=/hphMTp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp4=RegionImpl{fqn=/hphRTp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=1}, /r=RegionImpl{fqn=/r; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp3=RegionImpl{fqn=/hphMRp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp3=RegionImpl{fqn=/rdp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp2=RegionImpl{fqn=/hphRRp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp3=RegionImpl{fqn=/hphRTp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=2}, /hphMTp4=RegionImpl{fqn=/hphMTp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp1=RegionImpl{fqn=/hphMTp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp5=RegionImpl{fqn=/rdp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}}
  | Nov 14 18:49:13,101 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region /u].  Queue size is 0
  | Nov 14 18:49:13,103 [Incoming-1,192.168.1.104:61141] TRACE RegionManagerImpl:getRegion:271 - Trying next region /m and got RegionImpl{fqn=/m; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=1}
  | Nov 14 18:49:13,103 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /u
  | Nov 14 18:49:13,104 [Incoming-1,192.168.1.104:61141] TRACE EvictionInterceptor:registerEvictionEventToRegionManager:254 - Registering event VISIT_NODE_EVENT on node /m/1:575
  | Nov 14 18:49:13,104 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,105 [Incoming-1,192.168.1.104:61141] TRACE ReadCommittedNode:commitUpdate:136 - Updating node [/m/1:575].  deleted=false valid=true changed=true created=true
  | Nov 14 18:49:13,107 [Incoming-1,192.168.1.104:61141] TRACE MVCCLockingInterceptor:cleanupLocks:374 - Releasing lock on [/m/1:575] for owner Thread[Incoming-1,192.168.1.104:61141,10,Thread Pools]
  | Nov 14 18:49:13,106 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,107 [Incoming-1,192.168.1.104:61141] TRACE MVCCLockManager:unlock:145 - Attempting to unlock /m/1:575
  | Nov 14 18:49:13,108 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,108 [Incoming-1,192.168.1.104:61141] TRACE InvocationContextInterceptor:handleAll:208 - Resetting invocation-scope options
  | Nov 14 18:49:13,109 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMVp3].  Queue size is 0
  | Nov 14 18:49:13,109 [Incoming-1,192.168.1.104:61141] TRACE InvalidateCommand:perform:77 - Invalidating fqn:/m/1:575
  | Nov 14 18:49:13,109 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMVp3
  | Nov 14 18:49:13,111 [Incoming-1,192.168.1.104:61141] TRACE DataContainerImpl:evict:691 - removing NODE as it is a leaf: evict(/m/1:575)
  | Nov 14 18:49:13,111 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,112 [Incoming-1,192.168.1.104:61141] TRACE UnversionedNode:setValid:595 - Marking node /m/1:575 as invalid
  | Nov 14 18:49:13,112 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,113 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,113 [Incoming-1,192.168.1.104:61141] TRACE UnversionedNode:setValid:595 - Marking node /m/1:575 as invalid
  | Nov 14 18:49:13,113 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphRRp5].  Queue size is 0
  | Nov 14 18:49:13,113 [Incoming-1,192.168.1.104:61141] TRACE MVCCLockingInterceptor:doAfterCall:350 - Nothing to do since there are no modifications in scope.
  | Nov 14 18:49:13,114 [Incoming-1,192.168.1.104:61141] TRACE InvocationContextInterceptor:handleAll:208 - Resetting invocation-scope options
  | Nov 14 18:49:13,114 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphRRp5
  | Nov 14 18:49:13,114 [Incoming-1,192.168.1.104:61141] TRACE CommandAwareRpcDispatcher:handle:247 - Command : ReplicateCommand{cmds=InvalidateCommand{fqn=/m/1:575}} executed, result is: null
  | Nov 14 18:49:13,114 [OOB-1,192.168.1.104:61141] TRACE CacheMarshaller300:objectFromObjectStream:162 - Unmarshalled object null
  | Nov 14 18:49:13,116 [Incoming-1,192.168.1.104:61141] TRACE CacheMarshaller300:objectToObjectStream:169 - Marshalling object null
  | Nov 14 18:49:13,115 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,116 [Incoming-1,192.168.1.104:61141] TRACE CacheMarshaller300:objectToObjectStream:200 - Done serializing object: null
  | Nov 14 18:49:13,116 [main] TRACE CommandAwareRpcDispatcher:call:398 - responses: [sender=192.168.1.104:61140, retval=null, received=true, suspected=false]
  | 
  | Nov 14 18:49:13,117 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,117 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,118 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,118 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 1
  | Nov 14 18:49:13,117 [main] TRACE RPCManagerImpl:callRemoteMethods:748 - (192.168.1.104:61141): responses for method ReplicateCommand:
  | null
  | Nov 14 18:49:13,118 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMLp2].  Queue size is 0
  | Nov 14 18:49:13,118 [main] TRACE InvalidationInterceptor:replicateCall:167 - responses=[]
  | Nov 14 18:49:13,118 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMLp2
  | Nov 14 18:49:13,119 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,120 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,119 [main] TRACE InvocationContextInterceptor:handleAll:208 - Resetting invocation-scope options
  | Nov 14 18:49:13,120 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,120 [main] TRACE ComponentRegistry:invocationsAllowed:880 - Testing if invocations are allowed.
  | Nov 14 18:49:13,121 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,121 [main] TRACE InvocationContextInterceptor:handleAll:141 - Invoked with command GetNodeCommand{fqn=/hphRTp4/0:0_2} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false, suppressPersistence=false, suppressEventNotification=false}, originLocal=true, bypassUnmarshalling=false}]
  | Nov 14 18:49:13,121 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 1
  | Nov 14 18:49:13,122 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/v].  Queue size is 0
  | Nov 14 18:49:13,122 [main] TRACE InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional context.
  | Nov 14 18:49:13,122 [main] TRACE InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as null
  | Nov 14 18:49:13,122 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /v
  | Nov 14 18:49:13,123 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,123 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,122 [main] TRACE MVCCNodeHelper:wrapNodeForReading:129 - Node /hphRTp4/0:0_2 is not in context, fetching from container.
  | Nov 14 18:49:13,123 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,123 [main] TRACE CacheLoaderInterceptor:mustLoad:421 - Node [/hphRTp4/0:0_2] is null in memory.  Must load? true
  | Nov 14 18:49:13,123 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMTp2].  Queue size is 0
  | Nov 14 18:49:13,125 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMTp2
  | Nov 14 18:49:13,125 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,124 [main] TRACE CacheLoaderInterceptor:loadIfNeeded:293 - load element /hphRTp4/0:0_2 mustLoad=true
  | Nov 14 18:49:13,125 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,125 [main] TRACE MVCCLockManager:lockAndRecord:131 - Attempting to lock /hphRTp4/0:0_2
  | Nov 14 18:49:13,125 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,126 [main] TRACE TcpDelegatingCacheLoader:invokeWithRetries:129 - About to invoke operation protected boolean org.jboss.cache.loader.TcpDelegatingCacheLoader._exists(org.jboss.cache.Fqn) throws java.lang.Exception
  | Nov 14 18:49:13,126 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMRp4].  Queue size is 0
  | Nov 14 18:49:13,127 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMRp4
  | Nov 14 18:49:13,127 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,127 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,127 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,127 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMLp1].  Queue size is 0
  | Nov 14 18:49:13,128 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMLp1
  | Nov 14 18:49:13,128 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,129 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,129 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,130 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,130 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 1
  | Nov 14 18:49:13,130 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/m].  Queue size is 2
  | Nov 14 18:49:13,130 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /m
  | Nov 14 18:49:13,130 [EvictionTimer-0] DEBUG BaseEvictionAlgorithm:processVisitedNodes:438 - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
  | Nov 14 18:49:13,131 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processAddedNodes:333 - Adding node /m/1:576 with 1 elements to eviction queue
  | Nov 14 18:49:13,131 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processAddedNodes:359 - /m/1:576 added successfully to eviction queue
  | Nov 14 18:49:13,131 [EvictionTimer-0] DEBUG BaseEvictionAlgorithm:processVisitedNodes:438 - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
  | Nov 14 18:49:13,131 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processAddedNodes:333 - Adding node /m/1:575 with 1 elements to eviction queue
  | Nov 14 18:49:13,131 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processAddedNodes:359 - /m/1:575 added successfully to eviction queue
  | Nov 14 18:49:13,131 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 2 node events
  | Nov 14 18:49:13,132 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,132 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,132 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,132 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 15
  | Nov 14 18:49:13,133 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMVp4].  Queue size is 0
  | Nov 14 18:49:13,133 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMVp4
  | Nov 14 18:49:13,134 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,134 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,135 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,135 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphRTp2].  Queue size is 0
  | Nov 14 18:49:13,135 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphRTp2
  | Nov 14 18:49:13,135 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,135 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,136 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,136 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,136 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 1
  | Nov 14 18:49:13,136 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region /i].  Queue size is 0
  | Nov 14 18:49:13,136 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /i
  | Nov 14 18:49:13,137 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,137 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,137 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,137 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,137 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 18
  | Nov 14 18:49:13,138 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMVp1].  Queue size is 0
  | Nov 14 18:49:13,138 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMVp1
  | Nov 14 18:49:13,138 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,140 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,140 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,140 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMRp5].  Queue size is 0
  | Nov 14 18:49:13,141 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMRp5
  | Nov 14 18:49:13,141 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,141 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,141 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,142 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/cN].  Queue size is 0
  | Nov 14 18:49:13,142 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /cN
  | Nov 14 18:49:13,142 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,142 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,142 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,143 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/ibTHUMB].  Queue size is 0
  | Nov 14 18:49:13,143 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /ibTHUMB
  | Nov 14 18:49:13,143 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,143 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,143 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,144 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,144 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 21
  | Nov 14 18:49:13,145 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMVp5].  Queue size is 0
  | Nov 14 18:49:13,145 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMVp5
  | Nov 14 18:49:13,145 [main] TRACE TcpDelegatingCacheLoader:invokeWithRetries:131 - Completed invocation of protected boolean org.jboss.cache.loader.TcpDelegatingCacheLoader._exists(org.jboss.cache.Fqn) throws java.lang.Exception
  | Nov 14 18:49:13,146 [main] TRACE MVCCNodeFactory:createChildNode:175 - Created new child with fqn [/hphRTp4/0:0_2]
  | Nov 14 18:49:13,147 [main] TRACE MVCCNodeHelper:wrapNodeForReading:136 - Node /hphRTp4 is already in context.
  | Nov 14 18:49:13,147 [main] TRACE MVCCNodeHelper:wrapNodeForReading:136 - Node /hphRTp4/0:0_2 is already in context.
  | Nov 14 18:49:13,147 [main] TRACE CallInterceptor:handleDefault:98 - Executing command: GetNodeCommand{fqn=/hphRTp4/0:0_2}.
  | Nov 14 18:49:13,148 [main] TRACE GetNodeCommand:perform:70 - Found node, returning NodeReference{delegate=UnversionedNode[ /hphRTp4/0:0_2]}
  | Nov 14 18:49:13,148 [main] TRACE RegionManagerImpl:getRegion:223 - Contents of RegionsRegistry: {/hphRRp1=RegionImpl{fqn=/hphRRp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /uN=RegionImpl{fqn=/uN; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp2=RegionImpl{fqn=/rdp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp1=RegionImpl{fqn=/hphMRp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp4=RegionImpl{fqn=/hphRRp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp4=RegionImpl{fqn=/rdp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp1=RegionImpl{fqn=/rdp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rXY=RegionImpl{fqn=/rXY; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /=RegionImpl{fqn=/; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rDCB=RegionImpl{fqn=/rDCB; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /uF=RegionImpl{fqn=/uF; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp5=RegionImpl{fqn=/hphMLp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp3=RegionImpl{fqn=/hphRRp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp4=RegionImpl{fqn=/hphMLp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /test=RegionImpl{fqn=/test; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp2=RegionImpl{fqn=/hphMVp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp3=RegionImpl{fqn=/hphMLp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp1=RegionImpl{fqn=/hphRTp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /ibPREVIEW=RegionImpl{fqn=/ibPREVIEW; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /mC=RegionImpl{fqn=/mC; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /u=RegionImpl{fqn=/u; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp3=RegionImpl{fqn=/hphMVp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp5=RegionImpl{fqn=/hphRRp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp2=RegionImpl{fqn=/hphMLp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /v=RegionImpl{fqn=/v; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp2=RegionImpl{fqn=/hphMTp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp4=RegionImpl{fqn=/hphMRp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp1=RegionImpl{fqn=/hphMLp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /m=RegionImpl{fqn=/m; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp4=RegionImpl{fqn=/hphMVp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp2=RegionImpl{fqn=/hphRTp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /i=RegionImpl{fqn=/i; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp1=RegionImpl{fqn=/hphMVp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp5=RegionImpl{fqn=/hphMRp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /cN=RegionImpl{fqn=/cN; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /ibTHUMB=RegionImpl{fqn=/ibTHUMB; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp5=RegionImpl{fqn=/hphMVp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp2=RegionImpl{fqn=/hphMRp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /aC=RegionImpl{fqn=/aC; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /mR=RegionImpl{fqn=/mR; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp3=RegionImpl{fqn=/hphMTp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp5=RegionImpl{fqn=/hphRTp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=2}, /pN=RegionImpl{fqn=/pN; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp5=RegionImpl{fqn=/hphMTp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp4=RegionImpl{fqn=/hphRTp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=1}, /r=RegionImpl{fqn=/r; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp3=RegionImpl{fqn=/hphMRp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp3=RegionImpl{fqn=/rdp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp2=RegionImpl{fqn=/hphRRp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp3=RegionImpl{fqn=/hphRTp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=2}, /hphMTp4=RegionImpl{fqn=/hphMTp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp1=RegionImpl{fqn=/hphMTp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp5=RegionImpl{fqn=/rdp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}}
  | Nov 14 18:49:13,152 [main] TRACE RegionManagerImpl:getRegion:271 - Trying next region /hphRTp4 and got RegionImpl{fqn=/hphRTp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=1}
  | 
  | 
  | Nov 14 18:49:13,152 [main] TRACE EvictionInterceptor:registerEvictionEventToRegionManager:254 - Registering event VISIT_NODE_EVENT on node /hphRTp4/0:0_2
  | Nov 14 18:49:13,153 [main] TRACE ReadCommittedNode:commitUpdate:136 - Updating node [/hphRTp4/0:0_2].  deleted=false valid=true changed=true created=true
  | Nov 14 18:49:13,153 [main] TRACE MVCCLockingInterceptor:cleanupLocks:374 - Releasing lock on [/hphRTp4/0:0_2] for owner Thread[main,5,main]
  | Nov 14 18:49:13,153 [main] TRACE MVCCLockManager:unlock:145 - Attempting to unlock /hphRTp4/0:0_2
  | Nov 14 18:49:13,154 [main] TRACE InvocationContextInterceptor:handleAll:208 - Resetting invocation-scope options
  | Nov 14 18:49:13,154 [main] TRACE ComponentRegistry:invocationsAllowed:880 - Testing if invocations are allowed.
  | Nov 14 18:49:13,154 [main] TRACE InvocationContextInterceptor:handleAll:141 - Invoked with command PutKeyValueCommand{fqn=/hphRTp4/0:0_2, dataVersion=null, globalTransaction=null, key=d, value=null} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false, suppressPersistence=false, suppressEventNotification=false}, originLocal=true, bypassUnmarshalling=false}]
  | Nov 14 18:49:13,155 [main] TRACE InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional context.
  | Nov 14 18:49:13,156 [main] TRACE InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as null
  | Nov 14 18:49:13,157 [main] TRACE MVCCNodeHelper:wrapNodeForReading:129 - Node /hphRTp4/0:0_2 is not in context, fetching from container.
  | Nov 14 18:49:13,157 [main] TRACE CacheLoaderInterceptor:mustLoad:454 - Must load node [/hphRTp4/0:0_2], uninitialized
  | Nov 14 18:49:13,157 [main] TRACE CacheLoaderInterceptor:loadIfNeeded:293 - load element /hphRTp4/0:0_2 mustLoad=true
  | Nov 14 18:49:13,147 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,158 [main] TRACE MVCCLockManager:lockAndRecord:131 - Attempting to lock /hphRTp4/0:0_2
  | Nov 14 18:49:13,158 [main] TRACE CacheLoaderInterceptor:loadData:509 - Attempting to load data for /hphRTp4/0:0_2
  | Nov 14 18:49:13,159 [main] TRACE TcpDelegatingCacheLoader:invokeWithRetries:129 - About to invoke operation protected java.util.Map org.jboss.cache.loader.TcpDelegatingCacheLoader._get(org.jboss.cache.Fqn) throws java.lang.Exception
  | Nov 14 18:49:13,158 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,159 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,159 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMRp2].  Queue size is 0
  | Nov 14 18:49:13,160 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMRp2
  | Nov 14 18:49:13,160 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,161 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,161 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,161 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/aC].  Queue size is 0
  | Nov 14 18:49:13,161 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /aC
  | Nov 14 18:49:13,162 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,162 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,162 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,162 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/mR].  Queue size is 0
  | Nov 14 18:49:13,162 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /mR
  | Nov 14 18:49:13,163 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,163 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,163 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,163 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMTp3].  Queue size is 0
  | Nov 14 18:49:13,164 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMTp3
  | Nov 14 18:49:13,164 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,164 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,164 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,164 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphRTp5].  Queue size is 2
  | Nov 14 18:49:13,165 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphRTp5
  | Nov 14 18:49:13,165 [EvictionTimer-0] DEBUG BaseEvictionAlgorithm:processVisitedNodes:438 - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
  | Nov 14 18:49:13,166 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processAddedNodes:333 - Adding node /hphRTp5/0:0_2 with 1 elements to eviction queue
  | Nov 14 18:49:13,166 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processAddedNodes:359 - /hphRTp5/0:0_2 added successfully to eviction queue
  | Nov 14 18:49:13,167 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 2 node events
  | Nov 14 18:49:13,167 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,167 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,167 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,168 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 3
  | Nov 14 18:49:13,168 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/pN].  Queue size is 0
  | Nov 14 18:49:13,168 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /pN
  | Nov 14 18:49:13,168 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,168 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,169 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,169 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,169 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 1
  | Nov 14 18:49:13,169 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMTp5].  Queue size is 0
  | Nov 14 18:49:13,170 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMTp5
  | Nov 14 18:49:13,170 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,170 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,170 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,174 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphRTp4].  Queue size is 2
  | Nov 14 18:49:13,174 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphRTp4
  | Nov 14 18:49:13,174 [EvictionTimer-0] DEBUG BaseEvictionAlgorithm:processVisitedNodes:438 - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
  | Nov 14 18:49:13,176 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processAddedNodes:333 - Adding node /hphRTp4/0:0_2 with 1 elements to eviction queue
  | Nov 14 18:49:13,177 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processAddedNodes:359 - /hphRTp4/0:0_2 added successfully to eviction queue
  | Nov 14 18:49:13,177 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 2 node events
  | Nov 14 18:49:13,177 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,177 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,177 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,178 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 3
  | Nov 14 18:49:13,178 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/r].  Queue size is 0
  | Nov 14 18:49:13,178 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /r
  | Nov 14 18:49:13,178 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,178 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,179 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,179 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMRp3].  Queue size is 0
  | Nov 14 18:49:13,179 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMRp3
  | Nov 14 18:49:13,179 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,179 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,182 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,182 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/rdp3].  Queue size is 0
  | Nov 14 18:49:13,182 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /rdp3
  | Nov 14 18:49:13,183 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,183 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,186 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,186 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphRRp2].  Queue size is 0
  | Nov 14 18:49:13,186 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphRRp2
  | Nov 14 18:49:13,186 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,187 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,188 [main] TRACE TcpDelegatingCacheLoader:invokeWithRetries:131 - Completed invocation of protected java.util.Map org.jboss.cache.loader.TcpDelegatingCacheLoader._get(org.jboss.cache.Fqn) throws java.lang.Exception
  | Nov 14 18:49:13,188 [main] TRACE CacheLoaderInterceptor:loadData:512 - Node /hphRTp4/0:0_2 exists? true
  | Nov 14 18:49:13,188 [main] TRACE CacheLoaderInterceptor:setNodeState:469 - setNodeState node is UnversionedNode[ /hphRTp4/0:0_2]
  | Nov 14 18:49:13,189 [main] TRACE UnversionedNode:setValid:595 - Marking node /hphRTp4/0:0_2 as valid
  | Nov 14 18:49:13,189 [main] TRACE CacheLoaderInterceptor:setNodeState:502 - Setting dataLoaded to true
  | Nov 14 18:49:13,190 [main] TRACE PutKeyValueCommand:perform:76 - Perform('null', '/hphRTp4/0:0_2', k='d', v='null')
  | Nov 14 18:49:13,192 [main] TRACE PutKeyValueCommand:perform:88 - Old value is null, dataLoaded=true
  | Nov 14 18:49:13,189 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,192 [main] TRACE RegionManagerImpl:getRegion:223 - Contents of RegionsRegistry: {/hphRRp1=RegionImpl{fqn=/hphRRp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /uN=RegionImpl{fqn=/uN; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp2=RegionImpl{fqn=/rdp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp1=RegionImpl{fqn=/hphMRp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp4=RegionImpl{fqn=/hphRRp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp4=RegionImpl{fqn=/rdp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp1=RegionImpl{fqn=/rdp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rXY=RegionImpl{fqn=/rXY; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /=RegionImpl{fqn=/; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rDCB=RegionImpl{fqn=/rDCB; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /uF=RegionImpl{fqn=/uF; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp5=RegionImpl{fqn=/hphMLp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp3=RegionImpl{fqn=/hphRRp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp4=RegionImpl{fqn=/hphMLp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /test=RegionImpl{fqn=/test; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp2=RegionImpl{fqn=/hphMVp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp3=RegionImpl{fqn=/hphMLp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp1=RegionImpl{fqn=/hphRTp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /ibPREVIEW=RegionImpl{fqn=/ibPREVIEW; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /mC=RegionImpl{fqn=/mC; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /u=RegionImpl{fqn=/u; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp3=RegionImpl{fqn=/hphMVp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp5=RegionImpl{fqn=/hphRRp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp2=RegionImpl{fqn=/hphMLp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /v=RegionImpl{fqn=/v; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp2=RegionImpl{fqn=/hphMTp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp4=RegionImpl{fqn=/hphMRp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMLp1=RegionImpl{fqn=/hphMLp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /m=RegionImpl{fqn=/m; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp4=RegionImpl{fqn=/hphMVp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp2=RegionImpl{fqn=/hphRTp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /i=RegionImpl{fqn=/i; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp1=RegionImpl{fqn=/hphMVp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp5=RegionImpl{fqn=/hphMRp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /cN=RegionImpl{fqn=/cN; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /ibTHUMB=RegionImpl{fqn=/ibTHUMB; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMVp5=RegionImpl{fqn=/hphMVp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp2=RegionImpl{fqn=/hphMRp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /aC=RegionImpl{fqn=/aC; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /mR=RegionImpl{fqn=/mR; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp3=RegionImpl{fqn=/hphMTp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp5=RegionImpl{fqn=/hphRTp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /pN=RegionImpl{fqn=/pN; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp5=RegionImpl{fqn=/hphMTp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp4=RegionImpl{fqn=/hphRTp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /r=RegionImpl{fqn=/r; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMRp3=RegionImpl{fqn=/hphMRp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp3=RegionImpl{fqn=/rdp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRRp2=RegionImpl{fqn=/hphRRp2; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphRTp3=RegionImpl{fqn=/hphRTp3; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=2}, /hphMTp4=RegionImpl{fqn=/hphMTp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /hphMTp1=RegionImpl{fqn=/hphMTp1; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}, /rdp5=RegionImpl{fqn=/rdp5; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}}
  | Nov 14 18:49:13,194 [main] TRACE RegionManagerImpl:getRegion:271 - Trying next region /hphRTp4 and got RegionImpl{fqn=/hphRTp4; classloader=null; status=ACTIVE; eviction=true; evictionQueueSize=0}
  | Nov 14 18:49:13,194 [main] TRACE EvictionInterceptor:registerEvictionEventToRegionManager:254 - Registering event ADD_ELEMENT_EVENT on node /hphRTp4/0:0_2
  | Nov 14 18:49:13,194 [main] TRACE TcpDelegatingCacheLoader:invokeWithRetries:129 - About to invoke operation protected java.lang.Object 
  | org.jboss.cache.loader.TcpDelegatingCacheLoader._put(org.jboss.cache.Fqn,java.lang.Object,java.lang.Object) throws java.lang.Exception
  | 
  | Nov 14 18:49:13,192 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,197 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 1
  | Nov 14 18:49:13,197 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphRTp3].  Queue size is 2
  | Nov 14 18:49:13,197 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphRTp3
  | Nov 14 18:49:13,197 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 2 node events
  | Nov 14 18:49:13,197 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,199 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,199 [EvictionTimer-0] TRACE LRUAlgorithm:shouldEvictNode:64 - No idle or max time limit!
  | Nov 14 18:49:13,199 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 3
  | Nov 14 18:49:13,199 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMTp4].  Queue size is 0
  | Nov 14 18:49:13,200 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMTp4
  | Nov 14 18:49:13,200 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,200 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,200 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,201 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/hphMTp1].  Queue size is 0
  | Nov 14 18:49:13,201 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:process:142 - process(): region: /hphMTp1
  | Nov 14 18:49:13,201 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:processQueues:223 - processed 0 node events
  | Nov 14 18:49:13,201 [EvictionTimer-0] TRACE BaseEvictionAlgorithm:emptyRecycleQueue:522 - Recycle queue is empty
  | Nov 14 18:49:13,202 [EvictionTimer-0] TRACE LRUQueue:getNumberOfNodes:172 - LRUQUeue.size() = 0
  | Nov 14 18:49:13,203 [EvictionTimer-0] TRACE RegionImpl:processEvictionQueues:127 - Processing eviction queue for region [/rdp5].  Queue si

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

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




More information about the jboss-user mailing list