[RATIS-2013] OrderedAsync retry results an IllegalStateException in GrpcClientProtocolService

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 3.1.0
• Component/s: server, util
• Assignee: Tsz-wo Sze
• Reporter: Tsz-wo Sze
• Created: 22/Jan/24 16:39
• Updated: 22/Jan/24 22:32
• Resolved: 22/Jan/24 22:32

Description

Run TestExceptionDependentRetry.testExceptionRetryAttempts, there are IllegalStateException in the log

2024-01-22 08:35:08,902 [grpc-default-executor-2] ERROR impl.OrderedAsync (OrderedAsync.java:lambda$sendRequest$9(247)) - client-44EE5747CA06: Failed* RaftClientRequest:client-44EE5747CA06->s0@group-A21961BDAD00, cid=4, seq=2*, RW, 2
java.util.concurrent.CompletionException: java.io.IOException: java.lang.IllegalStateException: Entry already exists for key 2 in map SlidingWindow$Server:1-OrderedRequestStreamObserver1:requests
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
	at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
	at org.apache.ratis.grpc.client.GrpcClientProtocolClient$AsyncStreamObservers.completeReplyExceptionally(GrpcClientProtocolClient.java:394)
	at org.apache.ratis.grpc.client.GrpcClientProtocolClient$AsyncStreamObservers.access$000(GrpcClientProtocolClient.java:300)
	at org.apache.ratis.grpc.client.GrpcClientProtocolClient$AsyncStreamObservers$1.onError(GrpcClientProtocolClient.java:331)
	at org.apache.ratis.thirdparty.io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:481)
	at org.apache.ratis.thirdparty.io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
	at org.apache.ratis.thirdparty.io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
	at org.apache.ratis.grpc.metrics.intercept.client.MetricClientCallListener.onClose(MetricClientCallListener.java:47)
	at org.apache.ratis.thirdparty.io.grpc.internal.DelayedClientCall$DelayedListener$3.run(DelayedClientCall.java:489)
	at org.apache.ratis.thirdparty.io.grpc.internal.DelayedClientCall$DelayedListener.delayOrExecute(DelayedClientCall.java:453)
	at org.apache.ratis.thirdparty.io.grpc.internal.DelayedClientCall$DelayedListener.onClose(DelayedClientCall.java:486)
	at org.apache.ratis.thirdparty.io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:567)
	at org.apache.ratis.thirdparty.io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:71)
	at org.apache.ratis.thirdparty.io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:735)
	at org.apache.ratis.thirdparty.io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:716)
	at org.apache.ratis.thirdparty.io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
	at org.apache.ratis.thirdparty.io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:750)
Caused by: java.io.IOException: java.lang.IllegalStateException: Entry already exists for key 2 in map SlidingWindow$Server:1-OrderedRequestStreamObserver1:requests
	at org.apache.ratis.grpc.GrpcUtil.unwrapException(GrpcUtil.java:103)
	at org.apache.ratis.grpc.GrpcUtil.unwrapIOException(GrpcUtil.java:163)
	at org.apache.ratis.grpc.client.GrpcClientProtocolClient$AsyncStreamObservers$1.onError(GrpcClientProtocolClient.java:330)
	... 16 more
Caused by: java.lang.IllegalStateException: Entry already exists for key 2 in map SlidingWindow$Server:1-OrderedRequestStreamObserver1:requests
	at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:77)
	at org.apache.ratis.util.Preconditions.assertNull(Preconditions.java:97)
	at org.apache.ratis.util.CollectionUtils.putNew(CollectionUtils.java:117)
	at org.apache.ratis.util.CollectionUtils.putNew(CollectionUtils.java:107)
	at org.apache.ratis.util.SlidingWindow$RequestMap.putNewRequest(SlidingWindow.java:127)
	at org.apache.ratis.util.SlidingWindow$Server.receivedRequest(SlidingWindow.java:450)
	at org.apache.ratis.grpc.server.GrpcClientProtocolService$OrderedRequestStreamObserver.processClientRequest(GrpcClientProtocolService.java:390)
	at org.apache.ratis.grpc.server.GrpcClientProtocolService$RequestStreamObserver.onNext(GrpcClientProtocolService.java:272)
	at org.apache.ratis.grpc.server.GrpcClientProtocolService$RequestStreamObserver.onNext(GrpcClientProtocolService.java:191)
	at org.apache.ratis.thirdparty.io.grpc.stub.ServerCalls$StreamingServerCallHandler$StreamingServerCallListener.onMessage(ServerCalls.java:262)
	at org.apache.ratis.thirdparty.io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.messagesAvailableInternal(ServerCallImpl.java:329)
	at org.apache.ratis.thirdparty.io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.messagesAvailable(ServerCallImpl.java:314)
	at org.apache.ratis.thirdparty.io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1MessagesAvailable.runInContext(ServerImpl.java:833)
	... 5 more

Issue Links

• links to: GitHub Pull Request #1026