voonhous commented on code in PR #19485:
URL: https://github.com/apache/hudi/pull/19485#discussion_r3916671585
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/TestHoodieDeltaStreamer.java:
##########
@@ -1754,6 +1754,12 @@ static void deltaStreamerTestRunner(HoodieDeltaStreamer
ds, HoodieDeltaStreamer.
});
TestHelpers.waitTillCondition(condition, dsFuture, 360);
Review Comment:
**major:** On the timeout path the `AssertionError` leaves this method
before `ds.shutdownGracefully()` or `executor.shutdown()` run, so the
continuous streamer keeps going into the next test in the same fork
(`forkCount=1`, `reuseForks=true`). That test's `UtilitiesTestBase.setup()`
deletes `basePath` and its `teardown()` calls `TestDataSource.resetDataGen()`,
which closes the generators the leaked streamer is still reading. Pre-existing,
but it is the exact path this PR is about. Could we shut the streamer down when
the wait fails (catch, `ds.shutdownGracefully()`, rethrow) and move
`executor.shutdown()` into a `finally`?
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/HoodieDeltaStreamerTestBase.java:
##########
@@ -763,22 +766,55 @@ static HoodieInstant
assertCommitMetadataForIncrSource(String expected, String t
return lastInstant;
}
+ /**
+ * Polls {@code condition} until it holds, the deltastreamer future
finishes, or the timeout expires.
+ *
+ * <p>On timeout the last error the condition threw is attached to the
failure. Without it the only
+ * output is a bare {@link TimeoutException} pointing at this method,
which says nothing about which
+ * assertion never held - the reason HUDI-6843 stayed open: every report
of it looks identical.
+ */
static void waitTillCondition(Function<Boolean, Boolean> condition, Future
dsFuture, long timeoutInSecs) throws Exception {
- Future<Boolean> res = Executors.newSingleThreadExecutor().submit(() -> {
- boolean ret = false;
- while (!ret && !dsFuture.isDone()) {
- try {
- Thread.sleep(2000);
- ret = condition.apply(true);
- log.info("Condition completed successfully");
- } catch (Throwable error) {
- log.debug("Got error waiting for condition", error);
- ret = false;
+ AtomicReference<Throwable> lastError = new AtomicReference<>();
+ ExecutorService executor = Executors.newSingleThreadExecutor();
+ try {
+ Future<Boolean> res = executor.submit(() -> {
+ boolean ret = false;
+ while (!ret && !dsFuture.isDone() &&
!Thread.currentThread().isInterrupted()) {
Review Comment:
**minor:** The interrupt from `shutdownNow()` is delivered once, so a
condition that swallows it leaves this guard false forever and the poller runs
for the JVM lifetime. `TestHelpers.waitFor` (line 824) does exactly that,
`catch (Throwable)` around `Thread.sleep(5)`, and it runs inside the conditions
at `TestHoodieDeltaStreamer.java:2197` and `:2257`, so for those two tests the
stop that `pollingStopsOnceTheWaitHasGivenUp` pins does not hold. Not blocking.
Could the guard also check the executor, and could `waitFor` restore the flag
(and get a timeout) while here?
```suggestion
while (!ret && !dsFuture.isDone() &&
!Thread.currentThread().isInterrupted() && !executor.isShutdown()) {
```
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/HoodieDeltaStreamerTestBase.java:
##########
@@ -763,22 +766,55 @@ static HoodieInstant
assertCommitMetadataForIncrSource(String expected, String t
return lastInstant;
}
+ /**
+ * Polls {@code condition} until it holds, the deltastreamer future
finishes, or the timeout expires.
+ *
+ * <p>On timeout the last error the condition threw is attached to the
failure. Without it the only
+ * output is a bare {@link TimeoutException} pointing at this method,
which says nothing about which
+ * assertion never held - the reason HUDI-6843 stayed open: every report
of it looks identical.
+ */
static void waitTillCondition(Function<Boolean, Boolean> condition, Future
dsFuture, long timeoutInSecs) throws Exception {
- Future<Boolean> res = Executors.newSingleThreadExecutor().submit(() -> {
- boolean ret = false;
- while (!ret && !dsFuture.isDone()) {
- try {
- Thread.sleep(2000);
- ret = condition.apply(true);
- log.info("Condition completed successfully");
- } catch (Throwable error) {
- log.debug("Got error waiting for condition", error);
- ret = false;
+ AtomicReference<Throwable> lastError = new AtomicReference<>();
+ ExecutorService executor = Executors.newSingleThreadExecutor();
+ try {
+ Future<Boolean> res = executor.submit(() -> {
+ boolean ret = false;
+ while (!ret && !dsFuture.isDone() &&
!Thread.currentThread().isInterrupted()) {
+ try {
+ Thread.sleep(2000);
+ ret = condition.apply(true);
+ if (ret) {
+ log.info("Condition completed successfully");
+ }
+ } catch (InterruptedException interrupted) {
+ // shutdownNow below interrupts this thread once the wait has
given up. Thread.sleep clears
+ // the interrupt flag when it throws, so catching this with
everything else would re-enter
+ // the loop and keep polling forever. Restore the flag and stop;
this is not a condition
+ // failure, so it is deliberately not recorded as one.
+ Thread.currentThread().interrupt();
+ break;
+ } catch (Throwable error) {
+ lastError.set(error);
+ ret = false;
+ }
}
+ return ret;
+ });
+ try {
+ res.get(timeoutInSecs, TimeUnit.SECONDS);
+ } catch (TimeoutException e) {
+ Throwable last = lastError.get();
+ String detail = last == null
+ ? "The condition returned false without throwing, so there is no
further detail."
+ : "The last failure it reported was: " + last;
+ Throwable cause = last == null ? e : last;
Review Comment:
**minor:** With `last == null` this puts a `TimeoutException` with a null
message in the cause chain. `JavaTestUtils.checkNestedExceptionContains`
(hudi-common, line 31) calls `getMessage().contains(...)` unguarded, so in
`runJobsInParallel`'s catch (`TestHoodieDeltaStreamerWithMultiWriter.java:441`)
it NPEs and the new message is lost. Reachable when the condition hangs before
its first throw. Not blocking. Could we null-guard that helper
(`String.valueOf(throwable.getMessage()).contains(errorMsg)`, which also covers
NPEs in a chain), or drop the cause when `last == null`?
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/HoodieDeltaStreamerTestBase.java:
##########
@@ -763,22 +766,55 @@ static HoodieInstant
assertCommitMetadataForIncrSource(String expected, String t
return lastInstant;
}
+ /**
+ * Polls {@code condition} until it holds, the deltastreamer future
finishes, or the timeout expires.
+ *
+ * <p>On timeout the last error the condition threw is attached to the
failure. Without it the only
+ * output is a bare {@link TimeoutException} pointing at this method,
which says nothing about which
+ * assertion never held - the reason HUDI-6843 stayed open: every report
of it looks identical.
+ */
static void waitTillCondition(Function<Boolean, Boolean> condition, Future
dsFuture, long timeoutInSecs) throws Exception {
Review Comment:
**minor:** Awaitility 3.1.2 is already on this module's test classpath via
`hudi-tests-common` (hudi-client-common's `TestHoodieHeartbeatClient` uses it
the same way) and does the executor, last-error and interrupt handling in one
call: `await().atMost(timeoutInSecs, SECONDS).pollInterval(2,
SECONDS).ignoreExceptions().untilAsserted(() -> { if (!dsFuture.isDone())
assertTrue(condition.apply(true)); })`. `ConditionTimeoutException` carries the
last assertion message and cause. Not blocking, and keeping the current shape
after four rounds is a fair call. Would it be worth switching, since it also
retires the interrupt subtlety?
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/HoodieDeltaStreamerTestBase.java:
##########
@@ -763,22 +766,55 @@ static HoodieInstant
assertCommitMetadataForIncrSource(String expected, String t
return lastInstant;
}
+ /**
+ * Polls {@code condition} until it holds, the deltastreamer future
finishes, or the timeout expires.
+ *
+ * <p>On timeout the last error the condition threw is attached to the
failure. Without it the only
+ * output is a bare {@link TimeoutException} pointing at this method,
which says nothing about which
+ * assertion never held - the reason HUDI-6843 stayed open: every report
of it looks identical.
+ */
static void waitTillCondition(Function<Boolean, Boolean> condition, Future
dsFuture, long timeoutInSecs) throws Exception {
- Future<Boolean> res = Executors.newSingleThreadExecutor().submit(() -> {
- boolean ret = false;
- while (!ret && !dsFuture.isDone()) {
- try {
- Thread.sleep(2000);
- ret = condition.apply(true);
- log.info("Condition completed successfully");
- } catch (Throwable error) {
- log.debug("Got error waiting for condition", error);
- ret = false;
+ AtomicReference<Throwable> lastError = new AtomicReference<>();
+ ExecutorService executor = Executors.newSingleThreadExecutor();
+ try {
+ Future<Boolean> res = executor.submit(() -> {
+ boolean ret = false;
+ while (!ret && !dsFuture.isDone() &&
!Thread.currentThread().isInterrupted()) {
+ try {
+ Thread.sleep(2000);
+ ret = condition.apply(true);
+ if (ret) {
+ log.info("Condition completed successfully");
+ }
+ } catch (InterruptedException interrupted) {
+ // shutdownNow below interrupts this thread once the wait has
given up. Thread.sleep clears
+ // the interrupt flag when it throws, so catching this with
everything else would re-enter
+ // the loop and keep polling forever. Restore the flag and stop;
this is not a condition
+ // failure, so it is deliberately not recorded as one.
+ Thread.currentThread().interrupt();
+ break;
+ } catch (Throwable error) {
+ lastError.set(error);
+ ret = false;
+ }
}
+ return ret;
+ });
+ try {
+ res.get(timeoutInSecs, TimeUnit.SECONDS);
+ } catch (TimeoutException e) {
+ Throwable last = lastError.get();
+ String detail = last == null
+ ? "The condition returned false without throwing, so there is no
further detail."
Review Comment:
**minor:** `lastError == null` does not only mean the condition returned
false: it also covers an evaluation that is still running (a stuck Spark read,
or `waitFor` spinning) or one that never started, and this message then asserts
the wrong thing. The kept error can likewise be minutes stale if a later
evaluation hangs. Not blocking. Could we count completed evaluations and report
it, e.g. "no evaluation completed" vs "N evaluations completed; last error:
..."?
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/TestWaitTillCondition.java:
##########
@@ -0,0 +1,111 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.apache.hudi.utilities.deltastreamer;
+
+import org.junit.jupiter.api.Test;
+
+import java.util.concurrent.CompletableFuture;
+import java.util.concurrent.Future;
+import java.util.concurrent.atomic.AtomicInteger;
+
+import static org.junit.jupiter.api.Assertions.assertDoesNotThrow;
+import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.assertThrows;
+import static org.junit.jupiter.api.Assertions.assertTrue;
+
+/**
+ * Covers {@code HoodieDeltaStreamerTestBase.TestHelpers#waitTillCondition},
the helper every
+ * continuous-mode deltastreamer test waits on.
+ *
+ * <p>HUDI-6843 is a flaky timeout in that wait whose only output was
+ * {@code java.util.concurrent.TimeoutException} at this method, with no
indication of which assertion in
+ * the condition never held - the condition's error was logged at debug and
discarded. That is why every
+ * report of the flake looks the same and none of them is actionable.
+ */
+class TestWaitTillCondition {
+
+ /** A deltastreamer future that never finishes, as a continuous-mode job
would be. */
+ private static final Future<?> RUNNING = new CompletableFuture<>();
+
+ /**
+ * The helper polls every 2s, so the timeout has to leave room for several
evaluations. A value close to
+ * one interval would make this test itself flaky on a loaded machine - if
the worker started late and the
+ * first evaluation landed after the timeout, nothing would have been
recorded to report.
+ */
+ private static final int CONDITION_TIMEOUT_SECS = 15;
Review Comment:
**nit:** The four tests spend ~27s asleep in the shared utilities UT job
(15s here, 10s in `pollingStopsOnceTheWaitHasGivenUp`). That test already
trusts a 5s timeout to have recorded two polls, so the same value here saves
10s at the same margin. Feel free to ignore.
```suggestion
private static final int CONDITION_TIMEOUT_SECS = 5;
```
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/TestHoodieDeltaStreamer.java:
##########
@@ -1754,6 +1754,12 @@ static void deltaStreamerTestRunner(HoodieDeltaStreamer
ds, HoodieDeltaStreamer.
});
TestHelpers.waitTillCondition(condition, dsFuture, 360);
if (cfg != null && !cfg.postWriteTerminationStrategyClass.isEmpty()) {
+ // If the streamer died, waitTillCondition returns as soon as the future
completes. Surface that
+ // failure here rather than letting awaitDeltaStreamerShutdown time out
and report the misleading
+ // "Deltastreamer should have shutdown by now" two minutes later.
+ if (dsFuture.isDone()) {
Review Comment:
**minor:** This guard is not covered: only
`testUpsertsContinuousMode(testShutdownGracefully=true)` reaches the branch,
and only if the streamer dies. A ~2s case in `TestWaitTillCondition` would pin
it: a Mockito `HoodieDeltaStreamer` (non-final, mockito-core is on the
classpath) whose `sync()` throws, a cfg with a non-empty
`postWriteTerminationStrategyClass`, and
`assertThrows(ExecutionException.class, ...)`. Without the guard
`awaitDeltaStreamerShutdown` NPEs on the mock's null ingestion service, so the
test discriminates. Not blocking. Would it be worth adding?
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/HoodieDeltaStreamerTestBase.java:
##########
@@ -763,22 +766,55 @@ static HoodieInstant
assertCommitMetadataForIncrSource(String expected, String t
return lastInstant;
}
+ /**
+ * Polls {@code condition} until it holds, the deltastreamer future
finishes, or the timeout expires.
+ *
+ * <p>On timeout the last error the condition threw is attached to the
failure. Without it the only
+ * output is a bare {@link TimeoutException} pointing at this method,
which says nothing about which
+ * assertion never held - the reason HUDI-6843 stayed open: every report
of it looks identical.
+ */
static void waitTillCondition(Function<Boolean, Boolean> condition, Future
dsFuture, long timeoutInSecs) throws Exception {
- Future<Boolean> res = Executors.newSingleThreadExecutor().submit(() -> {
- boolean ret = false;
- while (!ret && !dsFuture.isDone()) {
- try {
- Thread.sleep(2000);
- ret = condition.apply(true);
- log.info("Condition completed successfully");
- } catch (Throwable error) {
- log.debug("Got error waiting for condition", error);
- ret = false;
+ AtomicReference<Throwable> lastError = new AtomicReference<>();
+ ExecutorService executor = Executors.newSingleThreadExecutor();
+ try {
+ Future<Boolean> res = executor.submit(() -> {
+ boolean ret = false;
+ while (!ret && !dsFuture.isDone() &&
!Thread.currentThread().isInterrupted()) {
+ try {
+ Thread.sleep(2000);
+ ret = condition.apply(true);
+ if (ret) {
+ log.info("Condition completed successfully");
+ }
+ } catch (InterruptedException interrupted) {
+ // shutdownNow below interrupts this thread once the wait has
given up. Thread.sleep clears
+ // the interrupt flag when it throws, so catching this with
everything else would re-enter
+ // the loop and keep polling forever. Restore the flag and stop;
this is not a condition
+ // failure, so it is deliberately not recorded as one.
+ Thread.currentThread().interrupt();
+ break;
+ } catch (Throwable error) {
+ lastError.set(error);
Review Comment:
**nit:** The old `log.debug("Got error waiting for condition", error)` is
gone, so the per-poll progression (`got 0`, then `got 2`) is invisible even at
debug; only the final error survives. Feel free to ignore.
```suggestion
log.debug("Got error waiting for condition", error);
lastError.set(error);
```
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/HoodieDeltaStreamerTestBase.java:
##########
@@ -763,22 +766,55 @@ static HoodieInstant
assertCommitMetadataForIncrSource(String expected, String t
return lastInstant;
}
+ /**
+ * Polls {@code condition} until it holds, the deltastreamer future
finishes, or the timeout expires.
+ *
+ * <p>On timeout the last error the condition threw is attached to the
failure. Without it the only
+ * output is a bare {@link TimeoutException} pointing at this method,
which says nothing about which
+ * assertion never held - the reason HUDI-6843 stayed open: every report
of it looks identical.
Review Comment:
**nit:** This `TestHelpers` region had six comment lines in ~290 before this
change; the narrative here ("the reason HUDI-6843 stayed open", and "none of
them is actionable" in the `TestWaitTillCondition` class doc) reads as
PR-description text rather than a contract. Feel free to ignore. Could we keep
the first sentence plus the interrupt comment and leave the history to the PR?
##########
hudi-utilities/src/test/java/org/apache/hudi/utilities/deltastreamer/TestWaitTillCondition.java:
##########
@@ -0,0 +1,111 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.apache.hudi.utilities.deltastreamer;
+
+import org.junit.jupiter.api.Test;
+
+import java.util.concurrent.CompletableFuture;
+import java.util.concurrent.Future;
+import java.util.concurrent.atomic.AtomicInteger;
+
+import static org.junit.jupiter.api.Assertions.assertDoesNotThrow;
+import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.assertThrows;
+import static org.junit.jupiter.api.Assertions.assertTrue;
+
+/**
+ * Covers {@code HoodieDeltaStreamerTestBase.TestHelpers#waitTillCondition},
the helper every
+ * continuous-mode deltastreamer test waits on.
+ *
+ * <p>HUDI-6843 is a flaky timeout in that wait whose only output was
+ * {@code java.util.concurrent.TimeoutException} at this method, with no
indication of which assertion in
+ * the condition never held - the condition's error was logged at debug and
discarded. That is why every
+ * report of the flake looks the same and none of them is actionable.
+ */
+class TestWaitTillCondition {
+
+ /** A deltastreamer future that never finishes, as a continuous-mode job
would be. */
+ private static final Future<?> RUNNING = new CompletableFuture<>();
+
+ /**
+ * The helper polls every 2s, so the timeout has to leave room for several
evaluations. A value close to
+ * one interval would make this test itself flaky on a loaded machine - if
the worker started late and the
+ * first evaluation landed after the timeout, nothing would have been
recorded to report.
+ */
+ private static final int CONDITION_TIMEOUT_SECS = 15;
+
+ @Test
+ void timeoutFailureNamesTheLastConditionFailure() {
+ String assertionText = "assertAtleastNDeltaCommits: expected at least 3
delta commits but got 2";
+
+ AssertionError error = assertThrows(AssertionError.class,
+ () -> HoodieDeltaStreamerTestBase.TestHelpers.waitTillCondition(
+ ignored -> {
+ throw new AssertionError(assertionText);
+ }, RUNNING, CONDITION_TIMEOUT_SECS));
+
+ assertTrue(error.getMessage().contains("was not met within " +
CONDITION_TIMEOUT_SECS + " seconds"),
+ () -> "The failure should say the condition timed out, but was: " +
error.getMessage());
+ assertTrue(error.getMessage().contains(assertionText),
+ () -> "The failure should carry the condition's own error, which is
the only clue to why the "
+ + "wait timed out, but was: " + error.getMessage());
+ }
+
+ /**
+ * {@code shutdownNow} interrupts the polling thread, but {@code
Thread.sleep} clears the interrupt flag
+ * when it throws, so a catch-all around the sleep would swallow it and keep
polling for the life of the
+ * JVM. This pins that the worker actually stops.
+ */
+ @Test
+ void pollingStopsOnceTheWaitHasGivenUp() throws Exception {
+ AtomicInteger polls = new AtomicInteger();
+
+ assertThrows(AssertionError.class,
+ () -> HoodieDeltaStreamerTestBase.TestHelpers.waitTillCondition(
+ ignored -> {
+ polls.incrementAndGet();
+ throw new AssertionError("never true");
+ }, RUNNING, 5));
+
+ int pollsWhenItGaveUp = polls.get();
+ Thread.sleep(5000);
+ assertEquals(pollsWhenItGaveUp, polls.get(),
Review Comment:
**nit:** This also passes as `0 == 0` if the worker never ran a poll. Feel
free to ignore.
```suggestion
assertTrue(pollsWhenItGaveUp > 0, "the condition should have been
evaluated at least once before the wait gave up");
assertEquals(pollsWhenItGaveUp, polls.get(),
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
