Uploaded image for project: 'Infinispan'
  1. Infinispan
  2. ISPN-13163

Scattered cache key iteration is slow

    XMLWordPrintable

    Details

      Description

      PrefetchInterceptor.BackingKeySet doesn't implement localPublisher(), so a full iterator() is created and iterated for each segment.

      If the cache has a store, iteration will call publishKeys(segment) numSegments times.

      In scattered caches, the existence of the key must be confirmed with cache.get(key), which slows the iteration again (in addition to activating keys that shouldn't have been activated).

      The end result is that it can take more than 15 seconds to count 100 keys in 256 segments when trace logging is enabled, causing random failures in ThreeNodeScatteredGlobalStateRestartTest.

      15:08:13,651 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command SizeCommand{} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@7e8d563c]
      15:08:13,653 TRACE (testng-Test:[]) [JGroupsTransport] Test-NodeA sending single request 110 to Test-NodeC: PublisherRequestCommand{, includeLoader=true, topologyId=5, segments={86-127 213-255}, keys=[], excludedKeys=[], transformer= org.infinispan.reactive.publisher.PublisherReducers$SumReducer@2dbe8878, finalizer=org.infinispan.reactive.publisher.PublisherReducers$SumFinalizer@365f2f3c}
      15:08:13,657 TRACE (jgroups-7,Test-NodeC:[]) [JGroupsTransport] Test-NodeC received request 110 from Test-NodeA: PublisherRequestCommand{, includeLoader=true, topologyId=5, segments={86-127 213-255}, keys=[], excludedKeys=[], transformer= org.infinispan.reactive.publisher.PublisherReducers$SumReducer@2dbe8878, finalizer=org.infinispan.reactive.publisher.PublisherReducers$SumFinalizer@365f2f3c}
      15:08:13,657 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command KeySetCommand{, flags=[CACHE_MODE_LOCAL, REMOTE_ITERATION, IGNORE_TRANSACTION]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@438a1162]
      15:08:13,658 TRACE (jgroups-7,Test-NodeC:[]) [InvocationContextInterceptor] Invoked with command KeySetCommand{, flags=[CACHE_MODE_LOCAL, REMOTE_ITERATION, IGNORE_TRANSACTION]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@3c93a27b]
      15:08:13,659 TRACE (jgroups-7,Test-NodeB:[]) [InvocationContextInterceptor] Invoked with command KeySetCommand{, flags=[CACHE_MODE_LOCAL, REMOTE_ITERATION, IGNORE_TRANSACTION]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@2d52a0aa]
      15:08:13,694 TRACE (jgroups-7,Test-NodeC:[]) [KeyStreamSupplier] Applying segment filter {86}
      15:08:14,309 TRACE (jgroups-7,Test-NodeC:[]) [KeyStreamSupplier] Applying segment filter {87}
      15:08:28,493 TRACE (jgroups-7,Test-NodeC:[]) [KeyStreamSupplier] Applying segment filter {126}
      15:08:28,657 TRACE (timeout-thread-Test-NodeA-p25-t1:[]) [ClusterPublisherManagerImpl] General error encountered when executing publisher request command
      org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 110 from Test-NodeC
      15:08:28,861 TRACE (jgroups-7,Test-NodeC:[]) [KeyStreamSupplier] Applying segment filter {127}
      15:08:36,378 TRACE (jgroups-7,Test-NodeC:[]) [KeyStreamSupplier] Applying segment filter {253}
      
      15:08:36,496 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.globalstate.ThreeNodeScatteredGlobalStateRestartTest.testFailedRestartWithExtraneousCoordinator
      org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 110 from Test-NodeC
      	at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:255) ~[classes/:?]
      	at org.infinispan.cache.impl.InvocationHelper.doInvoke(InvocationHelper.java:297) ~[classes/:?]
      	at org.infinispan.cache.impl.InvocationHelper.invoke(InvocationHelper.java:101) ~[classes/:?]
      	at org.infinispan.cache.impl.CacheImpl.size(CacheImpl.java:497) ~[classes/:?]
      	at org.infinispan.cache.impl.CacheImpl.size(CacheImpl.java:492) ~[classes/:?]
      	at org.infinispan.cache.impl.AbstractDelegatingCache.size(AbstractDelegatingCache.java:369) ~[classes/:?]
      	at org.infinispan.globalstate.AbstractGlobalStateRestartTest.checkData(AbstractGlobalStateRestartTest.java:190) ~[test-classes/:?]
      	at org.infinispan.globalstate.AbstractGlobalStateRestartTest.createInitialCluster(AbstractGlobalStateRestartTest.java:208) ~[test-classes/:?]
      	at org.infinispan.globalstate.AbstractGlobalStateRestartTest.shutdownAndRestart(AbstractGlobalStateRestartTest.java:85) ~[test-classes/:?]
      	at org.infinispan.globalstate.ThreeNodeScatteredGlobalStateRestartTest.testFailedRestartWithExtraneousCoordinator(ThreeNodeScatteredGlobalStateRestartTest.java:31) ~[test-classes/:?]
      

        Attachments

          Activity

            People

            Assignee:
            Unassigned Unassigned
            Reporter:
            dan.berindei Dan Berindei
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated: