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

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#... Reply to the post : http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&a...