Loading...

Type: Bug
Resolution: Done
Priority: Major
Fix Version/s: 14.0.26.Final, 15.0.0.Final
Affects Version/s: None
Component/s: Hot Rod
Labels:
None

Git Pull Request:
https://github.com/infinispan/infinispan/pull/11919, https://github.com/infinispan/infinispan/pull/12039

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:

https://ci.infinispan.org/job/Infinispan/job/main/1476/testReport/org.infinispan.client.hotrod.near/AvoidStaleNearCacheReadsTest/testAvoidStaleReadsAfterReplacemaxEntries__20__bloomFilter__true__Flaky_Test_/

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)

is caused by

ISPN-14832 Operations not completing in the Hot Rod client when server crashes

Resolved

Details

Description

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates

PagerDuty