Skip to content

Commit 9cbb654

Browse files
authored
End a timed-out run's wait at its deadline, whoever cancelled the row (#635)
Fixes #627. ## The problem A workflow past its deadline is cancelled by whichever comes first: its own timer or the database-side timeout sweep, which runs on every executor. The timer cancelled the run's future, which is what ends a local handle's `getResult()`, only when `cancelOwnedWorkflow(workflowId, ownerXid)` succeeded, that is, only while the run still owned the row. If the sweep (on any executor) settled the row first, the timer found nothing to cancel and left the future alone. `getResult()` then waited until the run's next write was refused: through a whole `dbos.sleep`, 30 s for a 1 s timeout in #627. ## The fix - **The timer always ends the wait at the deadline.** It still cancels the row only while the run owns it, but it cancels the run's future either way. That happens in a `finally`, so a cancel that fails against the database still ends the wait. - **`getResult()` reports what the row records.** When the future was cancelled, it awaits the row instead of assuming a cancellation. That gives: - cancelled, whether by this run, the sweep on any executor, or an explicit cancel; - if the workflow was resumed after the timeout, the resumed run's outcome. The handle used to report that case as a cancellation. - **A run whose body has finished is left alone.** Such a run only records or adopts its outcome, so it completes its own future promptly. Cancelling it would make `getResult()` return a copy deserialized from the row instead of the value the run holds: for a portable workflow returning a record, a `Map`. - **The timer is dropped when the run finishes first.** It used to stay queued until the deadline, holding the run's future and so its result. The run's future now cancels its timer on completion, and the timeout scheduler (`setRemoveOnCancelPolicy(true)`) removes cancelled tasks instead of keeping them until their delay runs out. As before, cancelling the future doesn't stop the run's thread, because `CompletableFuture.cancel` doesn't interrupt. The run keeps going until its next write is refused. What changes is that `getResult()` no longer waits for it. The first commit took a different approach: the sweep completed the handles of local runs whose rows it cancelled. It only helped the executor whose sweep won the row, so the second commit reverts it. ## Behaviour changes for a handle whose deadline passed - If the row has since been deleted, `getResult()` throws `DBOSNonExistentWorkflowException` instead of reporting a cancellation. - If the workflow was resumed, `getResult()` waits for the resumed run. ## Tests - `WorkflowTimeoutSweepTest`: - `aRunTheSweepCancelsFirstStillEndsAtItsDeadline`: the sweep cancels the row before the run's timer fires. - `aRowAnotherExecutorCancelledEndsTheWaitAtTheDeadline`: the row is cancelled the way another executor's sweep would. - `aHandleReportsTheOutcomeOfARunResumedAfterTheTimeout`. Each waits until the run is inside its sleep, where nothing else would end the wait. All three fail against main's `DBOSExecutor`. - `TimeoutTest.aFinishedRunLeavesNoTimerQueued`: fails without either the timer cancel or the remove-on-cancel policy. 🤖 Generated with [Claude Code](https://claude.com/claude-code)
1 parent 614fedd commit 9cbb654

5 files changed

Lines changed: 276 additions & 12 deletions

File tree

‎transact/src/main/java/dev/dbos/transact/execution/DBOSExecutor.java‎

Lines changed: 44 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -93,6 +93,7 @@
9393
import java.util.concurrent.Executors;
9494
import java.util.concurrent.Future;
9595
import java.util.concurrent.ScheduledExecutorService;
96+
import java.util.concurrent.ScheduledThreadPoolExecutor;
9697
import java.util.concurrent.ThreadPoolExecutor;
9798
import java.util.concurrent.TimeUnit;
9899
import java.util.concurrent.atomic.AtomicBoolean;
@@ -325,7 +326,11 @@ public void start(
325326
};
326327

327328
executorService = executorServiceSupplier.get();
328-
timeoutScheduler = Executors.newScheduledThreadPool(2);
329+
var scheduler = new ScheduledThreadPoolExecutor(2);
330+
// A workflow's timeout timer is cancelled when the workflow finishes; without this, the
331+
// cancelled timer, and the result it references, stays queued until the deadline.
332+
scheduler.setRemoveOnCancelPolicy(true);
333+
timeoutScheduler = scheduler;
329334

330335
systemDatabase = SystemDatabase.create(config, this.executorId, this.appName);
331336
systemDatabase.start();
@@ -1599,7 +1604,9 @@ public <T, E extends Exception> T getResult(String workflowId, Future<T> futureR
15991604
} catch (DBOSWorkflowExecutionConflictException e) {
16001605
return awaitWorkflowResult(workflowId, false);
16011606
} catch (CancellationException e) {
1602-
throw new DBOSAwaitedWorkflowCancelledException(workflowId);
1607+
// The run's deadline passed. The row has the outcome: cancelled by this run, by the
1608+
// timeout sweep or explicitly, or, if the workflow was resumed, the new run's.
1609+
return awaitWorkflowResult(workflowId, true);
16031610
} catch (ExecutionException e) {
16041611
if (e.getCause() instanceof Exception cause) {
16051612
if (cause instanceof DBOSWorkflowExecutionConflictException) {
@@ -2597,6 +2604,11 @@ private <T, E extends Exception> WorkflowHandle<T, E> executeWorkflow(
25972604
final String notRecordedWarning =
25982605
"Workflow outcome was not recorded: the workflow is no longer owned by this execution."
25992606
+ " Waiting for the recorded outcome.";
2607+
// Set as the run starts writing its outcome. From then on it completes its own future
2608+
// promptly, with the result it holds or the outcome it adopts, so the deadline timer leaves it
2609+
// to: cancelling it could make getResult read back a deserialized copy of that result. Work
2610+
// before the write, such as deleting step checkpoints, stays under the deadline.
2611+
var recordingOutcome = new AtomicBoolean(false);
26002612
Supplier<T> task =
26012613
() -> {
26022614
DBOSContextHolder.clear();
@@ -2650,6 +2662,7 @@ private <T, E extends Exception> WorkflowHandle<T, E> executeWorkflow(
26502662
deleteCompletedStepCheckpoints(workflowId);
26512663

26522664
active.release();
2665+
recordingOutcome.set(true);
26532666
if (persistWorkflowOutput(workflowId, output, initResult.serialization(), ownerXid)) {
26542667
return output;
26552668
}
@@ -2694,6 +2707,7 @@ private <T, E extends Exception> WorkflowHandle<T, E> executeWorkflow(
26942707
if (!Thread.currentThread().isInterrupted()) {
26952708
deleteCompletedStepCheckpoints(workflowId);
26962709
}
2710+
recordingOutcome.set(true);
26972711
if (persistWorkflowError(workflowId, actual, initResult.serialization(), ownerXid)) {
26982712
// active is already closed here: try-with-resources closes before catch runs,
26992713
// so the entry is released before this terminal write becomes durable.
@@ -2731,21 +2745,39 @@ private <T, E extends Exception> WorkflowHandle<T, E> executeWorkflow(
27312745

27322746
var future = CompletableFuture.supplyAsync(task, executorService);
27332747
if (timeLeft != null) {
2734-
timeoutScheduler.schedule(
2735-
() -> {
2736-
// A run that lost the workflow is left to reach the fence and report the owner's
2737-
// outcome; cancelling its future would report a cancellation that never happened.
2738-
if (!future.isDone() && systemDatabase.cancelOwnedWorkflow(workflowId, ownerXid)) {
2739-
future.cancel(true);
2740-
}
2741-
},
2742-
timeLeft.toMillis(),
2743-
TimeUnit.MILLISECONDS);
2748+
var timer =
2749+
timeoutScheduler.schedule(
2750+
() -> {
2751+
// The deadline has passed. Unless the run is already writing its outcome, the
2752+
// handle stops waiting on it, even if the cancel fails. The run cancels the row
2753+
// only while it still owns it; if it doesn't, something else settled or took over
2754+
// the row (the timeout sweep on any executor, an explicit cancel, a resume), and
2755+
// getResult reports what the row records.
2756+
if (future.isDone() || recordingOutcome.get()) {
2757+
return;
2758+
}
2759+
try {
2760+
systemDatabase.cancelOwnedWorkflow(workflowId, ownerXid);
2761+
} finally {
2762+
// Checked again: the run may have started writing during the cancel.
2763+
if (!recordingOutcome.get()) {
2764+
future.cancel(true);
2765+
}
2766+
}
2767+
},
2768+
timeLeft.toMillis(),
2769+
TimeUnit.MILLISECONDS);
2770+
// A run that ends before its deadline needs no timer.
2771+
future.whenComplete((result, error) -> timer.cancel(false));
27442772
}
27452773

27462774
return new WorkflowHandleFuture<>(this, workflowId, future);
27472775
}
27482776

2777+
ScheduledExecutorService timeoutScheduler() {
2778+
return timeoutScheduler;
2779+
}
2780+
27492781
// Persist an queued workflow to the database without execution
27502782
// used by DBOSExecutor and DBOSClient
27512783
public static void enqueueWorkflow(

‎transact/src/test/java/dev/dbos/transact/execution/DBOSExecutorTestAccess.java‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,8 @@
66
import dev.dbos.transact.database.SystemDatabase;
77
import dev.dbos.transact.workflow.WorkflowHandle;
88

9+
import java.util.concurrent.ScheduledThreadPoolExecutor;
10+
911
/**
1012
* Note that this class is in the `dev.dbos.transact.execution` package and allows access to
1113
* package-scoped executor methods as a result.
@@ -23,6 +25,11 @@ public static SchedulerService getSchedulerService(DBOSExecutor exec) {
2325
return exec.getSchedulerService();
2426
}
2527

28+
/** Tasks queued on the executor's timeout scheduler: workflow timers and periodic upkeep. */
29+
public static int queuedTimeoutTasks(DBOSExecutor exec) {
30+
return ((ScheduledThreadPoolExecutor) exec.timeoutScheduler()).getQueue().size();
31+
}
32+
2633
public static ConductorOptions getConductorOptions(DBOSExecutor exec) {
2734
return exec.conductorOptions();
2835
}

‎transact/src/test/java/dev/dbos/transact/txstep/CompletedStepCheckpointsTest.java‎

Lines changed: 51 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22

33
import static org.junit.jupiter.api.Assertions.assertEquals;
44
import static org.junit.jupiter.api.Assertions.assertThrows;
5+
import static org.junit.jupiter.api.Assertions.assertTimeoutPreemptively;
56
import static org.junit.jupiter.api.Assertions.assertTrue;
67

78
import dev.dbos.transact.DBOS;
@@ -20,6 +21,7 @@
2021

2122
import java.sql.Connection;
2223
import java.sql.SQLException;
24+
import java.time.Duration;
2325
import java.time.Instant;
2426
import java.util.Collection;
2527
import java.util.concurrent.CompletableFuture;
@@ -49,6 +51,8 @@ interface CompletionService {
4951
String stepResultNotRecorded() throws SQLException;
5052

5153
String interruptedThenFails() throws SQLException;
54+
55+
String cleanupOutlastsTheDeadline() throws SQLException;
5256
}
5357

5458
class CompletionServiceImpl implements CompletionService {
@@ -58,6 +62,7 @@ class CompletionServiceImpl implements CompletionService {
5862
final CountDownLatch gate = new CountDownLatch(1);
5963
StepCheckpointStore brokenStore;
6064
StepCheckpointStore recordingStore;
65+
StepCheckpointStore blockingStore;
6166
final AtomicInteger unrecordedRuns = new AtomicInteger();
6267

6368
CompletionServiceImpl(DBOS dbos, JdbcStepFactory factory) {
@@ -118,6 +123,14 @@ public String interruptedThenFails() throws SQLException {
118123
throw new IllegalStateException("interrupted");
119124
}
120125

126+
@Override
127+
@Workflow
128+
public String cleanupOutlastsTheDeadline() throws SQLException {
129+
dbos.integration().useStepCheckpointStore(blockingStore);
130+
factory.txStep((Connection conn) -> {}, "one");
131+
return "done";
132+
}
133+
121134
@Override
122135
@Workflow
123136
public String alsoUsesABrokenStore() throws SQLException {
@@ -257,6 +270,44 @@ public void anExecutionThatLostTheWorkflowDeletesNothing() throws Exception {
257270
assertEquals(1, checkpoints(workflowId));
258271
}
259272

273+
/**
274+
* Deleting the checkpoints comes before the outcome is written, so the deadline still applies to
275+
* it: a cleanup that outlasts the deadline doesn't hold the handle past it.
276+
*/
277+
@Test
278+
public void aCleanupThatOutlastsTheDeadlineStillEndsTheWaitAtIt() throws Exception {
279+
launch(false);
280+
var cleanupGate = new CountDownLatch(1);
281+
impl.blockingStore =
282+
new StepCheckpointStore() {
283+
@Override
284+
public void deleteCheckpoints(String workflowId, int fromStepId) {}
285+
286+
@Override
287+
public void deleteCheckpoints(Collection<String> workflowIds) {}
288+
289+
@Override
290+
public void deleteCompletedCheckpoints(String workflowId) {
291+
try {
292+
cleanupGate.await(60, TimeUnit.SECONDS);
293+
} catch (InterruptedException e) {
294+
Thread.currentThread().interrupt();
295+
}
296+
}
297+
};
298+
try {
299+
var handle =
300+
dbos.startWorkflow(
301+
proxy::cleanupOutlastsTheDeadline,
302+
new StartWorkflowOptions("wf-slow-cleanup").withTimeout(Duration.ofSeconds(2)));
303+
assertThrows(
304+
DBOSAwaitedWorkflowCancelledException.class,
305+
() -> assertTimeoutPreemptively(Duration.ofSeconds(15), () -> handle.getResult()));
306+
} finally {
307+
cleanupGate.countDown();
308+
}
309+
}
310+
260311
@Test
261312
public void aFailedDeleteDoesNotChangeTheOutcomeOrSkipTheOtherFactories() throws Exception {
262313
launch(false);

‎transact/src/test/java/dev/dbos/transact/workflow/TimeoutTest.java‎

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -237,6 +237,31 @@ public void queuedTimedOut() {
237237
assertEquals(WorkflowState.CANCELLED, s.status());
238238
}
239239

240+
/** A run that finishes well before its deadline doesn't leave its timer queued until then. */
241+
@Test
242+
public void aFinishedRunLeavesNoTimerQueued() throws Exception {
243+
SimpleServiceImpl impl = new SimpleServiceImpl(dbos);
244+
SimpleService simpleService = dbos.registerProxy(SimpleService.class, impl);
245+
impl.setSelf(simpleService);
246+
dbos.launch();
247+
var executor = DBOSTestAccess.getDbosExecutor(dbos);
248+
int before = DBOSExecutorTestAccess.queuedTimeoutTasks(executor);
249+
250+
for (int i = 0; i < 5; i++) {
251+
try (var id = new WorkflowOptions("timer-" + i).withTimeout(1, TimeUnit.HOURS).setContext()) {
252+
assertEquals("Processed: ab", simpleService.workWithString("ab"));
253+
}
254+
}
255+
256+
// The timer is cancelled as the run's future completes, which may be just after getResult
257+
// returns.
258+
long giveUp = System.nanoTime() + Duration.ofSeconds(5).toNanos();
259+
while (DBOSExecutorTestAccess.queuedTimeoutTasks(executor) != before) {
260+
assertTrue(System.nanoTime() < giveUp, "the finished runs' timers are still queued");
261+
Thread.sleep(20);
262+
}
263+
}
264+
240265
@Test
241266
public void sync() throws Exception {
242267

0 commit comments

Comments
 (0)