[ 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: 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: 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} -- 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