4 Replies Latest reply on Dec 4, 2014 7:12 AM by bjorn.ellingsen

    Infinispan 7.0.x, still "Did not retrieve entries in allotted timeout..." errors

    bjorn.ellingsen

      Very similar to this question: Re: Re: 7.0.0 migration issue? "Did not retrieve entries in allotted timeout..."

      I get the same result from time to time when calling "values()" on the cache map (not "isEmpty()" like above).

       

      org.infinispan.util.concurrent.TimeoutException: Did not retrieve entries in allotted timeout: 240000 units: MILLISECONDS

      at org.infinispan.iteration.impl.LocalEntryRetriever$Itr.hasNext(LocalEntryRetriever.java:456)

      at org.infinispan.iteration.impl.RemovableEntryIterator.getNextFromIterator(RemovableEntryIterator.java:33)

      at org.infinispan.iteration.impl.RemovableEntryIterator.<init>(RemovableEntryIterator.java:28)

      at org.infinispan.iteration.impl.TrackingEntryIterable.iterator(TrackingEntryIterable.java:72)

      at org.infinispan.commands.read.ValuesCommand$BackingValuesCollection.iterator(ValuesCommand.java:62)

      at org.infinispan.commands.read.ValuesCommand$BackingValuesCollection.iterator(ValuesCommand.java:54)

       

      All works as expected with ISPN 6.0.2, but trying ISPN 7.0.0, 7.0.1 or 7.0.2 results in this error. The cache is REPL_SYNC, has few elements (<10K), using jgroups-udp.xml configuration file. The cluster is very small, only two nodes.

       

      Might this be a variant of the isEmpty() bug?

       

      Thanks,

      Bjørn E.

        • 1. Re: Infinispan 7.0.x, still "Did not retrieve entries in allotted timeout..." errors
          william.burns

          The issue specifically with the other forum post was that the iterator was closed before it was completely iterated upon, which could cause an issue in a thread to hang.  This however was fixed in 7.0.1.

           

          Is it possible you are not closing the iterator retrieved from the values method in a try with resource block (see Iterator Use section at [1]) and don't iterate upon it fully?  If you don't then this will cause a thread to blocked and will only be freed when the finalizer is ran on the iterator when the GC reclaims it.

           

          If you are not having that issue you should take a thread dump of the process to find out what the transport threads are doing (because they are the ones that add to the iterator).

           

          [1] Infinispan Distribution 7.0.2.Final API

          1 of 1 people found this helpful
          • 2. Re: Infinispan 7.0.x, still "Did not retrieve entries in allotted timeout..." errors
            bjorn.ellingsen

            Thanks, yes it is not only possible but absolutely certain that the iterator was not closed - that API change (return type of values() from Collection to CloseableIteratorCollection) had slipped my attention. I'll try reproducing the situation and dump the threads, and also see if closing the iterator makes any change.

             

            Bjørn E.

            • 3. Re: Re: Infinispan 7.0.x, still "Did not retrieve entries in allotted timeout..." errors
              bjorn.ellingsen

              Using the try-with-resource approach worked like a charm, thanks a lot!

               

              I also grabbed a thread dump for the "allotted timeout" case, which gave me one thread doing the iterating (using values()):

                 java.lang.Thread.State: TIMED_WAITING (parking)
                  at sun.misc.Unsafe.park(Native Method)
                  - parking to wait for  <0x00000000fa3a1250> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
                  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
                  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
                  at org.infinispan.iteration.impl.LocalEntryRetriever$Itr.hasNext(LocalEntryRetriever.java:451)
                  at org.infinispan.iteration.impl.RemovableEntryIterator.getNextFromIterator(RemovableEntryIterator.java:33)
                  at org.infinispan.iteration.impl.RemovableEntryIterator.<init>(RemovableEntryIterator.java:28)
                  at org.infinispan.iteration.impl.TrackingEntryIterable.iterator(TrackingEntryIterable.java:72)
                  at org.infinispan.commands.read.ValuesCommand$BackingValuesCollection.iterator(ValuesCommand.java:62)
                  at org.infinispan.commands.read.ValuesCommand$BackingValuesCollection.iterator(ValuesCommand.java:54)
              
              

               

              ...followed by 25 threads which seemed to have an identical stack:

               

              "transport-thread--p2-t25" #50 daemon prio=5 os_prio=0 tid=0x00007fddadb8a000 nid=0x3aac runnable [0x00007fdd7ec33000]
                 java.lang.Thread.State: TIMED_WAITING (parking)
                  at sun.misc.Unsafe.park(Native Method)
                  - parking to wait for  <0x00000000f86797e0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
                  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
                  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
                  at java.util.concurrent.ArrayBlockingQueue.offer(ArrayBlockingQueue.java:379)
                  at org.infinispan.iteration.impl.LocalEntryRetriever$Itr.addEntries(LocalEntryRetriever.java:545)
                  at org.infinispan.iteration.impl.LocalEntryRetriever$ItrQueuerHandler.handleBatch(LocalEntryRetriever.java:421)
                  at org.infinispan.iteration.impl.LocalEntryRetriever$MapAction.apply(LocalEntryRetriever.java:399)
                  at org.infinispan.iteration.impl.LocalEntryRetriever$1.run(LocalEntryRetriever.java:294)
                  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
                  at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
                  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
                  at java.lang.Thread.run(Thread.java:745)
              

               

               

              Bjørn E.

              • 4. Re: Infinispan 7.0.x, still "Did not retrieve entries in allotted timeout..." errors
                bjorn.ellingsen

                It might, by the way, be a good idea to spend a sentence or two in the Upgrade Guide about this change, as it is not backwards compatible.

                 

                Bjørn E.