fix(store-client): stop retrying after DEADLINE_EXCEEDED and honour thread interrupts in NodeTxExecutor - #3204
Conversation
… honour thread interrupts NodeTxExecutor.retryingInvoke() retried every failure up to NODE_MAX_RETRYING_TIMES (10) with a sleep schedule of 1,1,1,2..8 s and swallowed the InterruptedException from Thread.sleep. When a partition leader stops answering, one commit therefore held the calling REST worker for 11 x grpc.timeout.seconds + 38 s (about 19 min on defaults) and restserver.request_timeout could not stop it, so a single stalled store node exhausted the REST worker pool. Now the loop aborts when the calling thread is interrupted (restoring the interrupt flag) and does not retry a DEADLINE_EXCEEDED or CANCELLED status: a second attempt would only wait the full deadline again. UNAVAILABLE and other transport errors are retried as before (store replacement, leader change).
…d interrupt handling in NodeTxExecutor
bitflicker64
left a comment
There was a problem hiding this comment.
Blocking: no. Summary: the fix holds at 4350ef99 — the exception the retry loop sees really does carry the gRPC status (NotifyingExecutor.invoke() rethrows err(t) = HgStoreClientException.of(msg, t) at NotifyingExecutor.java:74-82, GrpcStoreNodeSessionImpl.commit() wraps it in RuntimeException(t) at :139-141, and doCommit() unwraps one level at NodeTxExecutor.java:154-161), and no recovery path is lost by dropping DEADLINE_EXCEEDED from the retry set, because the node-invalidation notice that would make a retry resolve a different leader only fires for UNAVAILABLE (NotifyingExecutor.java:244-255) while leader moves arrive in-band as PARTITION_FAULT_TYPE_NOT_LEADER on an HgStoreClientException with no gRPC cause (:150-171), which isRetryable() still retries. Interrupt-flag hygiene is safe for pooled callers: Grizzly clears the flag at the top of every task (AbstractThreadPool.Worker.doWork(), grizzly-framework 3.0.1 line 526), as does ThreadPoolExecutor.runWorker. Five comments below, none blocking; the important one is that doCommit() keeps only the first of several parallel commit failures, so on a mixed-failure commit whether the new fail-fast engages is decided by a race. Evidence: static review of the exact-head diff (2 files, +128/-18) against merge-base 36811483; suite wiring checked (ClientSuiteTest lists NodeTxExecutorTest.class, hg-store-test/pom.xml:227-237 includes **/ClientSuiteTest.java, run by pd-store-ci.yml:286). No CI signal at this head — all seven workflows are action_required awaiting maintainer approval, so gh api repos/apache/hugegraph/commits/4350ef99.../status is pending and check-runs is empty. The new tests could not be executed locally: mvn test -pl hugegraph-store/hg-store-test -am -P store-client-test fails in the untouched hugegraph-commons/hugegraph-common module with lombok annotations unprocessed, so the author's 6/6 result is unverified here.
| throw HgStoreClientException.of( | ||
| t.getMessage(), t); | ||
| } | ||
| if (!isRetryable(t)) { |
There was a problem hiding this comment.
Evidence:
doCommit()commits every session in parallel and keeps only the first throwable:sessions.parallelStream().forEach(...)withthrowable.compareAndSet(null, t)(NodeTxExecutor.java:136-145). WhichForkJoinPooltask wins is nondeterministic.- That single throwable is the only one rethrown (
:154-161), so it is the only inputisRetryable()ever sees for the whole commit — the other nodes' failures are discarded, not even suppressed. - So for a commit touching a stalled node (
DEADLINE_EXCEEDED) and a node being replaced (UNAVAILABLE, the refactor(store): recover retries after store replacement #3130 recovery this PR is careful to preserve): if theUNAVAILABLElands first, the commit is retried up to 11 times and each attempt still blocks on the stalled partition for the fullgrpc.timeout.seconds(AbstractGrpcClient.java:128). That is11 × grpc.timeout.secondsof held caller thread — the stall from [Bug] A stalled HStore node holds REST workers for minutes: store-client commit retry swallows interrupts #3199, unchanged. - Nothing pins this: all four new tests use a supplier with a single failure mode, and
testTransientFailureIsStillRetried/testDeadlineExceededIsNotRetriedeach exercise one node's worth of behaviour.
Requested change: collect every failure instead of the first (a ConcurrentLinkedQueue<Throwable> or Collections.synchronizedList) and make the decision deterministic — retry only when every captured failure is retryable, attaching the rest as suppressed on the thrown HgStoreClientException — and add a test for a two-session commit where one session fails DEADLINE_EXCEEDED and the other UNAVAILABLE, asserting exactly one attempt.
There was a problem hiding this comment.
Done in 8adf522. commitSessions() now collects every session failure in a ConcurrentLinkedQueue and throws one HgStoreClientException (first failure unwrapped one level as before, the others attached as suppressed); isRetryable() walks the suppressed failures as well as the cause chain (identity-set guarded against cycles), so one DEADLINE_EXCEEDED among several failures makes the attempt non-retryable regardless of which partition reported first. Tests: testMixedCommitFailuresAreNotRetried (two sessions, UNAVAILABLE + DEADLINE_EXCEEDED thrown fresh on every call, exactly one attempt, both sessions rolled back, one suppressed) and testAllRetryableCommitFailuresAreRetried.
| // A deadline or a cancellation will not | ||
| // get better by waiting the full deadline | ||
| // again; fail fast and let the caller decide. | ||
| log.warn("Not retrying after: {}", |
There was a problem hiding this comment.
🧹 This log drops the throwable, on what this change makes the common failure path.
Evidence:
log.warn("Not retrying after: {}", t.getMessage())passes only the message, so nothing reaches the logger's throwable slot.- The branch four lines up keeps it:
log.error(maxTryMsg, t)(:393). Before this PR that was the only place a store failure was logged with its cause chain; after it, a stalled node takes this branch on the first attempt and never reaches:393, so the nestedStatusRuntimeExceptionand its stack trace are no longer in the server log at all.
Requested change: log.warn("Not retrying after: {}", t.getMessage(), t); — slf4j appends a trailing Throwable argument as the cause.
There was a problem hiding this comment.
Done in 8adf522 — the throwable is passed as the trailing argument.
| } | ||
| } else { | ||
| if (i + 1 > NODE_MAX_RETRYING_TIMES) { | ||
| log.error(maxTryMsg, t); |
There was a problem hiding this comment.
🧹 Ordering the attempt-budget check before the retryability check makes the last attempt log the wrong reason.
Evidence:
- At
i == NODE_MAX_RETRYING_TIMESthe loop takes:392-396first, so aDEADLINE_EXCEEDEDon the final attempt is reported as"the number of retries reached the upper limit : 10"(maxTryMsg,:58-60) even though the new gate at:397is what should have described it. - This is reachable in the scenario the PR targets: attempts 0-9 fail
UNAVAILABLEwhile a store is being replaced (still retried by design), then attempt 10 hits the deadline on the new node.
Requested change: move the if (!isRetryable(t)) block above the i + 1 > NODE_MAX_RETRYING_TIMES block so each exit logs the reason that actually applied.
There was a problem hiding this comment.
Done in 8adf522 — isRetryable() is checked first, the attempt budget second.
| Thread.currentThread().interrupt(); | ||
| throw new RuntimeException("simulated transport failure"); | ||
| })); | ||
| assertEquals(1, attempts.get()); |
There was a problem hiding this comment.
🧹 The new pre-attempt interrupt guard has no coverage; this test exercises only the sleep handler.
Evidence:
- The supplier increments
attempts, then sets the flag, then throws (:163-165). So thei == 0guard atNodeTxExecutor.java:381-387runs on a clean thread,isRetryable(new RuntimeException(...))is true, and the abort comes from thecatch (InterruptedException)aroundThread.sleepatNodeTxExecutor.java:411-418. - This assertion proves it:
assertEquals(1, attempts.get()). Had the guard fired, the supplier would never have run andattemptswould be0. - The untested branch is the one that matters for a caller whose
restserver.request_timeoutexpired between store calls rather than during one — the case the guard's own comment cites.
Requested change: add a case that sets the flag before the call, e.g. Thread.currentThread().interrupt(); assertThrows(HgStoreClientException.class, () -> executor.retryingInvoke(() -> { attempts.incrementAndGet(); return "ok"; })); assertEquals(0, attempts.get());, with the same finally { Thread.interrupted(); } guard this test already uses.
There was a problem hiding this comment.
Done in 8adf522 — testInterruptBeforeCallSkipsTheAttempt sets the flag before the call and asserts attempts == 0 with the flag still set.
| assertFalse(NodeTxExecutor.isRetryable(new InterruptedException("interrupted"))); | ||
| // The status is usually wrapped by the time it reaches the retry loop | ||
| assertFalse(NodeTxExecutor.isRetryable(HgStoreClientException.of( | ||
| "commit failed", new RuntimeException(Status.DEADLINE_EXCEEDED.asRuntimeException())))); |
There was a problem hiding this comment.
🧹 Two style nits in the new test code.
Evidence:
- This line is 104 characters, over the project's
LineLengthmax of 100 (style/checkstyle.xml:29-32). It is the only added line in the diff that exceeds it. import io.grpc.StatusRuntimeException(:43) is unused: the tests only callStatus.<CODE>.asRuntimeException()and never name the type.UnusedImportsis enabled atstyle/checkstyle.xml:59.- Neither breaks the build — the checkstyle plugin is bound only in
hugegraph-server/pom.xml:295andhugegraph-commons/pom.xml:147, not in the store modules — so this is purely to keep the new code inside the shared style.
Requested change: wrap the argument list onto a second line and drop the unused import.
There was a problem hiding this comment.
Done in 8adf522 — line wrapped, unused import removed; no added line exceeds 100 characters now.
…; log the cause; cover the pre-attempt interrupt guard Review follow-ups on apache#3204: - commitSessions() collects every session failure (ConcurrentLinkedQueue) and throws one HgStoreClientException with the others as suppressed; isRetryable() inspects suppressed failures too (cycle-safe), so a DEADLINE_EXCEEDED on one partition is never retried because an UNAVAILABLE on another happened to be reported first - retryability is checked before the attempt budget, so the last attempt logs the reason that applied - the non-retry warning carries the throwable - tests: mixed-failure commit (one attempt, both sessions rolled back), all-retryable commit, interrupt set before the call skips the attempt; style nits
bitflicker64
left a comment
There was a problem hiding this comment.
Blocking: no. Summary: the earlier follow-ups are in at 8adf522 and the interrupt handling looks right; one inline comment on DEADLINE_EXCEEDED no longer riding through a partition leader failover, which corrects what my earlier summary said about that. Evidence: static trace through NotifyingExecutor, HgStoreNodePartitionerImpl, ClientCache and PartitionEngine at the exact head; mvn test -pl hugegraph-store/hg-store-test -am -P store-client-test -Dtest=NodeTxExecutorTest passes locally on JDK 17 (9 tests, 0 failures). No CI signal at this head: all seven workflows are action_required, waiting for maintainer approval.
| } | ||
| if (c instanceof StatusRuntimeException) { | ||
| Status.Code code = ((StatusRuntimeException) c).getStatus().getCode(); | ||
| if (code == Status.Code.DEADLINE_EXCEEDED || code == Status.Code.CANCELLED) { |
There was a problem hiding this comment.
DEADLINE_EXCEEDED also drops a leader-failover recovery. The Javadoc's reasoning (a retry waits the full deadline again) holds when the retry goes to the same store, which is not the case once the partition leader has moved. This corrects my earlier summary, which only looked at node eviction.
Evidence:
- Every RPC error sends a
NOT_WORKnotice (NotifyingExecutor.java:117-123,:244-255).HgStoreNodePartitionerImpl.notice()then callspdClient.invalidPartitionCache()(HgStoreNodePartitionerImpl.java:190-195), which reloads shard-group leaders from PD right away (ClientCache.java:220-230,:178-186). - The retried
doCommit()supplier re-runsdoAction()for every entry (NodeTxExecutor.java:132-135), so it routes against the reloaded leaders (NodeTxSessionProxy.java:731-734,:862-866). - A new raft leader is elected after the 3 s election timeout (
HgStoreEngineOptions.java:91) and pushes its shard group to PD (PartitionEngine.java:605-681), well inside the 100 s defaultgrpc.timeout.seconds(HgStoreClientConfig.java:30).
So with replicated partitions, attempt 1 used to reach the new leader; now the call fails after attempt 0. Interrupted REST workers still stop after one deadline either way, but callers with no timeout that interrupts them (async jobs are only interrupted on cancel) lose the recovery. Was the SIGSTOP cluster at the shipped default-shard-count: 1 (hugegraph-pd/hg-pd-dist/src/assembly/static/conf/application.yml:95)? With 3 replicas the before run should have recovered on attempt 1.
Requested change: allow at most one DEADLINE_EXCEEDED retry per retryingInvoke() call (keep CANCELLED and InterruptedException non-retryable), update the Javadoc to match, and make testDeadlineExceededIsNotRetried expect two attempts.
There was a problem hiding this comment.
Agreed, and yes — the SIGSTOP cluster runs with the shipped default-shard-count: 1, so it never had a leader to fail over to; with replicas the first retry would indeed have reached the new leader. Done in b588aa8: retryingInvoke() now classifies a failure as FATAL (interrupt, CANCELLED: never retried), DEADLINE (retried exactly once per call, then failed on a second deadline in a row) or RETRYABLE (unchanged); suppressed failures of a parallel commit are classified as well and the most severe class wins. Javadoc updated. Tests: testDeadlineExceededIsRetriedExactlyOnce expects two attempts, testDeadlineThenNewLeaderSucceeds covers the failover case, the mixed-commit test now expects two attempts, testClassifyFailures replaces the old isRetryable test. 10/10 locally on JDK 17.
…rtition leader is still reached Review follow-up on apache#3204: the NOT_WORK notice sent for the failed RPC reloads the partition leaders, so with replicated partitions the next attempt can reach a new raft leader. retryingInvoke() now classifies a failure as FATAL (interrupt, CANCELLED: never retried), DEADLINE (retried once per call; a second deadline in a row would only wait the full deadline again on the same stalled store) or RETRYABLE (as before). Suppressed failures of a parallel commit are classified too, the most severe class wins. Tests: classification, deadline retried exactly once, deadline then new leader succeeds, mixed commit retried once.
Purpose of the PR
When a store node stops answering,
NodeTxExecutor.retryingInvoke()(hg-store-client) retries the failing call up toNODE_MAX_RETRYING_TIMES(10) with a 1, 1, 1, 2, 3, 4, 5, 6, 7, 8 s sleep schedule, and every attempt is a blocking gRPC call bounded only bygrpc.timeout.seconds(default 100 s). After aDEADLINE_EXCEEDEDthe next attempt just waits the full deadline again, so one commit or one point lookup on a stalled partition holds its calling thread for11 × grpc.timeout.seconds + 38 s(about 19 minutes on defaults). The loop also catches theInterruptedExceptionfromThread.sleep, logsFailed to sleepand continues, so the interrupt sent byrestserver.request_timeout(REST worker) or by the Gremlin ServerevaluationTimeoutis swallowed and neither limit can free the thread. With a writer at 1 request/s, a single stalled store node exhausts the REST worker pool within tens of seconds and the server answers 503 to everything for minutes after the writer stops.Main Changes
NodeTxExecutor.retryingInvoke(): abort the loop when the calling thread is interrupted (before an attempt, or while sleeping between attempts), restoring the interrupt flag and surfacing anHgStoreClientException.Status.Code.DEADLINE_EXCEEDED,Status.Code.CANCELLEDor anInterruptedException(isRetryable()); a second attempt cannot succeed faster than the deadline that just expired.UNAVAILABLEand other transport failures are retried exactly as before, which is what the store-replacement recovery of refactor(store): recover retries after store replacement #3130 relies on.Verifying these changes
New unit tests in
NodeTxExecutorTest(hg-store-test,store-client-testprofile):isRetryable()classification, aDEADLINE_EXCEEDEDfailure makes exactly one attempt, an interrupt during a retryable failure stops the loop after one attempt with the interrupt flag restored, and anUNAVAILABLEfailure is still retried and succeeds on the second attempt.6/6 pass on Temurin 17.
Before/after on a live PD + 3-store cluster (master
36811483, one store frozen withSIGSTOP, onePOST /graph/verticesper second for 300 s, a probeGETevery 2 s,grpc.timeout.seconds=20so that a run fits in minutes):Failed to sleep×30,reached the upper limit×30Failed to sleep0,Not retrying after×152Full logs and the reproduction script: https://github.com/SebastianGruza/hugegraph-validation/blob/master/docs/findings.md#f15
Trivial rework / code cleanup without any test coverage. (No Need)
Already covered by existing tests, such as (please modify tests here).
Need tests and can be verified as shown above.
Does this PR potentially affect the following parts?
DEADLINE_EXCEEDED/CANCELLEDare no longer retried, interrupts are honouredDocumentation Status
Doc - TODODoc - DoneDoc - No Need