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

Blocking pool and Hibernate Search StackOverflow overwhelms queue

XMLWordPrintable

      We've recently updated our Infinispans to run 15.0.3. However, one of our Infinispans seems to be reliably crashing. I suspect this might be due to the fact this Infinispan is under the most load.

       

      Inside the log, I see many of these CacheBackpressureFullException:

      13:14:11,921 WARN  (non-blocking-thread--p2-t8) [com.github.benmanes.caffeine.cache.BoundedLocalCache] Exception thrown by eviction listener org.infinispan.commons.util.concurrent.CacheBackpressureFullException
          at org.infinispan.commons.util.concurrent.BlockingRejectedExecutionHandler.rejectedExecution(BlockingRejectedExecutionHandler.java:43)
          at org.infinispan.factories.threads.EnhancedQueueExecutorFactory.lambda$createExecutor$0(EnhancedQueueExecutorFactory.java:47)
          at org.jboss.threads.EnhancedQueueExecutor.rejectQueueFull(EnhancedQueueExecutor.java:2110)
          at org.jboss.threads.EnhancedQueueExecutor.execute(EnhancedQueueExecutor.java:804)
          at org.infinispan.util.concurrent.BlockingTaskAwareExecutorServiceImpl.execute(BlockingTaskAwareExecutorServiceImpl.java:128)
          at org.infinispan.executors.LazyInitializingBlockingTaskAwareExecutorService.execute(LazyInitializingBlockingTaskAwareExecutorService.java:194)
          at java.base/java.util.concurrent.CompletableFuture.asyncRunStage(CompletableFuture.java:1818)
          at java.base/java.util.concurrent.CompletableFuture.runAsync(CompletableFuture.java:2033)
          at org.infinispan.util.concurrent.BlockingManagerImpl.runBlockingOperation(BlockingManagerImpl.java:134)
          at org.infinispan.util.concurrent.BlockingManagerImpl.runBlockingOperation(BlockingManagerImpl.java:110)
          at org.infinispan.util.concurrent.BlockingManagerImpl.runBlocking(BlockingManagerImpl.java:76)
          at org.infinispan.persistence.file.SingleFileStore.write(SingleFileStore.java:926)
          at org.infinispan.persistence.manager.PersistenceManagerImpl.writeToAllNonTxStores(PersistenceManagerImpl.java:1037)
          at org.infinispan.persistence.manager.PersistenceManager.writeToAllNonTxStores(PersistenceManager.java:304)
          at org.infinispan.persistence.support.DelegatingPersistenceManager.writeToAllNonTxStores(DelegatingPersistenceManager.java:249)
          at org.infinispan.persistence.manager.PassivationPersistenceManager.passivate(PassivationPersistenceManager.java:40)
          at org.infinispan.eviction.impl.PassivationManagerImpl.doPassivate(PassivationManagerImpl.java:90)
          at org.infinispan.eviction.impl.PassivationManagerImpl.passivateAsync(PassivationManagerImpl.java:111)
          at org.infinispan.container.impl.AbstractInternalDataContainer.handleEviction(AbstractInternalDataContainer.java:504)
          at org.infinispan.container.impl.AbstractInternalDataContainer$DefaultEvictionListener.onEntryChosenForEviction(AbstractInternalDataContainer.java:535)
          at org.infinispan.container.impl.AbstractInternalDataContainer.lambda$applyListener$3(AbstractInternalDataContainer.java:412)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.notifyEviction(BoundedLocalCache.java:442)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$evictEntry$2(BoundedLocalCache.java:1071)
          at java.base/java.util.concurrent.ConcurrentHashMap.computeIfPresent(ConcurrentHashMap.java:1828)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.evictEntry(BoundedLocalCache.java:1032)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.evictFromMain(BoundedLocalCache.java:868)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.evictEntries(BoundedLocalCache.java:710)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.maintenance(BoundedLocalCache.java:1722)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.performCleanUp(BoundedLocalCache.java:1660)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache$PerformCleanupTask.run(BoundedLocalCache.java:3886)
          at org.infinispan.util.concurrent.WithinThreadExecutor.execute(WithinThreadExecutor.java:20)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.scheduleDrainBuffers(BoundedLocalCache.java:1633)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.scheduleAfterWrite(BoundedLocalCache.java:1599)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.afterWrite(BoundedLocalCache.java:1531)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.put(BoundedLocalCache.java:2314)
          at com.github.benmanes.caffeine.cache.BoundedLocalCache.put(BoundedLocalCache.java:2278)
          at org.infinispan.commons.util.AbstractDelegatingMap.put(AbstractDelegatingMap.java:51)
          at org.infinispan.container.impl.PeekableTouchableMap.putNoReturn(PeekableTouchableMap.java:45)
          at org.infinispan.container.impl.AbstractInternalDataContainer.putEntryInMap(AbstractInternalDataContainer.java:309)
          at org.infinispan.container.impl.AbstractInternalDataContainer.put(AbstractInternalDataContainer.java:168)
          at org.infinispan.container.entries.ReadCommittedEntry.commit(ReadCommittedEntry.java:157)
          at org.infinispan.statetransfer.CommitManager.commitEntry(CommitManager.java:166)
          at org.infinispan.statetransfer.CommitManager.commit(CommitManager.java:116)
          at org.infinispan.interceptors.locking.ClusteringDependentLogic$LocalLogic.commitSingleEntry(ClusteringDependentLogic.java:389)
          at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.commitEntryOrdered(ClusteringDependentLogic.java:280)
          at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.commitEntry(ClusteringDependentLogic.java:241)
          at org.infinispan.interceptors.impl.EntryWrappingInterceptor.commitContextEntry(EntryWrappingInterceptor.java:611)
          at org.infinispan.interceptors.impl.EntryWrappingInterceptor.commitEntryIfNeeded(EntryWrappingInterceptor.java:884)
          at org.infinispan.interceptors.impl.EntryWrappingInterceptor.commitContextEntries(EntryWrappingInterceptor.java:591)
          at org.infinispan.interceptors.impl.EntryWrappingInterceptor.applyChanges(EntryWrappingInterceptor.java:685)
          at org.infinispan.interceptors.impl.EntryWrappingInterceptor.applyAndFixVersion(EntryWrappingInterceptor.java:737)
          at org.infinispan.interceptors.SyncInvocationStage.thenApply(SyncInvocationStage.java:44)
          at org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(EntryWrappingInterceptor.java:732)
          at org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:335)
          at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:65)
          at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndFinally(BaseAsyncInterceptor.java:154)
          at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lambda$nonTxLockAndInvokeNext$3(AbstractLockingInterceptor.java:318)
          at org.infinispan.interceptors.SyncInvocationStage.andHandle(SyncInvocationStage.java:69)
          at org.infinispan.interceptors.locking.AbstractLockingInterceptor.nonTxLockAndInvokeNext(AbstractLockingInterceptor.java:313)
          at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:138)
          at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:41)
          at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:82)
          at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:65)
          at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58)
          at org.infinispan.interceptors.impl.CacheMgmtInterceptor.updateStoreStatistics(CacheMgmtInterceptor.java:233)
          at org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:196)
          at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:65)
          at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58)
          at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
          at org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
          at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:65)
          at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:127)
          at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
          at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:211)
          at org.infinispan.cache.impl.InvocationHelper.doInvokeAsync(InvocationHelper.java:318)
          at org.infinispan.cache.impl.InvocationHelper.invokeAsync(InvocationHelper.java:156)
          at org.infinispan.cache.impl.InvocationHelper.invokeAsync(InvocationHelper.java:139)
          at org.infinispan.cache.impl.CacheImpl.putAsync(CacheImpl.java:1433)
          at org.infinispan.cache.impl.CacheImpl.putAsync(CacheImpl.java:1900)
          at org.infinispan.cache.impl.CacheImpl.putAsync(CacheImpl.java:434)
          at org.infinispan.cache.impl.EncoderCache.putAsync(EncoderCache.java:263)
          at org.infinispan.server.logging.events.ServerEventLogger.actualSend(ServerEventLogger.java:85)
          at org.infinispan.server.logging.events.ServerEventLogger.eventLog(ServerEventLogger.java:81)
          at org.infinispan.server.logging.events.DecoratedServerEventLogger.log(DecoratedServerEventLogger.java:29)
          at org.infinispan.util.logging.events.EventLogger.info(EventLogger.java:41)
          at org.infinispan.topology.LocalTopologyManagerImpl.lambda$handleRebalance$26(LocalTopologyManagerImpl.java:682)
          at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
          at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
          at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
          at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2179)
          at org.infinispan.util.concurrent.ActionSequencer$SequenceEntry.accept(ActionSequencer.java:213)
          at org.infinispan.util.concurrent.ActionSequencer$SequenceEntry.accept(ActionSequencer.java:181)
          at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863)
          at java.base/java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:887)
          at java.base/java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2357)
          at java.base/java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:144)
          at org.infinispan.util.concurrent.ActionSequencer$SequenceEntry.run(ActionSequencer.java:229)
          at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
          at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
          at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
          at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:405)
          at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
          at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
          at java.base/java.lang.Thread.run(Thread.java:1583)
          Suppressed: java.util.concurrent.RejectedExecutionException: Queue is full
              at org.jboss.threads.EnhancedQueueExecutor.rejectQueueFull(EnhancedQueueExecutor.java:2112)
              ... 101 more 

       

       

      It looks like the task queue is getting full. However, even after taking the Infinispan cluster out of rotation, the Queue size never seemed to reduce, and is still spamming these errors 12 hours after having no traffic going to it.

      thread-dump.txt

      Here is a thread dump containing the state of the broken Infinispan.

      I did have a look at the code myself, and it seems that Hibernate search is using a ArrayBlockingQueue, which appears to add tasks to itself from within the tasks. Which in turns means that as long as the Queue is stuck with tasks all trying to add to the Queue, the Queue will never be able to complete any of the tasks. I am unsure if this is an issue in Infinispan or Hibernate Search, but I felt I should report it as we're seeing crashes very frequently.

       

      Regarding getting a solution out on our end, I could not figure out how to configure either the max queue size of the max number of threads for this processing. I narrowed it down to this config value,] however I am very unsure of where to actually put this value. My gut seems to say it needs to go into this config file, however I cannot figure out the path. Is there some documentation on the list of configuration options and where they go that I'm am missing?

       

            wburns@redhat.com Will Burns
            rubik_cube_man Luke Morfill (Inactive)
            Votes:
            1 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved: