Details
-
Bug
-
Resolution: Done
-
Major
-
None
-
None
Description
During ISPN-14832, we identified operations could be enqueued while a channel was released, causing an operation not to execute. This has a chance of causing an operation to be scheduled twice.
After we enqueue an operation, we recheck the pool to see if a channel is available. If this second check succeeds AND another channel is released to the pool, we end scheduling the same operation for execution twice.
Some tests in CI show this problem:
And locally:
[OK: 1261, KO: 1, SKIP: 0] Test failed: org.infinispan.client.hotrod.near.AvoidStaleNearCacheReadsTest.testAvoidStaleReadsAfterPutAllmaxEntries\=20, bloomFilter\=true
org.infinispan.client.hotrod.exceptions.TransportException:: java.lang.AssertionError: PutAllOperation{(default), flags=6, connection=127.0.0.1/127.0.0.1:46385} is trying to override a timeout: 81387086
at org.infinispan.client.hotrod.impl.Util.rewrap(Util.java:87)
at org.infinispan.client.hotrod.impl.Util.await(Util.java:58)
at org.infinispan.client.hotrod.impl.RemoteCacheSupport.putAll(RemoteCacheSupport.java:48)
at org.infinispan.client.hotrod.impl.RemoteCacheSupport.putAll(RemoteCacheSupport.java:38)
at org.infinispan.client.hotrod.near.AvoidStaleNearCacheReadsTest.lambda$testAvoidStaleReadsAfterPutAll$1(AvoidStaleNearCacheReadsTest.java:99)
at org.infinispan.client.hotrod.near.AvoidStaleNearCacheReadsTest.lambda$repeated$5(AvoidStaleNearCacheReadsTest.java:137)
at java.base/java.util.stream.Streams$RangeIntSpliterator.forEachRemaining(Streams.java:104)
at java.base/java.util.stream.IntPipeline$Head.forEach(IntPipeline.java:617)
at org.infinispan.client.hotrod.near.AvoidStaleNearCacheReadsTest.repeated(AvoidStaleNearCacheReadsTest.java:136)
at org.infinispan.client.hotrod.near.AvoidStaleNearCacheReadsTest.testAvoidStaleReadsAfterPutAll(AvoidStaleNearCacheReadsTest.java:95)
at java.base/java.lang.reflect.Method.invoke(Method.java:568)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:124)
at org.testng.internal.MethodInvocationHelper$1.runTestMethod(MethodInvocationHelper.java:230)
at org.infinispan.commons.test.TestNGLongTestsHook.run(TestNGLongTestsHook.java:24)
at org.testng.internal.MethodInvocationHelper.invokeHookable(MethodInvocationHelper.java:242)
at org.testng.internal.Invoker.invokeMethod(Invoker.java:579)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:719)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:989)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109)
at org.testng.TestRunner.privateRun(TestRunner.java:648)
at org.testng.TestRunner.run(TestRunner.java:505)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:455)
at org.testng.SuiteRunner.access$000(SuiteRunner.java:40)
at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:489)
at org.testng.internal.thread.ThreadUtil$1.call(ThreadUtil.java:52)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.AssertionError: PutAllOperation{(default), flags=6, connection=127.0.0.1/127.0.0.1:46385} is trying to override a timeout: 81387086
at org.infinispan.client.hotrod.impl.operations.HotRodOperation.scheduleTimeout(HotRodOperation.java:169)
at org.infinispan.client.hotrod.impl.transport.netty.HeaderDecoder.registerOperation(HeaderDecoder.java:83)
at org.infinispan.client.hotrod.impl.operations.HotRodOperation.scheduleRead(HotRodOperation.java:90)
at org.infinispan.client.hotrod.impl.operations.StatsAffectingRetryingOperation.scheduleRead(StatsAffectingRetryingOperation.java:35)
at org.infinispan.client.hotrod.impl.operations.PutAllOperation.executeOperation(PutAllOperation.java:57)
at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.invoke(RetryOnFailureOperation.java:78)
at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.activateChannel(ChannelPool.java:319)
at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.executeDirectlyIfPossible(ChannelPool.java:126)
at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.acquire(ChannelPool.java:93)
at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.fetchChannelAndInvoke(ChannelFactory.java:327)
at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.fetchChannelAndInvoke(ChannelFactory.java:322)
at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.fetchChannelAndInvoke(ChannelFactory.java:305)
at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.fetchChannelAndInvoke(ChannelFactory.java:281)
at org.infinispan.client.hotrod.impl.transport.netty.ChannelFactory.fetchChannelAndInvoke(ChannelFactory.java:367)
at org.infinispan.client.hotrod.impl.operations.PutAllOperation.fetchChannelAndInvoke(PutAllOperation.java:79)
at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.execute(RetryOnFailureOperation.java:63)
at org.infinispan.client.hotrod.impl.operations.ParallelHotRodOperation.execute(ParallelHotRodOperation.java:40)
at org.infinispan.client.hotrod.impl.RemoteCacheImpl.putAllAsync(RemoteCacheImpl.java:273)
at org.infinispan.client.hotrod.impl.DelegatingRemoteCache.putAllAsync(DelegatingRemoteCache.java:50)
at org.infinispan.client.hotrod.impl.InvalidatedNearRemoteCache.putAllAsync(InvalidatedNearRemoteCache.java:144)
... 28 more
With some changes to capture who first instantiated the timeout:
java.lang.RuntimeException: PutAllOperation{(default), flags=6, connection=127.0.0.1/127.0.0.1:46385} registered timeout: 81387086
at org.infinispan.client.hotrod.impl.operations.HotRodOperation.scheduleTimeout(HotRodOperation.java:172)
at org.infinispan.client.hotrod.impl.transport.netty.HeaderDecoder.registerOperation(HeaderDecoder.java:83)
at org.infinispan.client.hotrod.impl.operations.HotRodOperation.scheduleRead(HotRodOperation.java:90)
at org.infinispan.client.hotrod.impl.operations.StatsAffectingRetryingOperation.scheduleRead(StatsAffectingRetryingOperation.java:35)
at org.infinispan.client.hotrod.impl.operations.PutAllOperation.executeOperation(PutAllOperation.java:57)
at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.invoke(RetryOnFailureOperation.java:78)
at org.infinispan.client.hotrod.impl.transport.netty.ChannelPool.lambda$activateChannel$1(ChannelPool.java:311)
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:413)
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.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:833)
Attachments
Issue Links
- is caused by
-
-
- Resolved
-
