[JBoss JIRA] (ISPN-3834) New advanced indexing flag to skip deletion of previous entry
by Sanne Grinovero (JIRA)
[ https://issues.jboss.org/browse/ISPN-3834?page=com.atlassian.jira.plugin.... ]
Sanne Grinovero commented on ISPN-3834:
---------------------------------------
-1 automating detection is tricky to get correct.
I understand where you're coming from, and this is the reason why we still didn't have this flag after years of us knowing the need for this optimization: this has been brought up multiple times, but never resulted in any corrective action. Adding the Flag finally would allow advanced users to hate it behave like it needs, it doesn't prevent us to research improvements in future to automatically trigger the same optimization, but it's always going to be good to have a way to force the behavior.
> New advanced indexing flag to skip deletion of previous entry
> -------------------------------------------------------------
>
> Key: ISPN-3834
> URL: https://issues.jboss.org/browse/ISPN-3834
> Project: Infinispan
> Issue Type: Enhancement
> Components: Querying
> Reporter: Sanne Grinovero
> Assignee: Sanne Grinovero
> Labels: 620
> Fix For: 6.1.0.Final
>
>
> I'm needing to add a org.infinispan.context.Flag.SKIP_INDEX_CLEANUP which does not issue an UPDATE index command but a simple ADD.
> Just ADD is way more efficient, just we can't automatically detect it safely so I need a flag to allow for efficient data import.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years
[JBoss JIRA] (ISPN-3845) CACHE_MODE_LOCAL flag only works in primary owner for non-tx caches
by Pedro Ruivo (JIRA)
Pedro Ruivo created ISPN-3845:
---------------------------------
Summary: CACHE_MODE_LOCAL flag only works in primary owner for non-tx caches
Key: ISPN-3845
URL: https://issues.jboss.org/browse/ISPN-3845
Project: Infinispan
Issue Type: Bug
Affects Versions: 6.0.0.Final
Reporter: Pedro Ruivo
Assignee: Pedro Ruivo
Fix For: 6.1.0.Final
the flag is not forcing the EntryWrappingInterceptor to wrap the entry. the result is the entry will not be stored in the cache.
It's causing the random failures in:
{noformat}
HotRodReplicationTest.testReplicatedPutWithTopologyChanges
HotRod11ReplicationTest.testReplicatedPutWithTopologyChanges
HotRod12ReplicationTest.testReplicatedPutWithTopologyChanges
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years
[JBoss JIRA] (ISPN-3473) CDI Cache interceptor tests are failing while running in Tomcat container
by Jozef Hartinger (JIRA)
[ https://issues.jboss.org/browse/ISPN-3473?page=com.atlassian.jira.plugin.... ]
Jozef Hartinger commented on ISPN-3473:
---------------------------------------
This is caused by WELD-1543
> CDI Cache interceptor tests are failing while running in Tomcat container
> -------------------------------------------------------------------------
>
> Key: ISPN-3473
> URL: https://issues.jboss.org/browse/ISPN-3473
> Project: Infinispan
> Issue Type: Bug
> Components: CDI integration
> Affects Versions: 6.0.0.Alpha3
> Reporter: Anna Manukyan
> Assignee: Galder Zamarreño
> Labels: 620
>
> There is a problem with Infinispan CDI interceptors under the Tomcat container.
> While running the infinispan/cdi-extension module's tests under the tomcat container, the following 2 related issues appear:
> 1) When the beans.xml contains the definition for the interceptors, as given below:
> {code}
> <beans xmlns="http://java.sun.com/xml/ns/javaee"
> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
> xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/beans_1_0.xsd">
> <interceptors>
> <class>org.infinispan.jcache.annotation.CacheResultInterceptor</class>
> <class>org.infinispan.jcache.annotation.CachePutInterceptor</class>
> <class>org.infinispan.jcache.annotation.CacheRemoveEntryInterceptor</class>
> <class>org.infinispan.jcache.annotation.CacheRemoveAllInterceptor</class>
> </interceptors>
> <alternatives>
> <class>org.infinispan.cdi.InjectedCacheResolver</class>
> </alternatives>
> </beans>
> {code}
> Then while the deployment on the container, the following exception is thrown:
> {code}
> org.jboss.weld.exceptions.DeploymentException: WELD-001416 Enabled interceptor class [<class>org.infinispan.jcache.annotation.CacheResultInterceptor</class> in jar:file:/home/anna.manukyan/.jenkins/jobs/invm-tomcat/workspace/tomcat-server/jboss-ews-2.0/tomcat7/webapps/test/WEB-INF/lib/infinispan-jcache.jar!/META-INF/beans.xml@7, <class>org.infinispan.jcache.annotation.CachePutInterceptor</class> in jar:file:/home/anna.manukyan/.jenkins/jobs/invm-tomcat/workspace/tomcat-server/jboss-ews-2.0/tomcat7/webapps/test/WEB-INF/lib/infinispan-jcache.jar!/META-INF/beans.xml@8, <class>org.infinispan.jcache.annotation.CacheRemoveEntryInterceptor</class> in jar:file:/home/anna.manukyan/.jenkins/jobs/invm-tomcat/workspace/tomcat-server/jboss-ews-2.0/tomcat7/webapps/test/WEB-INF/lib/infinispan-jcache.jar!/META-INF/beans.xml@9, <class>org.infinispan.jcache.annotation.CacheRemoveAllInterceptor</class> in jar:file:/home/anna.manukyan/.jenkins/jobs/invm-tomcat/workspace/tomcat-server/jboss-ews-2.0/tomcat7/webapps/test/WEB-INF/lib/infinispan-jcache.jar!/META-INF/beans.xml@10, <class>org.infinispan.jcache.annotation.CacheResultInterceptor</class> in jndi:/localhost/test/WEB-INF/beans.xml@29, <class>org.infinispan.jcache.annotation.CachePutInterceptor</class> in jndi:/localhost/test/WEB-INF/beans.xml@30, <class>org.infinispan.jcache.annotation.CacheRemoveEntryInterceptor</class> in jndi:/localhost/test/WEB-INF/beans.xml@31, <class>org.infinispan.jcache.annotation.CacheRemoveAllInterceptor</class> in jndi:/localhost/test/WEB-INF/beans.xml@32] specified twice
> at org.jboss.weld.manager.Enabled.createMetadataMap(Enabled.java:123)
> at org.jboss.weld.manager.Enabled.<init>(Enabled.java:96)
> at org.jboss.weld.manager.Enabled.of(Enabled.java:79)
> at org.jboss.weld.bootstrap.BeanDeployment.<init>(BeanDeployment.java:114)
> at org.jboss.weld.bootstrap.WeldBootstrap$DeploymentVisitor.visit(WeldBootstrap.java:183)
> at org.jboss.weld.bootstrap.WeldBootstrap$DeploymentVisitor.visit(WeldBootstrap.java:152)
> at org.jboss.weld.bootstrap.WeldBootstrap.startContainer(WeldBootstrap.java:283)
> at org.jboss.weld.environment.servlet.Listener.contextInitialized(Listener.java:151)
> at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4791)
> at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5285)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
> at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:901)
> at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:877)
> at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:618)
> at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:963)
> at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:537)
> at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1468)
> at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at org.apache.tomcat.util.modeler.BaseModelMBean.invoke(BaseModelMBean.java:301)
> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819)
> at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:791)
> at org.apache.catalina.manager.ManagerServlet.check(ManagerServlet.java:1444)
> at org.apache.catalina.manager.ManagerServlet.deploy(ManagerServlet.java:677)
> at org.apache.catalina.manager.ManagerServlet.doPut(ManagerServlet.java:435)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:644)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
> at org.apache.catalina.filters.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:108)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
> at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:581)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
> at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1002)
> at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:585)
> at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:312)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:722)
> {code}
> If there is no need declare the interceptors in the beans.xml (as far as I know it is necessary), then please let me know and ignore this case.
> 2) When the interceptors declaration is commented, then the interceptors doesn't work properly. So all tests located under the package org.infinispan.cdi.test.interceptor.* are failing with assertion errors.
> Please note that this behaviour is noticed for infinispan 6.0.0.Alpha3. It is not tried for the earlier versions.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years
[JBoss JIRA] (ISPN-3795) QueryInterceptor incorrectly relies on the return value of a RemoveCommand
by Sanne Grinovero (JIRA)
[ https://issues.jboss.org/browse/ISPN-3795?page=com.atlassian.jira.plugin.... ]
Sanne Grinovero commented on ISPN-3795:
---------------------------------------
I agree but that's a known limitation: you might remember the problem with _putAll_ ...
We don't expect people to use Flags randomly and getting away with it unpunished ;-)
As a side note, I've been toying with the idea of looking if the IGNORE_PREVIOUS_VALUES or variations such as the one skipping load from a CacheStore is set, to see if I could use the ADD INDEX command rather than UPDATE .. (from the chat we had on github), but that seems to get very tricky, especially if you start considering corner scenarios like flag behaviour during state transfer / eviction and others.
I think the QueryInterceptor needs to play safe by default, but yes if the user forces Flags all bets are off.. he better knows what he's doing. Side note: not so sure we should document all these flags as public APIs.
> QueryInterceptor incorrectly relies on the return value of a RemoveCommand
> --------------------------------------------------------------------------
>
> Key: ISPN-3795
> URL: https://issues.jboss.org/browse/ISPN-3795
> Project: Infinispan
> Issue Type: Bug
> Components: Querying
> Affects Versions: 6.0.0.Final
> Reporter: Dan Berindei
> Assignee: Sanne Grinovero
> Fix For: 7.0.0.Final
>
>
> QueryInterceptor uses the return value from RemoveCommand/ReplaceCommand to remove the value from the index.
> But both RemoveCommand and ReplaceCommand have a variant with an expected value parameter, and this variant return a boolean value instead of the removed/replaced value. In that case, the previous value won't be removed from the index.
> QueryInterceptor should probably use the previous value from the context entries to update the index instead.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years
[JBoss JIRA] (ISPN-3795) QueryInterceptor incorrectly relies on the return value of a RemoveCommand
by Adrian Nistor (JIRA)
[ https://issues.jboss.org/browse/ISPN-3795?page=com.atlassian.jira.plugin.... ]
Adrian Nistor commented on ISPN-3795:
-------------------------------------
I wonder if this problem regarding previous values is a bit broader. I suspect even a normal put with IGNORE_PREVIOUS_VALUES can lead to the same kind of problem.
> QueryInterceptor incorrectly relies on the return value of a RemoveCommand
> --------------------------------------------------------------------------
>
> Key: ISPN-3795
> URL: https://issues.jboss.org/browse/ISPN-3795
> Project: Infinispan
> Issue Type: Bug
> Components: Querying
> Affects Versions: 6.0.0.Final
> Reporter: Dan Berindei
> Assignee: Sanne Grinovero
> Fix For: 7.0.0.Final
>
>
> QueryInterceptor uses the return value from RemoveCommand/ReplaceCommand to remove the value from the index.
> But both RemoveCommand and ReplaceCommand have a variant with an expected value parameter, and this variant return a boolean value instead of the removed/replaced value. In that case, the previous value won't be removed from the index.
> QueryInterceptor should probably use the previous value from the context entries to update the index instead.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years
[JBoss JIRA] (ISPN-3834) New advanced indexing flag to skip deletion of previous entry
by Adrian Nistor (JIRA)
[ https://issues.jboss.org/browse/ISPN-3834?page=com.atlassian.jira.plugin.... ]
Adrian Nistor commented on ISPN-3834:
-------------------------------------
Efficiently and reliably detecting the presence of a previous value is crucial also for ISPN-3795, not just for this perf improvement. I would ponder this a bit more before adding a new _unsafe_ flag.
> New advanced indexing flag to skip deletion of previous entry
> -------------------------------------------------------------
>
> Key: ISPN-3834
> URL: https://issues.jboss.org/browse/ISPN-3834
> Project: Infinispan
> Issue Type: Enhancement
> Components: Querying
> Reporter: Sanne Grinovero
> Assignee: Sanne Grinovero
> Labels: 620
> Fix For: 6.1.0.Final
>
>
> I'm needing to add a org.infinispan.context.Flag.SKIP_INDEX_CLEANUP which does not issue an UPDATE index command but a simple ADD.
> Just ADD is way more efficient, just we can't automatically detect it safely so I need a flag to allow for efficient data import.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years
[JBoss JIRA] (ISPN-3842) Inconsistent L1 in non-tx distributed cache in certain circumstances
by Mikolaj Gierulski (JIRA)
[ https://issues.jboss.org/browse/ISPN-3842?page=com.atlassian.jira.plugin.... ]
Mikolaj Gierulski commented on ISPN-3842:
-----------------------------------------
Ok, so here are my full logs, but I'm not sure this will be sufficient. I set trace level for some infinispan packages and all other infinispan packages are set to debug. I left some of my own logs. I do element updates by sending a DistributedCallable from node A to B.
The problem occurs at 10:25:43.559.
Node A
{noformat}
10:25:38,672 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
10:25:38,672 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
10:25:38,673 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/C:/projekty/workspace/infinispan-scratch/target/classes/logback.xml]
10:25:38,764 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
10:25:38,769 |-INFO in ReconfigureOnChangeFilter{invocationCounter=0} - Will scan for changes in [[C:\projekty\workspace\infinispan-scratch\target\classes\logback.xml]] every 60 seconds.
10:25:38,769 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
10:25:38,782 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
10:25:38,785 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
10:25:38,868 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - This appender no longer admits a layout as a sub-component, set an encoder instead.
10:25:38,868 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - To ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
10:25:38,868 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - See also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
10:25:38,868 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.read.ListAppender]
10:25:38,869 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ISPN]
10:25:38,869 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.eclipse.jetty] to INFO
10:25:38,869 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.springframework] to INFO
10:25:38,869 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan] to DEBUG
10:25:38,870 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.commands.write.InvalidateL1Command] to TRACE
10:25:38,870 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.commands.write.InvalidateCommand] to TRACE
10:25:38,870 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.interceptors.distribution.L1WriteSynchronizer] to TRACE
10:25:38,870 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.distribution.L1ManagerImpl] to TRACE
10:25:38,870 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.interceptors.distribution.L1LastChanceInterceptor] to TRACE
10:25:38,870 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.interceptors.distribution.L1NonTxInterceptor] to TRACE
10:25:38,870 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.commands.write.RemoveCommand] to TRACE
10:25:38,870 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.distexec.DefaultExecutorService] to TRACE
10:25:38,870 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [pl.com.agora] to INFO
10:25:38,871 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - ROOT level set to INFO
10:25:38,871 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
10:25:38,871 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
10:25:38,873 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@1f016962 - Registering current configuration as safe fallback point
10:25:39.056 [main] DEBUG org.infinispan.util.ModuleProperties - No module lifecycle SPI classes available
10:25:39.133 [main] DEBUG org.infinispan.util.ModuleProperties - No module command extensions to load
10:25:39.202 [main] DEBUG o.i.manager.DefaultCacheManager - Started cache manager 60testCluster on null
10:25:39.331 [main] INFO o.i.r.t.jgroups.JGroupsTransport - ISPN000078: Starting JGroups Channel
10:25:40.074 [main] INFO org.jgroups.protocols.UFC - UFC is not needed (and can be removed) as we're running on a TCP transport
10:25:40.283 [main] DEBUG o.i.r.t.jgroups.JGroupsTransport - New view accepted: [AGST-2012000591-36869|1] (2) [AGST-2012000591-36869, AGST-2012000591-51775]
10:25:40.283 [main] INFO o.i.r.t.jgroups.JGroupsTransport - ISPN000094: Received new cluster view: [AGST-2012000591-36869|1] (2) [AGST-2012000591-36869, AGST-2012000591-51775]
10:25:40.490 [main] INFO o.i.r.t.jgroups.JGroupsTransport - ISPN000079: Cache local address is AGST-2012000591-51775, physical addresses are [127.0.0.1:7801]
10:25:40.490 [main] DEBUG o.i.r.t.jgroups.JGroupsTransport - Waiting on view being accepted
10:25:40.494 [main] INFO o.i.f.GlobalComponentRegistry - ISPN000128: Infinispan version: Infinispan 'Infinium' 6.0.0.Final
10:25:40.640 [main] DEBUG o.i.interceptors.InterceptorChain - Interceptor chain size: 11
10:25:40.640 [main] DEBUG o.i.interceptors.InterceptorChain - Interceptor chain is:
>> org.infinispan.interceptors.InvocationContextInterceptor
>> org.infinispan.interceptors.CacheMgmtInterceptor
>> org.infinispan.statetransfer.StateTransferInterceptor
>> org.infinispan.statetransfer.TransactionSynchronizerInterceptor
>> org.infinispan.interceptors.NotificationInterceptor
>> org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor
>> org.infinispan.interceptors.distribution.L1LastChanceInterceptor
>> org.infinispan.interceptors.EntryWrappingInterceptor
>> org.infinispan.interceptors.distribution.L1NonTxInterceptor
>> org.infinispan.interceptors.distribution.NonTxDistributionInterceptor
>> org.infinispan.interceptors.CallInterceptor
10:25:40.647 [main] DEBUG org.infinispan.jmx.JmxUtil - Object name org.infinispan:type=Cache,name="distTest(dist_sync)",manager="DefaultCacheManager",component=Cache already registered
10:25:40.647 [main] INFO o.i.jmx.CacheJmxRegistration - ISPN000031: MBeans were successfully registered to the platform MBean server.
10:25:40.649 [main] DEBUG o.i.t.LocalTopologyManagerImpl - Node AGST-2012000591-51775 joining cache distTest
10:25:40.739 [main] DEBUG o.i.t.LocalTopologyManagerImpl - Updating local consistent hash(es) for cache distTest: new topology = CacheTopology{id=0, currentCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869]}, pendingCH=null}
10:25:40.743 [main] DEBUG o.i.transaction.TransactionTable - Topology changed, recalculating minTopologyId
10:25:40.744 [remote-thread-0] DEBUG o.i.t.LocalTopologyManagerImpl - Starting local rebalance for cache distTest, topology = CacheTopology{id=1, currentCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869]}, pendingCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869, AGST-2012000591-51775]}}
10:25:40.747 [remote-thread-0] DEBUG o.i.statetransfer.StateConsumerImpl - Removing state for segments [] of cache distTest
10:25:40.747 [remote-thread-0] DEBUG o.i.statetransfer.StateConsumerImpl - Removing state for segments not in [] or [] for cache distTest
10:25:40.747 [remote-thread-0] DEBUG o.i.statetransfer.StateConsumerImpl - Finished receiving of segments for cache distTest for topology 1.
10:25:40.748 [remote-thread-0] DEBUG o.i.transaction.TransactionTable - Topology changed, recalculating minTopologyId
10:25:40.752 [remote-thread-0] DEBUG o.i.t.LocalTopologyManagerImpl - Updating local consistent hash(es) for cache distTest: new topology = CacheTopology{id=2, currentCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869, AGST-2012000591-51775]}, pendingCH=null}
10:25:40.752 [remote-thread-0] DEBUG o.i.statetransfer.StateConsumerImpl - Removing state for segments [] of cache distTest
10:25:40.752 [remote-thread-0] DEBUG o.i.statetransfer.StateConsumerImpl - Removing state for segments not in [] or [] for cache distTest
10:25:40.752 [remote-thread-0] DEBUG o.i.transaction.TransactionTable - Topology changed, recalculating minTopologyId
10:25:40.753 [main] DEBUG org.infinispan.CacheImpl - Started cache distTest on AGST-2012000591-51775
10:25:41.801 [main] TRACE o.i.i.d.L1NonTxInterceptor - Not invalidating key 'K' as local node(AGST-2012000591-51775) is not owner
10:25:41.874 [main] TRACE o.i.i.d.L1NonTxInterceptor - Removing entry from L1 for key K
10:25:41.876 [main] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:41.907 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:42.443 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 1
10:25:42.447 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:42.483 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:42.483 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:42.490 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:42.492 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:42.492 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:42.495 [transport-thread-0] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 1 complete, task runtime millis 51
10:25:42.498 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:42.877 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 2
10:25:42.877 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:42.881 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:42.881 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:42.884 [transport-thread-1] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 2 complete, task runtime millis 6
10:25:42.884 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:42.885 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:42.886 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:42.888 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:42.990 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 3
10:25:42.990 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:42.996 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:42.996 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.002 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.004 [transport-thread-2] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 3 complete, task runtime millis 14
10:25:43.005 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.005 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.007 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.011 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 4
10:25:43.011 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:43.014 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.014 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.017 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.017 [transport-thread-3] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 4 complete, task runtime millis 6
10:25:43.017 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.018 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.020 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.078 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 5
10:25:43.078 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:43.082 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.082 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.084 [transport-thread-4] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 5 complete, task runtime millis 5
10:25:43.084 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.094 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 6
10:25:43.095 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:43.097 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.098 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.099 [transport-thread-5] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 6 complete, task runtime millis 4
10:25:43.100 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.128 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 7
10:25:43.129 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:43.132 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.132 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.134 [transport-thread-6] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 7 complete, task runtime millis 6
10:25:43.134 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.135 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.135 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.137 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.345 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 8
10:25:43.345 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:43.350 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.350 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.352 [transport-thread-7] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 8 complete, task runtime millis 7
10:25:43.353 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.354 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.354 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.357 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.398 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 9
10:25:43.398 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:43.408 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.408 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.411 [transport-thread-8] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 9 complete, task runtime millis 13
10:25:43.411 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.412 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.412 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.415 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.552 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 10
10:25:43.553 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:43.556 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.556 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.559 [transport-thread-9] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 10 complete, task runtime millis 6
10:25:43.559 [main] TRACE o.i.i.d.L1WriteSynchronizer - Caching remotely retrieved entry for key K in L1
10:25:43.559 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - L1 invalidation found a pending update for key K - need to block until finished
10:25:43.559 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Pending L1 update completed successfully: true - L1 invalidation can occur for key K
10:25:43.559 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
10:25:43.559 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
10:25:43.559 [remote-thread-0] TRACE o.i.commands.write.RemoveCommand - Nothing to remove since the entry is null or we have a null entry
10:25:43.645 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 11
10:25:43.646 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:43.650 [transport-thread-10] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 11 complete, task runtime millis 4
10:25:43.664 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 12
10:25:43.664 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:43.667 [transport-thread-11] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 12 complete, task runtime millis 3
10:25:44.427 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 13
10:25:44.427 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:44.430 [transport-thread-12] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 13 complete, task runtime millis 3
10:25:44.448 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 14
10:25:44.448 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:44.451 [transport-thread-13] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 14 complete, task runtime millis 3
10:25:44.772 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 15
10:25:44.773 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:44.776 [transport-thread-14] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 15 complete, task runtime millis 3
10:25:44.865 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 16
10:25:44.865 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:44.873 [transport-thread-15] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 16 complete, task runtime millis 8
10:25:44.967 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 17
10:25:44.967 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:44.983 [transport-thread-16] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 17 complete, task runtime millis 15
10:25:45.079 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 18
10:25:45.079 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.085 [transport-thread-17] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 18 complete, task runtime millis 6
10:25:45.209 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 19
10:25:45.209 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.213 [transport-thread-18] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 19 complete, task runtime millis 3
10:25:45.279 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 20
10:25:45.280 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.286 [transport-thread-19] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 20 complete, task runtime millis 6
10:25:45.317 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 21
10:25:45.317 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.320 [transport-thread-20] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 21 complete, task runtime millis 3
10:25:45.339 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 22
10:25:45.340 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.347 [transport-thread-21] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 22 complete, task runtime millis 7
10:25:45.532 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 23
10:25:45.532 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.542 [transport-thread-22] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 23 complete, task runtime millis 10
10:25:45.621 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 24
10:25:45.621 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.625 [transport-thread-23] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 24 complete, task runtime millis 4
10:25:45.679 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 25
10:25:45.679 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.685 [transport-thread-24] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 25 complete, task runtime millis 6
10:25:45.965 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 26
10:25:45.965 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.967 [transport-thread-0] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 26 complete, task runtime millis 2
10:25:45.987 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 27
10:25:45.988 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:45.990 [transport-thread-1] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 27 complete, task runtime millis 3
10:25:46.125 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 28
10:25:46.125 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:46.138 [transport-thread-2] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 28 complete, task runtime millis 12
10:25:46.147 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 29
10:25:46.148 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:46.151 [transport-thread-3] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 29 complete, task runtime millis 3
10:25:46.639 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 30
10:25:46.640 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:46.643 [transport-thread-4] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 30 complete, task runtime millis 3
10:25:46.648 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 31
10:25:46.648 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:46.651 [transport-thread-5] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 31 complete, task runtime millis 3
10:25:46.726 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 32
10:25:46.726 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:46.730 [transport-thread-6] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 32 complete, task runtime millis 4
10:25:46.802 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 33
10:25:46.803 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:46.807 [transport-thread-7] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 33 complete, task runtime millis 4
10:25:46.910 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 34
10:25:46.911 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:46.913 [transport-thread-8] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 34 complete, task runtime millis 3
10:25:47.049 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 35
10:25:47.050 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:47.053 [transport-thread-9] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 35 complete, task runtime millis 3
10:25:47.269 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 36
10:25:47.269 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:47.273 [transport-thread-10] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 36 complete, task runtime millis 3
10:25:47.310 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 37
10:25:47.310 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:47.313 [transport-thread-11] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 37 complete, task runtime millis 3
10:25:47.347 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 38
10:25:47.347 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:47.351 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 39
10:25:47.351 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:47.352 [transport-thread-12] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 38 complete, task runtime millis 4
10:25:47.355 [transport-thread-13] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 39 complete, task runtime millis 4
10:25:47.687 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 40
10:25:47.688 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:47.690 [transport-thread-14] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 40 complete, task runtime millis 3
10:25:47.980 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 41
10:25:47.980 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:47.982 [transport-thread-15] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 41 complete, task runtime millis 2
10:25:48.000 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 42
10:25:48.001 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:48.004 [transport-thread-16] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 42 complete, task runtime millis 3
10:25:48.152 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 43
10:25:48.152 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:48.164 [transport-thread-17] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 43 complete, task runtime millis 12
10:25:48.194 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 44
10:25:48.194 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:48.198 [transport-thread-18] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 44 complete, task runtime millis 3
10:25:48.205 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 45
10:25:48.205 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:48.209 [transport-thread-19] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 45 complete, task runtime millis 4
10:25:48.715 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 46
10:25:48.715 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:48.718 [transport-thread-20] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 46 complete, task runtime millis 3
10:25:48.746 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 47
10:25:48.746 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:48.750 [transport-thread-21] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 47 complete, task runtime millis 3
10:25:48.870 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 48
10:25:48.870 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:48.873 [transport-thread-22] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 48 complete, task runtime millis 3
10:25:48.979 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 49
10:25:48.980 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:48.982 [transport-thread-23] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 49 complete, task runtime millis 2
10:25:49.074 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 50
10:25:49.074 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.084 [transport-thread-24] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 50 complete, task runtime millis 10
10:25:49.104 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 51
10:25:49.104 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.107 [transport-thread-0] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 51 complete, task runtime millis 3
10:25:49.236 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 52
10:25:49.237 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.240 [transport-thread-1] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 52 complete, task runtime millis 3
10:25:49.264 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 53
10:25:49.264 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.267 [transport-thread-2] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 53 complete, task runtime millis 3
10:25:49.316 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 54
10:25:49.316 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.321 [transport-thread-3] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 54 complete, task runtime millis 4
10:25:49.350 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 55
10:25:49.350 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.353 [transport-thread-4] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 55 complete, task runtime millis 3
10:25:49.377 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 56
10:25:49.377 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.381 [transport-thread-5] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 56 complete, task runtime millis 4
10:25:49.385 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 57
10:25:49.386 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.390 [transport-thread-6] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 57 complete, task runtime millis 4
10:25:49.406 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 58
10:25:49.407 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.410 [transport-thread-7] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 58 complete, task runtime millis 4
10:25:49.411 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 59
10:25:49.411 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.414 [transport-thread-8] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 59 complete, task runtime millis 3
10:25:49.544 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 60
10:25:49.544 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.547 [transport-thread-9] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 60 complete, task runtime millis 3
10:25:49.609 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 61
10:25:49.610 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.612 [transport-thread-10] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 61 complete, task runtime millis 2
10:25:49.624 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 62
10:25:49.625 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.641 [transport-thread-11] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 62 complete, task runtime millis 17
10:25:49.722 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 63
10:25:49.722 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.726 [transport-thread-12] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 63 complete, task runtime millis 4
10:25:49.841 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 64
10:25:49.841 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.844 [transport-thread-13] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 64 complete, task runtime millis 3
10:25:49.930 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 65
10:25:49.930 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.931 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 66
10:25:49.931 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:49.936 [transport-thread-14] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 65 complete, task runtime millis 6
10:25:49.937 [transport-thread-15] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 66 complete, task runtime millis 6
10:25:50.128 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 67
10:25:50.129 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:50.132 [transport-thread-16] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 67 complete, task runtime millis 3
10:25:50.299 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 68
10:25:50.300 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:50.304 [transport-thread-17] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 68 complete, task runtime millis 5
10:25:50.331 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 69
10:25:50.331 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:50.334 [transport-thread-18] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 69 complete, task runtime millis 3
10:25:50.539 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 70
10:25:50.540 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:50.543 [transport-thread-19] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 70 complete, task runtime millis 3
10:25:50.621 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 71
10:25:50.621 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:50.626 [transport-thread-20] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 71 complete, task runtime millis 5
10:25:50.919 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 72
10:25:50.919 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:50.922 [transport-thread-21] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 72 complete, task runtime millis 3
10:25:51.056 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 73
10:25:51.056 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:51.059 [transport-thread-22] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 73 complete, task runtime millis 3
10:25:51.179 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 74
10:25:51.179 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:51.182 [transport-thread-23] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 74 complete, task runtime millis 3
10:25:51.211 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 75
10:25:51.211 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:51.214 [transport-thread-24] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 75 complete, task runtime millis 3
10:25:51.259 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 76
10:25:51.260 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:51.265 [transport-thread-0] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 76 complete, task runtime millis 5
10:25:51.340 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 77
10:25:51.340 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:51.346 [transport-thread-1] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 77 complete, task runtime millis 6
10:25:51.420 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 78
10:25:51.420 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:51.433 [transport-thread-2] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 78 complete, task runtime millis 13
10:25:51.506 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Submitting write task no 79
10:25:51.506 [main] TRACE o.i.distexec.DefaultExecutorService - Sending null to remote execution at node AGST-2012000591-36869
10:25:51.516 [transport-thread-3] INFO pl.com.agora.ispn.scratch.IspnClient - Task no 79 complete, task runtime millis 10
10:25:52.760 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Node A reads : 10721066, writes : 79, element value read from cache : 10, element value expected : 79
10:25:52.763 [main] INFO pl.com.agora.ispn.scratch.IspnClient - Node A cache stats : clusterSize=2, entries=1, hits=10721067, misses=1, stores=1, retrievals=10721068
{noformat}
Node B
{noformat}
10:25:35,469 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
10:25:35,470 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
10:25:35,470 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/C:/projekty/workspace/infinispan-scratch/target/classes/logback.xml]
10:25:35,541 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
10:25:35,550 |-INFO in ReconfigureOnChangeFilter{invocationCounter=0} - Will scan for changes in [[C:\projekty\workspace\infinispan-scratch\target\classes\logback.xml]] every 60 seconds.
10:25:35,550 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
10:25:35,568 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
10:25:35,573 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
10:25:35,678 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - This appender no longer admits a layout as a sub-component, set an encoder instead.
10:25:35,678 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - To ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
10:25:35,678 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - See also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
10:25:35,678 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.read.ListAppender]
10:25:35,679 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ISPN]
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.eclipse.jetty] to INFO
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.springframework] to INFO
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan] to DEBUG
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.commands.write.InvalidateL1Command] to TRACE
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.commands.write.InvalidateCommand] to TRACE
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.interceptors.distribution.L1WriteSynchronizer] to TRACE
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.distribution.L1ManagerImpl] to TRACE
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.interceptors.distribution.L1LastChanceInterceptor] to TRACE
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.interceptors.distribution.L1NonTxInterceptor] to TRACE
10:25:35,680 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.commands.write.RemoveCommand] to TRACE
10:25:35,681 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.infinispan.distexec.DefaultExecutorService] to TRACE
10:25:35,681 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [pl.com.agora] to INFO
10:25:35,681 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - ROOT level set to INFO
10:25:35,681 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
10:25:35,681 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
10:25:35,683 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@28294944 - Registering current configuration as safe fallback point
10:25:35.878 [main] DEBUG org.infinispan.util.ModuleProperties - No module lifecycle SPI classes available
10:25:35.956 [main] DEBUG org.infinispan.util.ModuleProperties - No module command extensions to load
10:25:36.026 [main] DEBUG o.i.manager.DefaultCacheManager - Started cache manager 60testCluster on null
10:25:36.159 [main] INFO o.i.r.t.jgroups.JGroupsTransport - ISPN000078: Starting JGroups Channel
10:25:36.820 [main] INFO org.jgroups.protocols.UFC - UFC is not needed (and can be removed) as we're running on a TCP transport
10:25:39.882 [main] DEBUG o.i.r.t.jgroups.JGroupsTransport - New view accepted: [AGST-2012000591-36869|0] (1) [AGST-2012000591-36869]
10:25:39.882 [main] INFO o.i.r.t.jgroups.JGroupsTransport - ISPN000094: Received new cluster view: [AGST-2012000591-36869|0] (1) [AGST-2012000591-36869]
10:25:40.052 [main] INFO o.i.r.t.jgroups.JGroupsTransport - ISPN000079: Cache local address is AGST-2012000591-36869, physical addresses are [127.0.0.1:7800]
10:25:40.052 [main] DEBUG o.i.r.t.jgroups.JGroupsTransport - Waiting on view being accepted
10:25:40.059 [main] INFO o.i.f.GlobalComponentRegistry - ISPN000128: Infinispan version: Infinispan 'Infinium' 6.0.0.Final
10:25:40.223 [main] DEBUG o.i.interceptors.InterceptorChain - Interceptor chain size: 11
10:25:40.224 [main] DEBUG o.i.interceptors.InterceptorChain - Interceptor chain is:
>> org.infinispan.interceptors.InvocationContextInterceptor
>> org.infinispan.interceptors.CacheMgmtInterceptor
>> org.infinispan.statetransfer.StateTransferInterceptor
>> org.infinispan.statetransfer.TransactionSynchronizerInterceptor
>> org.infinispan.interceptors.NotificationInterceptor
>> org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor
>> org.infinispan.interceptors.distribution.L1LastChanceInterceptor
>> org.infinispan.interceptors.EntryWrappingInterceptor
>> org.infinispan.interceptors.distribution.L1NonTxInterceptor
>> org.infinispan.interceptors.distribution.NonTxDistributionInterceptor
>> org.infinispan.interceptors.CallInterceptor
10:25:40.233 [main] DEBUG org.infinispan.jmx.JmxUtil - Object name org.infinispan:type=Cache,name="distTest(dist_sync)",manager="DefaultCacheManager",component=Cache already registered
10:25:40.234 [main] INFO o.i.jmx.CacheJmxRegistration - ISPN000031: MBeans were successfully registered to the platform MBean server.
10:25:40.237 [main] DEBUG o.i.t.LocalTopologyManagerImpl - Node AGST-2012000591-36869 joining cache distTest
10:25:40.249 [main] DEBUG o.i.t.LocalTopologyManagerImpl - Updating local consistent hash(es) for cache distTest: new topology = CacheTopology{id=0, currentCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869]}, pendingCH=null}
10:25:40.253 [main] DEBUG o.i.statetransfer.StateConsumerImpl - Adding inbound state transfer for segments [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56, 63, 62, 61, 60, 68, 69, 70, 71, 64, 65, 66, 67, 76, 77, 78, 79, 72, 73, 74, 75, 85, 84, 87, 86, 81, 80, 83, 82, 93, 92, 95, 94, 89, 88, 91, 90, 98, 99, 96, 97] of cache distTest
10:25:40.254 [Incoming-1,AGST-2012000591-36869] DEBUG o.i.r.t.jgroups.JGroupsTransport - New view accepted: [AGST-2012000591-36869|1] (2) [AGST-2012000591-36869, AGST-2012000591-51775]
10:25:40.254 [Incoming-1,AGST-2012000591-36869] INFO o.i.r.t.jgroups.JGroupsTransport - ISPN000094: Received new cluster view: [AGST-2012000591-36869|1] (2) [AGST-2012000591-36869, AGST-2012000591-51775]
10:25:40.256 [main] DEBUG o.i.statetransfer.StateConsumerImpl - Finished adding inbound state transfer for segments [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56, 63, 62, 61, 60, 68, 69, 70, 71, 64, 65, 66, 67, 76, 77, 78, 79, 72, 73, 74, 75, 85, 84, 87, 86, 81, 80, 83, 82, 93, 92, 95, 94, 89, 88, 91, 90, 98, 99, 96, 97] of cache distTest
10:25:40.256 [main] DEBUG o.i.transaction.TransactionTable - Topology changed, recalculating minTopologyId
10:25:40.258 [main] DEBUG org.infinispan.CacheImpl - Started cache distTest on AGST-2012000591-36869
10:25:40.259 [main] INFO pl.com.agora.ispn.scratch.IspnServer - Created cache config capacity factor: 1.0
10:25:40.716 [transport-thread-2] DEBUG o.i.t.ClusterTopologyManagerImpl - Starting cluster-wide rebalance for cache distTest, topology = CacheTopology{id=1, currentCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869]}, pendingCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869, AGST-2012000591-51775]}}
10:25:40.719 [transport-thread-3] DEBUG o.i.t.LocalTopologyManagerImpl - Starting local rebalance for cache distTest, topology = CacheTopology{id=1, currentCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869]}, pendingCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869, AGST-2012000591-51775]}}
10:25:40.723 [transport-thread-3] DEBUG o.i.statetransfer.StateConsumerImpl - Removing state for segments [] of cache distTest
10:25:40.723 [transport-thread-3] DEBUG o.i.statetransfer.StateConsumerImpl - Removing state for segments not in [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56, 63, 62, 61, 60, 68, 69, 70, 71, 64, 65, 66, 67, 76, 77, 78, 79, 72, 73, 74, 75, 85, 84, 87, 86, 81, 80, 83, 82, 93, 92, 95, 94, 89, 88, 91, 90, 98, 99, 96, 97] or [] for cache distTest
10:25:40.724 [transport-thread-3] DEBUG o.i.statetransfer.StateConsumerImpl - Finished receiving of segments for cache distTest for topology 1.
10:25:40.725 [transport-thread-3] DEBUG o.i.transaction.TransactionTable - Topology changed, recalculating minTopologyId
10:25:40.725 [transport-thread-4] DEBUG o.i.t.ClusterTopologyManagerImpl - Finished local rebalance for cache distTest on node AGST-2012000591-36869, topology id = 1
10:25:40.748 [remote-thread-0] DEBUG o.i.t.ClusterTopologyManagerImpl - Finished local rebalance for cache distTest on node AGST-2012000591-51775, topology id = 1
10:25:40.748 [remote-thread-0] DEBUG o.i.t.ClusterTopologyManagerImpl - Finished cluster-wide rebalance for cache distTest, topology id = 1
10:25:40.749 [remote-thread-0] DEBUG o.i.t.ClusterTopologyManagerImpl - Updating cluster-wide consistent hash for cache distTest, topology = CacheTopology{id=2, currentCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869, AGST-2012000591-51775]}, pendingCH=null}
10:25:40.749 [transport-thread-5] DEBUG o.i.t.LocalTopologyManagerImpl - Updating local consistent hash(es) for cache distTest: new topology = CacheTopology{id=2, currentCH=DefaultConsistentHash{numSegments=100, numOwners=1, members=[AGST-2012000591-36869, AGST-2012000591-51775]}, pendingCH=null}
10:25:40.750 [transport-thread-5] DEBUG o.i.statetransfer.StateConsumerImpl - Removing state for segments [] of cache distTest
10:25:40.750 [transport-thread-5] DEBUG o.i.statetransfer.StateConsumerImpl - Removing state for segments not in [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56, 63, 62, 61, 60, 68, 69, 70, 71, 64, 65, 66, 67, 76, 77, 78, 79, 72, 73, 74, 75, 85, 84, 87, 86, 81, 80, 83, 82, 93, 92, 95, 94, 89, 88, 91, 90, 98, 99, 96, 97] or [] for cache distTest
10:25:40.750 [transport-thread-5] DEBUG o.i.transaction.TransactionTable - Topology changed, recalculating minTopologyId
10:25:41.788 [OOB-1,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:41.869 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:41.869 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:41.872 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:41.872 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:41.872 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:41.872 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:41.878 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:42.468 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:42.472 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:42.485 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:42.485 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:42.485 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:42.486 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:42.486 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 17
10:25:42.496 [OOB-1,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:42.879 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:42.880 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:42.882 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:42.882 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:42.882 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:42.882 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:42.883 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 3
10:25:42.887 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:42.993 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:42.994 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:42.998 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:42.998 [OOB-1,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:42.999 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:42.999 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.001 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 7
10:25:43.006 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.013 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:43.013 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.015 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:43.015 [OOB-1,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.015 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:43.016 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.016 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 3
10:25:43.019 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.080 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:43.081 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.083 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:43.083 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:43.083 [OOB-1,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.083 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:43.083 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 3
10:25:43.096 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:43.096 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.098 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:43.098 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:43.098 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:43.099 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.099 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 2
10:25:43.130 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:43.131 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.133 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:43.133 [OOB-1,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.133 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:43.133 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.134 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 3
10:25:43.136 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.260 [main] INFO pl.com.agora.ispn.scratch.IspnServer - Node B cache stats : clusterSize=2, entries=1, hits=7, misses=0, stores=7, retrievals=7
10:25:43.347 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:43.348 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.351 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:43.351 [OOB-1,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.351 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:43.351 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.352 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 4
10:25:43.356 [OOB-1,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.406 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:43.406 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.409 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:43.409 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.410 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:43.410 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.410 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 4
10:25:43.414 [OOB-1,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.554 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:43.555 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.557 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:43.557 [OOB-2,AGST-2012000591-36869] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-51775 for key 'K'
10:25:43.557 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:43.558 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-51775]. Use multicast? false
10:25:43.558 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 3
10:25:43.647 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:43.648 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:43.648 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:43.648 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:43.649 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:43.649 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:43.666 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:43.666 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:43.666 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:43.666 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:43.666 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:43.667 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:44.429 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:44.429 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.429 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:44.429 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:44.430 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.430 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:44.450 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:44.450 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.450 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:44.450 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:44.450 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.451 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:44.774 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:44.775 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.775 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:44.775 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:44.775 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.775 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:44.871 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:44.872 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.872 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:44.872 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:44.872 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.872 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:44.981 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:44.981 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.981 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:44.981 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:44.982 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:44.982 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:45.082 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.083 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.083 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.083 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.084 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.084 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 2
10:25:45.211 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.212 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.212 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.212 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.212 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.212 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:45.282 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.284 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.284 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.284 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.284 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.285 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 2
10:25:45.319 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.319 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.319 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.319 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.319 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.320 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:45.345 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.346 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.346 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.346 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.346 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.346 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:45.537 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.538 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.539 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.539 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.540 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.540 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 2
10:25:45.623 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.624 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.624 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.624 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.624 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.624 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:45.682 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.683 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.683 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.683 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.684 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.684 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 2
10:25:45.966 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.966 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.967 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.967 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.967 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.967 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:45.989 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:45.989 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.990 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:45.990 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:45.990 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:45.990 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:46.137 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:46.137 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.137 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:46.137 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:46.137 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.137 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:46.150 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:46.150 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.150 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:46.150 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:46.151 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.151 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:46.260 [main] INFO pl.com.agora.ispn.scratch.IspnServer - Node B cache stats : clusterSize=2, entries=1, hits=29, misses=0, stores=29, retrievals=29
10:25:46.641 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:46.641 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.641 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:46.642 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:46.642 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.642 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:46.649 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:46.650 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.650 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:46.650 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:46.650 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.650 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:46.727 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:46.728 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.728 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:46.728 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:46.729 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.729 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:46.804 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:46.805 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.805 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:46.805 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:46.805 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.805 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:46.912 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:46.912 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.912 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:46.912 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:46.913 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:46.913 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:47.051 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:47.051 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.052 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:47.052 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:47.052 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.052 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:47.271 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:47.271 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.272 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:47.272 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:47.272 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.272 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:47.312 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:47.312 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.312 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:47.312 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:47.312 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.312 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:47.349 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:47.350 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.350 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:47.350 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:47.350 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.350 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:47.353 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:47.354 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.354 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:47.354 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:47.354 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.354 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:47.689 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:47.689 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.689 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:47.689 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:47.690 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.690 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:47.981 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:47.981 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.981 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:47.981 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:47.982 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:47.982 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:48.002 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:48.003 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.003 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:48.003 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:48.003 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.003 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:48.163 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:48.163 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.164 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:48.164 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:48.164 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.164 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:48.196 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:48.196 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.196 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:48.197 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:48.197 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.197 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:48.207 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:48.208 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.208 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:48.208 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:48.208 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.208 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:48.716 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:48.717 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.717 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:48.717 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:48.717 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.717 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:48.748 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:48.748 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.748 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:48.749 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:48.749 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.749 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:48.872 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:48.872 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.872 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:48.872 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:48.872 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.873 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:48.981 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:48.981 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.981 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:48.981 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:48.981 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:48.981 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.083 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.083 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.083 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.083 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.083 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.084 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.105 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.106 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.106 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.106 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.106 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.106 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.238 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.238 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.239 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.239 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.239 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.239 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:49.261 [main] INFO pl.com.agora.ispn.scratch.IspnServer - Node B cache stats : clusterSize=2, entries=1, hits=52, misses=0, stores=52, retrievals=52
10:25:49.265 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.266 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.266 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.266 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.266 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.266 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:49.318 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.319 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.319 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.319 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.319 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.319 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:49.352 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.352 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.352 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.352 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.353 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.353 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:49.379 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.380 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.380 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.380 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.380 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.380 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:49.387 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.387 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.388 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.388 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.388 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.388 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.409 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.409 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.409 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.409 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.409 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.410 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.413 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.413 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.413 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.413 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.413 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.414 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.545 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.546 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.546 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.546 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.546 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.546 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.611 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.611 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.611 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.611 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.611 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.611 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.639 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.640 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.640 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.640 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.640 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.640 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.724 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.724 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.725 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.725 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.725 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.725 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.842 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.843 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.843 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.843 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.843 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.843 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:49.932 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.933 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.934 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.934 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.934 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.934 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:49.935 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:49.936 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.936 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:49.936 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:49.936 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:49.937 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:50.130 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:50.131 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.131 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:50.131 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:50.131 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.131 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:50.302 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:50.303 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.303 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:50.303 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:50.303 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.303 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:50.333 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:50.333 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.333 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:50.333 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:50.333 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.334 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:50.541 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:50.541 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.542 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:50.542 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:50.542 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.542 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:50.623 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:50.623 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.624 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:50.624 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:50.624 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.624 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:50.920 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:50.920 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.921 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:50.921 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:50.921 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:50.921 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:51.058 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:51.058 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.058 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:51.058 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:51.059 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.059 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:51.181 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:51.181 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.181 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:51.181 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:51.182 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.182 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:51.213 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:51.213 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.213 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:51.213 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:51.214 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.214 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:51.263 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:51.263 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.263 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:51.263 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:51.264 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.264 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:51.344 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:51.344 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.345 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:51.345 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:51.345 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.345 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:51.429 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:51.430 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.430 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:51.430 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:51.431 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.431 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 1
10:25:51.515 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Executing distributed callable for keys : [K]
10:25:51.515 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.515 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
10:25:51.515 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
10:25:51.516 [remote-thread-0] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
10:25:51.516 [remote-thread-0] INFO pl.com.agora.ispn.scratch.WriteTask - Task runtime millis 0
10:25:52.261 [main] INFO pl.com.agora.ispn.scratch.IspnServer - Node B cache stats : clusterSize=2, entries=1, hits=79, misses=0, stores=79, retrievals=79
{noformat}
> Inconsistent L1 in non-tx distributed cache in certain circumstances
> --------------------------------------------------------------------
>
> Key: ISPN-3842
> URL: https://issues.jboss.org/browse/ISPN-3842
> Project: Infinispan
> Issue Type: Bug
> Affects Versions: 6.0.0.Final
> Reporter: Mikolaj Gierulski
> Assignee: William Burns
>
> In my poc environment there are two nodes in dist non-tx sync cluster with L1 enabled and numOwners=1.
> Node A, in a loop, reads one key (K), which is stored on node B (in test case it performs about 1 000 000 reads per second).
> From time to time K is updated on node B. This causes an L1 invalidation message sent to A, and K is fetched from B upon next read attempt.
> But whenever I run my test, I come to a situation, where updates of K no longer invalidate it on A, and A sees old value of K.
> When this happens, I can see in logs of node A:
> {noformat}
> 18:21:33.296 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - L1 invalidation found a pending update for key K - need to block until finished
> 18:21:33.296 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Pending L1 update completed successfully: true - L1 invalidation can occur for key K
> 18:21:33.296 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
> 18:21:33.296 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
> 18:21:33.296 [remote-thread-0] TRACE o.i.commands.write.RemoveCommand - Nothing to remove since the entry is null or we have a null entry
> {noformat}
> While logs of node B show:
> {noformat}
> 18:21:33.200 [OOB-1,AGST-2012000591-33853] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-25400 for key 'K'
> 18:21:33.266 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-25400]. Use multicast? false
> 18:21:33.269 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
> 18:21:33.269 [OOB-2,AGST-2012000591-33853] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-25400 for key 'K'
> 18:21:33.269 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
> 18:21:33.269 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-25400]. Use multicast? false
> 18:21:33.270 [remote-thread-1] INFO p.c.a.ispn.WriteTask - Update task runtime millis 3
> 18:21:33.271 [OOB-1,AGST-2012000591-33853] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-25400 for key 'K'
> 18:21:33.293 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-25400]. Use multicast? false
> 18:21:33.295 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
> 18:21:33.295 [OOB-2,AGST-2012000591-33853] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-25400 for key 'K'
> 18:21:33.295 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
> 18:21:33.295 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-25400]. Use multicast? false
> 18:21:33.295 [remote-thread-1] INFO p.c.a.ispn.WriteTask - Update task runtime millis 2
> 18:21:33.476 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
> 18:21:33.476 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
> 18:21:33.476 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
> 18:21:33.476 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
> {noformat}
> So it seems, that after this:
> bq. 'L1 invalidation found a pending update for key K - need to block until finished'
> B no longer knows A holds K in L1, and no longer sends invalidation commands after updates.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years
[JBoss JIRA] (ISPN-3842) Inconsistent L1 in non-tx distributed cache in certain circumstances
by William Burns (JIRA)
[ https://issues.jboss.org/browse/ISPN-3842?page=com.atlassian.jira.plugin.... ]
William Burns commented on ISPN-3842:
-------------------------------------
The trace levels you have may be sufficient. If you could attach the entire trace log when this happens I may be able to see something. I am especially interested in what the other threads are doing at the same time. Thanks.
> Inconsistent L1 in non-tx distributed cache in certain circumstances
> --------------------------------------------------------------------
>
> Key: ISPN-3842
> URL: https://issues.jboss.org/browse/ISPN-3842
> Project: Infinispan
> Issue Type: Bug
> Affects Versions: 6.0.0.Final
> Reporter: Mikolaj Gierulski
> Assignee: William Burns
>
> In my poc environment there are two nodes in dist non-tx sync cluster with L1 enabled and numOwners=1.
> Node A, in a loop, reads one key (K), which is stored on node B (in test case it performs about 1 000 000 reads per second).
> From time to time K is updated on node B. This causes an L1 invalidation message sent to A, and K is fetched from B upon next read attempt.
> But whenever I run my test, I come to a situation, where updates of K no longer invalidate it on A, and A sees old value of K.
> When this happens, I can see in logs of node A:
> {noformat}
> 18:21:33.296 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - L1 invalidation found a pending update for key K - need to block until finished
> 18:21:33.296 [remote-thread-0] TRACE o.i.i.d.L1NonTxInterceptor - Pending L1 update completed successfully: true - L1 invalidation can occur for key K
> 18:21:33.296 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Preparing to invalidate keys [K]
> 18:21:33.296 [remote-thread-0] TRACE o.i.c.write.InvalidateL1Command - Invalidating key K.
> 18:21:33.296 [remote-thread-0] TRACE o.i.commands.write.RemoveCommand - Nothing to remove since the entry is null or we have a null entry
> {noformat}
> While logs of node B show:
> {noformat}
> 18:21:33.200 [OOB-1,AGST-2012000591-33853] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-25400 for key 'K'
> 18:21:33.266 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-25400]. Use multicast? false
> 18:21:33.269 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
> 18:21:33.269 [OOB-2,AGST-2012000591-33853] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-25400 for key 'K'
> 18:21:33.269 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
> 18:21:33.269 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-25400]. Use multicast? false
> 18:21:33.270 [remote-thread-1] INFO p.c.a.ispn.WriteTask - Update task runtime millis 3
> 18:21:33.271 [OOB-1,AGST-2012000591-33853] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-25400 for key 'K'
> 18:21:33.293 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-25400]. Use multicast? false
> 18:21:33.295 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
> 18:21:33.295 [OOB-2,AGST-2012000591-33853] TRACE o.i.distribution.L1ManagerImpl - Registering requestor AGST-2012000591-25400 for key 'K'
> 18:21:33.295 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
> 18:21:33.295 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - Invalidating keys [K] on nodes [AGST-2012000591-25400]. Use multicast? false
> 18:21:33.295 [remote-thread-1] INFO p.c.a.ispn.WriteTask - Update task runtime millis 2
> 18:21:33.476 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
> 18:21:33.476 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Allowing entry to commit as local node is owner
> 18:21:33.476 [remote-thread-1] TRACE o.i.i.d.L1NonTxInterceptor - Sending additional invalidation for requestors if necessary.
> 18:21:33.476 [remote-thread-1] TRACE o.i.distribution.L1ManagerImpl - No L1 caches to invalidate for keys [K]
> {noformat}
> So it seems, that after this:
> bq. 'L1 invalidation found a pending update for key K - need to block until finished'
> B no longer knows A holds K in L1, and no longer sends invalidation commands after updates.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years