Skip to content

fix(store-client): stop retrying after DEADLINE_EXCEEDED and honour thread interrupts in NodeTxExecutor - #3204

Open
SebastianGruza wants to merge 4 commits into
apache:masterfrom
SebastianGruza:fix/store-client-retry-interrupt
Open

fix(store-client): stop retrying after DEADLINE_EXCEEDED and honour thread interrupts in NodeTxExecutor#3204
SebastianGruza wants to merge 4 commits into
apache:masterfrom
SebastianGruza:fix/store-client-retry-interrupt

Conversation

@SebastianGruza

Copy link
Copy Markdown

Purpose of the PR

When a store node stops answering, NodeTxExecutor.retryingInvoke() (hg-store-client) retries the failing call up to NODE_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 by grpc.timeout.seconds (default 100 s). After a DEADLINE_EXCEEDED the next attempt just waits the full deadline again, so one commit or one point lookup on a stalled partition holds its calling thread for 11 × grpc.timeout.seconds + 38 s (about 19 minutes on defaults). The loop also catches the InterruptedException from Thread.sleep, logs Failed to sleep and continues, so the interrupt sent by restserver.request_timeout (REST worker) or by the Gremlin Server evaluationTimeout is 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 an HgStoreClientException.
  • Do not retry a failure whose cause chain carries Status.Code.DEADLINE_EXCEEDED, Status.Code.CANCELLED or an InterruptedException (isRetryable()); a second attempt cannot succeed faster than the deadline that just expired. UNAVAILABLE and 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.
  • No change to the attempt count or the sleep schedule; making them configurable is a possible follow-up.

Verifying these changes

  • New unit tests in NodeTxExecutorTest (hg-store-test, store-client-test profile): isRetryable() classification, a DEADLINE_EXCEEDED failure makes exactly one attempt, an interrupt during a retryable failure stops the loop after one attempt with the interrupt flag restored, and an UNAVAILABLE failure is still retried and succeeds on the second attempt.

    mvn test -pl hugegraph-store/hg-store-test -am -P store-client-test -Dtest=NodeTxExecutorTest -Dsurefire.failIfNoSpecifiedTests=false
    

    6/6 pass on Temurin 17.

  • Before/after on a live PD + 3-store cluster (master 36811483, one store frozen with SIGSTOP, one POST /graph/vertices per second for 300 s, a probe GET every 2 s, grpc.timeout.seconds=20 so that a run fits in minutes):

    before after
    REST unavailable (probe gets 503) 431 of 503 s 12 of 300 s
    REST still unavailable after the writer stopped 200 s 0 s
    300 writes 27 × 201, 243 × 503, 23 × 500 131 × 201, 152 × 500 after 20.0 s, 7 × 503
    slowest write 257 s (= 11 × 20 + 38) 20.1 s
    server log Failed to sleep ×30, reached the upper limit ×30 Failed to sleep 0, Not retrying after ×152

    Full 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?

  • Dependencies (add/update license info)
  • Modify configurations
  • The public API
  • Other affects: retry semantics of the HStore client — DEADLINE_EXCEEDED/CANCELLED are no longer retried, interrupts are honoured
  • Nope

Documentation Status

  • Doc - TODO
  • Doc - Done
  • Doc - No Need

… 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).

@bitflicker64 bitflicker64 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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)) {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ On a commit that spans more than one partition, whether this gate fires is decided by a race, so the fix is not guaranteed to engage on the very workload the issue describes.

Evidence:

  • doCommit() commits every session in parallel and keeps only the first throwable: sessions.parallelStream().forEach(...) with throwable.compareAndSet(null, t) (NodeTxExecutor.java:136-145). Which ForkJoinPool task wins is nondeterministic.
  • That single throwable is the only one rethrown (:154-161), so it is the only input isRetryable() 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 the UNAVAILABLE lands first, the commit is retried up to 11 times and each attempt still blocks on the stalled partition for the full grpc.timeout.seconds (AbstractGrpcClient.java:128). That is 11 × grpc.timeout.seconds of 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 / testDeadlineExceededIsNotRetried each 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.

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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: {}",

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 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 nested StatusRuntimeException and 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.

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done in 8adf522 — the throwable is passed as the trailing argument.

}
} else {
if (i + 1 > NODE_MAX_RETRYING_TIMES) {
log.error(maxTryMsg, t);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Ordering the attempt-budget check before the retryability check makes the last attempt log the wrong reason.

Evidence:

  • At i == NODE_MAX_RETRYING_TIMES the loop takes :392-396 first, so a DEADLINE_EXCEEDED on the final attempt is reported as "the number of retries reached the upper limit : 10" (maxTryMsg, :58-60) even though the new gate at :397 is what should have described it.
  • This is reachable in the scenario the PR targets: attempts 0-9 fail UNAVAILABLE while 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.

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done in 8adf522isRetryable() is checked first, the attempt budget second.

Thread.currentThread().interrupt();
throw new RuntimeException("simulated transport failure");
}));
assertEquals(1, attempts.get());

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 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 the i == 0 guard at NodeTxExecutor.java:381-387 runs on a clean thread, isRetryable(new RuntimeException(...)) is true, and the abort comes from the catch (InterruptedException) around Thread.sleep at NodeTxExecutor.java:411-418.
  • This assertion proves it: assertEquals(1, attempts.get()). Had the guard fired, the supplier would never have run and attempts would be 0.
  • The untested branch is the one that matters for a caller whose restserver.request_timeout expired 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.

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done in 8adf522testInterruptBeforeCallSkipsTheAttempt 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()))));

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Two style nits in the new test code.

Evidence:

  • This line is 104 characters, over the project's LineLength max 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 call Status.<CODE>.asRuntimeException() and never name the type. UnusedImports is enabled at style/checkstyle.xml:59.
  • Neither breaks the build — the checkstyle plugin is bound only in hugegraph-server/pom.xml:295 and hugegraph-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.

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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 bitflicker64 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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) {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Not retrying 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_WORK notice (NotifyingExecutor.java:117-123, :244-255). HgStoreNodePartitionerImpl.notice() then calls pdClient.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-runs doAction() 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 default grpc.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.

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[Bug] A stalled HStore node holds REST workers for minutes: store-client commit retry swallows interrupts

2 participants