[
https://issues.apache.org/jira/browse/RATIS-2677?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18109020#comment-18109020
]
Tsz-wo Sze edited comment on RATIS-2677 at 8/28/26 1:02 AM:
------------------------------------------------------------
Here is the log:
{code}
2026-08-27 10:51:05,444 [main] DEBUG util.SlidingWindow
(SlidingWindow.java:sendOrDelayRequest(312)) -
SlidingWindow$Client:client-000000000001->RAFT: detect firstSubmitted [cid=1,
seq=1] in SlidingWindow$Client:client-000000000001->RAFT: requests[1..1],
nextSeqNum=2, firstSubmitted=-1, replied? false, delayed=[]
2026-08-27 10:51:05,444 [main] TRACE impl.OrderedAsync
(OrderedAsync.java:setFirstRequest(91)) - setFirstRequest: [cid=1, seq=1(1st)]
java.lang.Throwable
at
org.apache.ratis.client.impl.OrderedAsync$PendingOrderedRequest.setFirstRequest(OrderedAsync.java:91)
at
org.apache.ratis.util.SlidingWindow$Client.sendOrDelayRequest(SlidingWindow.java:314)
at
org.apache.ratis.util.SlidingWindow$Client.submitNewRequest(SlidingWindow.java:294)
at org.apache.ratis.client.impl.OrderedAsync.send(OrderedAsync.java:175)
at
org.apache.ratis.client.impl.OrderedAsync.newInstance(OrderedAsync.java:127)
at
org.apache.ratis.client.impl.RaftClientImpl.lambda$new$1(RaftClientImpl.java:213)
at
org.apache.ratis.util.MemoizedFunction.lambda$apply$0(MemoizedFunction.java:67)
at org.apache.ratis.util.MemoizedBase.init(MemoizedBase.java:49)
at
org.apache.ratis.util.MemoizedFunction.apply(MemoizedFunction.java:67)
at
org.apache.ratis.client.impl.RaftClientImpl.getOrderedAsync(RaftClientImpl.java:282)
at
org.apache.ratis.client.impl.AsyncImpl.lambda$send$0(AsyncImpl.java:43)
at
org.apache.ratis.trace.NoOpTraceProvider.traceClientSend(NoOpTraceProvider.java:41)
at org.apache.ratis.trace.TraceClient.asyncSend(TraceClient.java:37)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:42)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:48)
at org.apache.ratis.client.api.AsyncApi.send(AsyncApi.java:46)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.runTestBasicAppendEntries(TestRaftAsyncWithGrpc.java:82)
...
2026-08-27 10:51:05,446 [main] DEBUG client.RaftClient
(RaftClientImpl.java:get(160)) - client-000000000001: get 1 returns []
2026-08-27 10:51:05,447 [main] DEBUG client.RaftClient
(RaftClientImpl.java:newRequest(97)) - attempt #1, newRequest
RaftClientRequest:client-000000000001->s0@group-6B458A98A0E9, cid=1,
seq=1(1st), Watch(0), Message:DUMMY
java.lang.Throwable
at
org.apache.ratis.client.impl.RaftClientImpl$PendingClientRequest.newRequest(RaftClientImpl.java:97)
at
org.apache.ratis.client.impl.OrderedAsync.sendRequestWithRetry(OrderedAsync.java:198)
at
org.apache.ratis.util.SlidingWindow$Client.sendOrDelayRequest(SlidingWindow.java:315)
at
org.apache.ratis.util.SlidingWindow$Client.submitNewRequest(SlidingWindow.java:294)
at org.apache.ratis.client.impl.OrderedAsync.send(OrderedAsync.java:175)
at
org.apache.ratis.client.impl.OrderedAsync.newInstance(OrderedAsync.java:127)
at
org.apache.ratis.client.impl.RaftClientImpl.lambda$new$1(RaftClientImpl.java:213)
at
org.apache.ratis.util.MemoizedFunction.lambda$apply$0(MemoizedFunction.java:67)
at org.apache.ratis.util.MemoizedBase.init(MemoizedBase.java:49)
at
org.apache.ratis.util.MemoizedFunction.apply(MemoizedFunction.java:67)
at
org.apache.ratis.client.impl.RaftClientImpl.getOrderedAsync(RaftClientImpl.java:282)
at
org.apache.ratis.client.impl.AsyncImpl.lambda$send$0(AsyncImpl.java:43)
at
org.apache.ratis.trace.NoOpTraceProvider.traceClientSend(NoOpTraceProvider.java:41)
at org.apache.ratis.trace.TraceClient.asyncSend(TraceClient.java:37)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:42)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:48)
at org.apache.ratis.client.api.AsyncApi.send(AsyncApi.java:46)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.runTestBasicAppendEntries(TestRaftAsyncWithGrpc.java:82)
...
2026-08-27 10:51:05,447 [main] TRACE impl.OrderedAsync
(OrderedAsync.java:setFirstRequest(91)) - setFirstRequest: [cid=1, seq=1(1st)]
java.lang.Throwable
at
org.apache.ratis.client.impl.OrderedAsync$PendingOrderedRequest.setFirstRequest(OrderedAsync.java:91)
at
org.apache.ratis.client.impl.OrderedAsync.sendRequestWithRetry(OrderedAsync.java:205)
at
org.apache.ratis.util.SlidingWindow$Client.sendOrDelayRequest(SlidingWindow.java:315)
at
org.apache.ratis.util.SlidingWindow$Client.submitNewRequest(SlidingWindow.java:294)
at org.apache.ratis.client.impl.OrderedAsync.send(OrderedAsync.java:175)
at
org.apache.ratis.client.impl.OrderedAsync.newInstance(OrderedAsync.java:127)
at
org.apache.ratis.client.impl.RaftClientImpl.lambda$new$1(RaftClientImpl.java:213)
at
org.apache.ratis.util.MemoizedFunction.lambda$apply$0(MemoizedFunction.java:67)
at org.apache.ratis.util.MemoizedBase.init(MemoizedBase.java:49)
at
org.apache.ratis.util.MemoizedFunction.apply(MemoizedFunction.java:67)
at
org.apache.ratis.client.impl.RaftClientImpl.getOrderedAsync(RaftClientImpl.java:282)
at
org.apache.ratis.client.impl.AsyncImpl.lambda$send$0(AsyncImpl.java:43)
at
org.apache.ratis.trace.NoOpTraceProvider.traceClientSend(NoOpTraceProvider.java:41)
at org.apache.ratis.trace.TraceClient.asyncSend(TraceClient.java:37)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:42)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:48)
at org.apache.ratis.client.api.AsyncApi.send(AsyncApi.java:46)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.runTestBasicAppendEntries(TestRaftAsyncWithGrpc.java:82)
...
2026-08-27 10:51:05,448 [main] DEBUG impl.OrderedAsync
(OrderedAsync.java:sendRequestWithRetry(207)) - client-000000000001: send*
RaftClientRequest:client-000000000001->s0@group-6B458A98A0E9, cid=1,
seq=1(1st), Watch(0), Message:DUMMY
2026-08-27 10:51:05,487 [main] DEBUG util.SlidingWindow
(SlidingWindow.java:submitNewRequest(295)) -
SlidingWindow$Client:client-000000000001->RAFT: submitting a new request
[cid=1, seq=1(1st)] in SlidingWindow$Client:client-000000000001->RAFT:
requests[1..1], nextSeqNum=2, firstSubmitted=1, replied? false, delayed=[]?
submitted
2026-08-27 10:51:05,488 [main] DEBUG util.SlidingWindow
(SlidingWindow.java:submitNewRequest(295)) -
SlidingWindow$Client:client-000000000001->RAFT: submitting a new request
[cid=2, seq=2] in SlidingWindow$Client:client-000000000001->RAFT:
requests[1..2], nextSeqNum=3, firstSubmitted=1, replied? false, delayed=[2]?
delayed
Aug 27, 2026 10:51:05 AM org.apache.ratis.thirdparty.io.grpc.netty.TcpMetrics
loadEpollInfo
INFO: Epoll available during static init of TcpMetrics:false
2026-08-27 10:51:05,533 [grpc-default-executor-0] DEBUG util.SlidingWindow
(SlidingWindow.java:receivedRequest(450)) - Received seq=1 (first request),
SlidingWindow$Server:0-OrderedRequestStreamObserver0: requests[1..1],
nextToProcess=1
2026-08-27 10:51:05,534 [s0-client-thread1] DEBUG server.RaftServer$Division
(RaftServerImpl.java:submitClientRequestAsyncInternal(995)) -
s0@group-6B458A98A0E9: receive client
request(RaftClientRequest:client-000000000001->s0@group-6B458A98A0E9, cid=1,
seq=1(1st), Watch(0), Message:DUMMY)
2026-08-27 10:51:05,535 [null-request--thread1] DEBUG util.SlidingWindow
(SlidingWindow.java:setReply(146)) -
SlidingWindow$Server:0-OrderedRequestStreamObserver0: set reply
RaftClientReply:client-000000000001->s0@group-6B458A98A0E9, cid=1, FAILED null,
logIndex=0, commits[] for seq=1 in
SlidingWindow$Server:0-OrderedRequestStreamObserver0: requests[1..1]
2026-08-27 10:51:05,543 [grpc-default-executor-0] DEBUG impl.OrderedAsync
(OrderedAsync.java:lambda$sendRequestWithRetry$5(209)) - client-000000000001:
receive* RaftClientReply:client-000000000001->s0@group-6B458A98A0E9, cid=1,
FAILED null, logIndex=0, commits[]
2026-08-27 10:51:05,543 [grpc-default-executor-0] DEBUG util.SlidingWindow
(SlidingWindow.java:setReply(146)) -
SlidingWindow$Client:client-000000000001->RAFT: set reply
RaftClientReply:client-000000000001->s0@group-6B458A98A0E9, cid=1, FAILED null,
logIndex=0, commits[] for seq=1 in
SlidingWindow$Client:client-000000000001->RAFT: requests[1..2]
2026-08-27 10:51:05,543 [grpc-default-executor-0] DEBUG client.RaftClient
(RaftClientImpl.java:get(160)) - client-000000000001: get 2 returns []
2026-08-27 10:51:05,543 [grpc-default-executor-0] DEBUG client.RaftClient
(RaftClientImpl.java:newRequest(97)) - attempt #1, newRequest
RaftClientRequest:client-000000000001->s0@group-6B458A98A0E9, cid=2, seq=2, RW,
m0
java.lang.Throwable
at
org.apache.ratis.client.impl.RaftClientImpl$PendingClientRequest.newRequest(RaftClientImpl.java:97)
at
org.apache.ratis.client.impl.OrderedAsync.sendRequestWithRetry(OrderedAsync.java:198)
at
org.apache.ratis.util.SlidingWindow$Client.lambda$trySendDelayed$2(SlidingWindow.java:365)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
at
org.apache.ratis.util.SlidingWindow$Client.trySendDelayed(SlidingWindow.java:364)
at
org.apache.ratis.util.SlidingWindow$Client.receiveReply(SlidingWindow.java:358)
at
org.apache.ratis.client.impl.OrderedAsync.lambda$sendRequestWithRetry$5(OrderedAsync.java:212)
at
java.base/java.util.concurrent.CompletableFuture$UniAccept.tryFire$$$capture(CompletableFuture.java:718)
at
java.base/java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java)
at --- Async.Stack.Trace --- (captured by IntelliJ IDEA debugger)
at
java.base/java.util.concurrent.CompletableFuture$UniAccept.<init>(CompletableFuture.java:697)
at
java.base/java.util.concurrent.CompletableFuture.uniAcceptStage(CompletableFuture.java:737)
at
java.base/java.util.concurrent.CompletableFuture.thenAccept(CompletableFuture.java:2182)
at
org.apache.ratis.client.impl.OrderedAsync.sendRequestWithRetry(OrderedAsync.java:208)
at
org.apache.ratis.util.SlidingWindow$Client.sendOrDelayRequest(SlidingWindow.java:315)
at
org.apache.ratis.util.SlidingWindow$Client.submitNewRequest(SlidingWindow.java:294)
at org.apache.ratis.client.impl.OrderedAsync.send(OrderedAsync.java:175)
at
org.apache.ratis.client.impl.OrderedAsync.newInstance(OrderedAsync.java:127)
at
org.apache.ratis.client.impl.RaftClientImpl.lambda$new$1(RaftClientImpl.java:213)
at
org.apache.ratis.util.MemoizedFunction.lambda$apply$0(MemoizedFunction.java:67)
at org.apache.ratis.util.MemoizedBase.init(MemoizedBase.java:49)
at
org.apache.ratis.util.MemoizedFunction.apply(MemoizedFunction.java:67)
at
org.apache.ratis.client.impl.RaftClientImpl.getOrderedAsync(RaftClientImpl.java:282)
at
org.apache.ratis.client.impl.AsyncImpl.lambda$send$0(AsyncImpl.java:43)
at
org.apache.ratis.trace.NoOpTraceProvider.traceClientSend(NoOpTraceProvider.java:41)
at org.apache.ratis.trace.TraceClient.asyncSend(TraceClient.java:37)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:42)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:48)
at org.apache.ratis.client.api.AsyncApi.send(AsyncApi.java:46)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.runTestBasicAppendEntries(TestRaftAsyncWithGrpc.java:82)
...
2026-08-27 10:51:05,544 [grpc-default-executor-0] DEBUG impl.OrderedAsync
(OrderedAsync.java:sendRequestWithRetry(207)) - client-000000000001: send*
RaftClientRequest:client-000000000001->s0@group-6B458A98A0E9, cid=2, seq=2, RW,
m0
2026-08-27 10:51:05,544 [grpc-default-executor-0] DEBUG util.SlidingWindow
(SlidingWindow.java:receivedRequest(453)) - Received seq=2, isRetry? false,
SlidingWindow$Server:0-OrderedRequestStreamObserver0: requests[2..2],
nextToProcess=2
{code}
was (Author: szetszwo):
{code}
2026-08-27 10:51:05,444 [main] DEBUG util.SlidingWindow
(SlidingWindow.java:sendOrDelayRequest(312)) -
SlidingWindow$Client:client-000000000001->RAFT: detect firstSubmitted [cid=1,
seq=1] in SlidingWindow$Client:client-000000000001->RAFT: requests[1..1],
nextSeqNum=2, firstSubmitted=-1, replied? false, delayed=[]
2026-08-27 10:51:05,444 [main] TRACE impl.OrderedAsync
(OrderedAsync.java:setFirstRequest(91)) - setFirstRequest: [cid=1, seq=1(1st)]
java.lang.Throwable
at
org.apache.ratis.client.impl.OrderedAsync$PendingOrderedRequest.setFirstRequest(OrderedAsync.java:91)
at
org.apache.ratis.util.SlidingWindow$Client.sendOrDelayRequest(SlidingWindow.java:314)
at
org.apache.ratis.util.SlidingWindow$Client.submitNewRequest(SlidingWindow.java:294)
at org.apache.ratis.client.impl.OrderedAsync.send(OrderedAsync.java:175)
at
org.apache.ratis.client.impl.OrderedAsync.newInstance(OrderedAsync.java:127)
at
org.apache.ratis.client.impl.RaftClientImpl.lambda$new$1(RaftClientImpl.java:213)
at
org.apache.ratis.util.MemoizedFunction.lambda$apply$0(MemoizedFunction.java:67)
at org.apache.ratis.util.MemoizedBase.init(MemoizedBase.java:49)
at
org.apache.ratis.util.MemoizedFunction.apply(MemoizedFunction.java:67)
at
org.apache.ratis.client.impl.RaftClientImpl.getOrderedAsync(RaftClientImpl.java:282)
at
org.apache.ratis.client.impl.AsyncImpl.lambda$send$0(AsyncImpl.java:43)
at
org.apache.ratis.trace.NoOpTraceProvider.traceClientSend(NoOpTraceProvider.java:41)
at org.apache.ratis.trace.TraceClient.asyncSend(TraceClient.java:37)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:42)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:48)
at org.apache.ratis.client.api.AsyncApi.send(AsyncApi.java:46)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.runTestBasicAppendEntries(TestRaftAsyncWithGrpc.java:82)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.lambda$testSingleAsyncRequest$0(TestRaftAsyncWithGrpc.java:63)
at
org.apache.ratis.server.impl.MiniRaftCluster$Factory$Get.runWithNewCluster(MiniRaftCluster.java:146)
at
org.apache.ratis.server.impl.MiniRaftCluster$Factory$Get.runWithNewCluster(MiniRaftCluster.java:124)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.testSingleAsyncRequest(TestRaftAsyncWithGrpc.java:62)
...
2026-08-27 10:51:05,446 [main] DEBUG client.RaftClient
(RaftClientImpl.java:get(160)) - client-000000000001: get 1 returns []
2026-08-27 10:51:05,447 [main] DEBUG client.RaftClient
(RaftClientImpl.java:newRequest(97)) - attempt #1, newRequest
RaftClientRequest:client-000000000001->s0@group-6B458A98A0E9, cid=1,
seq=1(1st), Watch(0), Message:DUMMY
java.lang.Throwable
at
org.apache.ratis.client.impl.RaftClientImpl$PendingClientRequest.newRequest(RaftClientImpl.java:97)
at
org.apache.ratis.client.impl.OrderedAsync.sendRequestWithRetry(OrderedAsync.java:198)
at
org.apache.ratis.util.SlidingWindow$Client.sendOrDelayRequest(SlidingWindow.java:315)
at
org.apache.ratis.util.SlidingWindow$Client.submitNewRequest(SlidingWindow.java:294)
at org.apache.ratis.client.impl.OrderedAsync.send(OrderedAsync.java:175)
at
org.apache.ratis.client.impl.OrderedAsync.newInstance(OrderedAsync.java:127)
at
org.apache.ratis.client.impl.RaftClientImpl.lambda$new$1(RaftClientImpl.java:213)
at
org.apache.ratis.util.MemoizedFunction.lambda$apply$0(MemoizedFunction.java:67)
at org.apache.ratis.util.MemoizedBase.init(MemoizedBase.java:49)
at
org.apache.ratis.util.MemoizedFunction.apply(MemoizedFunction.java:67)
at
org.apache.ratis.client.impl.RaftClientImpl.getOrderedAsync(RaftClientImpl.java:282)
at
org.apache.ratis.client.impl.AsyncImpl.lambda$send$0(AsyncImpl.java:43)
at
org.apache.ratis.trace.NoOpTraceProvider.traceClientSend(NoOpTraceProvider.java:41)
at org.apache.ratis.trace.TraceClient.asyncSend(TraceClient.java:37)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:42)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:48)
at org.apache.ratis.client.api.AsyncApi.send(AsyncApi.java:46)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.runTestBasicAppendEntries(TestRaftAsyncWithGrpc.java:82)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.lambda$testSingleAsyncRequest$0(TestRaftAsyncWithGrpc.java:63)
at
org.apache.ratis.server.impl.MiniRaftCluster$Factory$Get.runWithNewCluster(MiniRaftCluster.java:146)
at
org.apache.ratis.server.impl.MiniRaftCluster$Factory$Get.runWithNewCluster(MiniRaftCluster.java:124)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.testSingleAsyncRequest(TestRaftAsyncWithGrpc.java:62)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:144)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:101)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
at
org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:161)
at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:147)
at
org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:145)
at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:144)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:101)
at
org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
at
org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
at
org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.executeEngine(EngineExecutionOrchestrator.java:230)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.failOrExecuteEngine(EngineExecutionOrchestrator.java:204)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:172)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:101)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:64)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:150)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:63)
at
org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:109)
at
org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:91)
at
org.junit.platform.launcher.core.DelegatingLauncher.execute(DelegatingLauncher.java:47)
at
org.junit.platform.launcher.core.InterceptingLauncher.lambda$execute$1(InterceptingLauncher.java:39)
at
org.junit.platform.launcher.core.ClasspathAlignmentCheckingLauncherInterceptor.intercept(ClasspathAlignmentCheckingLauncherInterceptor.java:25)
at
org.junit.platform.launcher.core.InterceptingLauncher.execute(InterceptingLauncher.java:38)
at
org.junit.platform.launcher.core.DelegatingLauncher.execute(DelegatingLauncher.java:47)
at
org.junit.platform.launcher.core.SessionPerRequestLauncher.execute(SessionPerRequestLauncher.java:66)
at
com.intellij.junit5.JUnit5TestRunnerHelper.execute(JUnit5TestRunnerHelper.java:134)
at
com.intellij.junit5.JUnit5IdeaTestRunner.startRunnerWithArgs(JUnit5IdeaTestRunner.java:70)
at
com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
at
com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
at
com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
at
com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:226)
at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:62)
2026-08-27 10:51:05,447 [main] TRACE impl.OrderedAsync
(OrderedAsync.java:setFirstRequest(91)) - setFirstRequest: [cid=1, seq=1(1st)]
java.lang.Throwable
at
org.apache.ratis.client.impl.OrderedAsync$PendingOrderedRequest.setFirstRequest(OrderedAsync.java:91)
at
org.apache.ratis.client.impl.OrderedAsync.sendRequestWithRetry(OrderedAsync.java:205)
at
org.apache.ratis.util.SlidingWindow$Client.sendOrDelayRequest(SlidingWindow.java:315)
at
org.apache.ratis.util.SlidingWindow$Client.submitNewRequest(SlidingWindow.java:294)
at org.apache.ratis.client.impl.OrderedAsync.send(OrderedAsync.java:175)
at
org.apache.ratis.client.impl.OrderedAsync.newInstance(OrderedAsync.java:127)
at
org.apache.ratis.client.impl.RaftClientImpl.lambda$new$1(RaftClientImpl.java:213)
at
org.apache.ratis.util.MemoizedFunction.lambda$apply$0(MemoizedFunction.java:67)
at org.apache.ratis.util.MemoizedBase.init(MemoizedBase.java:49)
at
org.apache.ratis.util.MemoizedFunction.apply(MemoizedFunction.java:67)
at
org.apache.ratis.client.impl.RaftClientImpl.getOrderedAsync(RaftClientImpl.java:282)
at
org.apache.ratis.client.impl.AsyncImpl.lambda$send$0(AsyncImpl.java:43)
at
org.apache.ratis.trace.NoOpTraceProvider.traceClientSend(NoOpTraceProvider.java:41)
at org.apache.ratis.trace.TraceClient.asyncSend(TraceClient.java:37)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:42)
at org.apache.ratis.client.impl.AsyncImpl.send(AsyncImpl.java:48)
at org.apache.ratis.client.api.AsyncApi.send(AsyncApi.java:46)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.runTestBasicAppendEntries(TestRaftAsyncWithGrpc.java:82)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.lambda$testSingleAsyncRequest$0(TestRaftAsyncWithGrpc.java:63)
at
org.apache.ratis.server.impl.MiniRaftCluster$Factory$Get.runWithNewCluster(MiniRaftCluster.java:146)
at
org.apache.ratis.server.impl.MiniRaftCluster$Factory$Get.runWithNewCluster(MiniRaftCluster.java:124)
at
org.apache.ratis.grpc.TestRaftAsyncWithGrpc.testSingleAsyncRequest(TestRaftAsyncWithGrpc.java:62)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at
org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:786)
at
org.junit.platform.commons.support.ReflectionSupport.invokeMethod(ReflectionSupport.java:514)
at
org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
at
org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
at
org.junit.jupiter.engine.extension.SameThreadTimeoutInvocation.proceed(SameThreadTimeoutInvocation.java:49)
at
org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:161)
at
org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:152)
at
org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:91)
at
org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:112)
at
org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:94)
at
org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
at
org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
at
org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
at
org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
at
org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:93)
at
org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:87)
at
org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$4(TestMethodTestDescriptor.java:221)
at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at
org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:217)
at
org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:159)
at
org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:70)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:157)
at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:147)
at
org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:145)
at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:144)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:101)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
at
org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:161)
at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:147)
at
org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:145)
at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:144)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:101)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
at
org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:161)
at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:147)
at
org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:145)
at
org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:144)
at
org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:101)
at
org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
at
org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
at
org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.executeEngine(EngineExecutionOrchestrator.java:230)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.failOrExecuteEngine(EngineExecutionOrchestrator.java:204)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:172)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:101)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:64)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:150)
at
org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:63)
at
org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:109)
at
org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:91)
at
org.junit.platform.launcher.core.DelegatingLauncher.execute(DelegatingLauncher.java:47)
at
org.junit.platform.launcher.core.InterceptingLauncher.lambda$execute$1(InterceptingLauncher.java:39)
at
org.junit.platform.launcher.core.ClasspathAlignmentCheckingLauncherInterceptor.intercept(ClasspathAlignmentCheckingLauncherInterceptor.java:25)
at
org.junit.platform.launcher.core.InterceptingLauncher.execute(InterceptingLauncher.java:38)
at
org.junit.platform.launcher.core.DelegatingLauncher.execute(DelegatingLauncher.java:47)
at
org.junit.platform.launcher.core.SessionPerRequestLauncher.execute(SessionPerRequestLauncher.java:66)
at
com.intellij.junit5.JUnit5TestRunnerHelper.execute(JUnit5TestRunnerHelper.java:134)
at
com.intellij.junit5.JUnit5IdeaTestRunner.startRunnerWithArgs(JUnit5IdeaTestRunner.java:70)
at
com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
at
com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
at
com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
at
com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:226)
at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:62)
2026-08-27 10:51:05,448 [main] DEBUG impl.OrderedAsync
(OrderedAsync.java:sendRequestWithRetry(207)) - client-000000000001: send*
RaftClientRequest:client-000000000001->s0@group-6B458A98A0E9, cid=1,
seq=1(1st), Watch(0), Message:DUMMY
2026-08-27 10:51:05,487 [main] DEBUG util.SlidingWindow
(SlidingWindow.java:submitNewRequest(295)) -
SlidingWindow$Client:client-000000000001->RAFT: submitting a new request
[cid=1, seq=1(1st)] in SlidingWindow$Client:client-000000000001->RAFT:
requests[1..1], nextSeqNum=2, firstSubmitted=1, replied? false, delayed=[]?
submitted
2026-08-27 10:51:05,488 [main] DEBUG util.SlidingWindow
(SlidingWindow.java:submitNewRequest(295)) -
SlidingWindow$Client:client-000000000001->RAFT: submitting a new request
[cid=2, seq=2] in SlidingWindow$Client:client-000000000001->RAFT:
requests[1..2], nextSeqNum=3, firstSubmitted=1, replied? false, delayed=[2]?
delayed
Aug 27, 2026 10:51:05 AM org.apache.ratis.thirdparty.io.grpc.netty.TcpMetrics
loadEpollInfo
INFO: Epoll available during static init of TcpMetrics:false
2026-08-27 10:51:05,533 [grpc-default-executor-0] DEBUG util.SlidingWindow
(SlidingWindow.java:receivedRequest(450)) - Received seq=1 (first request),
SlidingWindow$Server:0-OrderedRequestStreamObserver0: requests[1..1],
nextToProcess=1
2026-08-27 10:51:05,534 [s0-client-thread1] DEBUG server.RaftServer$Division
(RaftServerImpl.java:submitClientRequestAsyncInternal(995)) -
s0@group-6B458A98A0E9: receive client
request(RaftClientRequest:client-000000000001->s0@group-6B458A98A0E9, cid=1,
seq=1(1st), Watch(0), Message:DUMMY)
2026-08-27 10:51:05,535 [null-request--thread1] DEBUG util.SlidingWindow
(SlidingWindow.java:setReply(146)) -
SlidingWindow$Server:0-OrderedRequestStreamObserver0: set reply
RaftClientReply:client-000000000001->s0@group-6B458A98A0E9, cid=1, FAILED null,
logIndex=0, commits[] for seq=1 in
SlidingWindow$Server:0-OrderedRequestStreamObserver0: requests[1..1]
2026-08-27 10:51:05,543 [grpc-default-executor-0] DEBUG impl.OrderedAsync
(OrderedAsync.java:lambda$sendRequestWithRetry$5(209)) - client-000000000001:
receive* RaftClientReply:client-000000000001->s0@group-6B458A98A0E9, cid=1,
FAILED null, logIndex=0, commits[]
2026-08-27 10:51:05,543 [grpc-default-executor-0] DEBUG util.SlidingWindow
(SlidingWindow.java:setReply(146)) -
SlidingWindow$Client:client-000000000001->RAFT: set reply
RaftClientReply:client-000000000001->s0@group-6B458A98A0E9, cid=1, FAILED null,
logIndex=0, commits[] for seq=1 in
SlidingWindow$Client:client-000000000001->RAFT: requests[1..2]
{code}
> In OrderedAsync, setFirstRequest() is not needed.
> -------------------------------------------------
>
> Key: RATIS-2677
> URL: https://issues.apache.org/jira/browse/RATIS-2677
> Project: Ratis
> Issue Type: Improvement
> Components: client
> Reporter: Tsz-wo Sze
> Priority: Major
> Attachments: RATIS-2677_test.patch
>
>
> {code}
> //OrderedAsync
> private void sendRequestWithRetry(PendingOrderedRequest pending) {
> ...
> if (getSlidingWindow(request).isFirst(pending.getSeqNum())) {
> pending.setFirstRequest();
> }
> ...
> }
> {code}
> {code}
> As pointed out by Teligen_ligc in [this
> email|https://lists.apache.org/thread/3vnv0ro2vvz8ckm08t7mm93yo2c1g4f1], the
> call setFirstRequest() above is not needed since it is already set by
> [SlidingWindow$Client.sendOrDelayRequest(..)|https://github.com/apache/ratis/blob/31427daaab2a4f7e95d3be0a0bd654683f7965c4/ratis-common/src/main/java/org/apache/ratis/util/SlidingWindow.java#L314].
> - It is better to change setFirstRequest() in OrderedAsync to an assertion.
> - We should also include isFirst info in the log messages.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
