Why calling get() before exceptional completion waits for exceptionally to execute?

Question

While answering this question, I noticed a strange behaviour of CompletableFuture: if you have a CompletableFuture cf and chain a call with cf.exceptionally(), calling cf.get() appears to behave strangely:

• if you call it before exceptional completion, it waits for the execution of the exceptionally() block before returning
• otherwise, it fails immediately by throwing the expected ExecutionException

Am I missing something or is this a bug? I am using Oracle JDK 1.8.0_131 on Ubuntu 17.04.

The following code illustrates this phenomenon:

public static void main(String[] args) {
    long start = System.currentTimeMillis();
    final CompletableFuture<Object> future = CompletableFuture.supplyAsync(() -> {
        sleep(1000);
        throw new RuntimeException("First");
    }).thenApply(Function.identity());

    future.exceptionally(e -> {
        sleep(1000);
        logDuration(start, "Exceptionally");
        return null;
    });

    final CompletableFuture<Void> futureA = CompletableFuture.runAsync(() -> {
        try {
            future.get();
        } catch (Exception e) {
        } finally {
            logDuration(start, "A");
        }
    });

    final CompletableFuture<Void> futureB = CompletableFuture.runAsync(() -> {
        sleep(1100);
        try {
            future.get();
        } catch (Exception e) {
        } finally {
            logDuration(start, "B");
        }
    });

    try {
        future.join();
    } catch (Exception e) {
        logDuration(start, "Main");
    }

    futureA.join();
    futureB.join();
}

private static void sleep(final int millis) {
    try {
        Thread.sleep(millis);
    } catch (InterruptedException e) {
        Thread.currentThread().interrupt();
    }
}

private static void logDuration(long start, String who) {
    System.out.println(who + " waited for " + (System.currentTimeMillis() - start) + "ms");
}

Output:

B waited for 1347ms
Exceptionally waited for 2230ms
Main waited for 2230ms
A waited for 2230ms

As you can see, futureB which sleeps a bit before calling get() does not block at all. However, both futureA and the main thread wait for exceptionally() to complete.

Note that this behaviour does not occur if you remove the .thenApply(Function.identity()).

Caban

Seems like CompletableFuture does not wait for exceptional to complete when calling get after a sleep over the time the exception is thrown. Accroding to JavaDoc it looks like get wont necessarily have to wait: "Waits if necessary for this future to complete, and then returns its result." – Berfield

@Berfield that is not necessary here though – Caban

Why not? Here is what I think is happening. Thread A calls get and since it does not have result yet it waits untill it gets exception and waits again untill it finishes calling exceptionally function before throwing exception back to A. Thread B calls get, since at this time we should already have exception result the get will just throw it without again calling exception handler function. – Berfield

@Berfield actually, when future B calls it, the exception handler is still running. What I meant is that it is not necessary to wait for the exception handler to run. It is true that it is necessary to wait, but it waits longer than necessary. – Caban

There is another strange behavior which I've also reported in the other post. If you change the "future.exceptionally(" above to ".exceptionally" and remove the semicolon on the previous line, then the call to future.get() waits for the exceptionally to finish. It's as if when you create a future through future = CompletableFuture.supplyAsync(...).thenApplyAsync(...).thenApplyAsync(...), it is different from future = CompletableFuture.supplyAysnc(...); future = future.thenApplyAsync(...); future = future.thenApplyAysnc(...). – Riboflavin

Answer 1

Waking up a sleeping thread is a dependent action which has to be processed like any other and it has no precedence. On the other hand, a thread polling a CompletableFuture when it has been completed already will not be put to sleep, have no need to be woken up, hence, no need to compete with the other dependent actions.

With the following program

public static void main(String[] args) {
    final CompletableFuture<Object> future = CompletableFuture.supplyAsync(() -> {
        waitAndLog("Supplier", null, 1000);
        throw new RuntimeException("First");
    }).thenApply(Function.identity());
    long start = System.nanoTime();

    CompletableFuture.runAsync(() -> waitAndLog("A", future, 0));

    LockSupport.parkNanos(TimeUnit.MILLISECONDS.toNanos(10));

    future.exceptionally(e -> {
        waitAndLog("Exceptionally", null, 1000);
        return null;
    });

    CompletableFuture.runAsync(() -> waitAndLog("B", future, 0));
    CompletableFuture.runAsync(() -> waitAndLog("C", future, 1100));

    waitAndLog("Main", future, 0);
    ForkJoinPool.commonPool().awaitQuiescence(10, TimeUnit.SECONDS);
}
private static void waitAndLog(String msg, CompletableFuture<?> primary, int sleep) {
    long nanoTime = System.nanoTime();
    Object result;
    try {
        if(sleep>0) Thread.sleep(sleep);
        result = primary!=null? primary.get(): null;
    } catch (InterruptedException|ExecutionException ex) {
        result = ex;
    }
    long millis=TimeUnit.NANOSECONDS.toMillis(System.nanoTime()-nanoTime);
    System.out.println(msg+" waited for "+millis+"ms"+(result!=null? ", got "+result: ""));
}

I get,

Supplier waited for 993ms
A waited for 993ms, got java.util.concurrent.ExecutionException: java.lang.RuntimeException: First
C waited for 1108ms, got java.util.concurrent.ExecutionException: java.lang.RuntimeException: First
Exceptionally waited for 998ms
Main waited for 1983ms, got java.util.concurrent.ExecutionException: java.lang.RuntimeException: First
B waited for 1984ms, got java.util.concurrent.ExecutionException: java.lang.RuntimeException: First

on my machine, suggesting that in this specific case, the dependent actions were executed right in the order they were scheduled, A first. Note that I inserted extra waiting time before scheduling Exceptionally, which will be the next dependent action. Since B runs in a background thread, it is non-deterministic whether it manages to schedule itself before the Main thread or not. We could insert another delay before either to enforce an order.

Since C polls an already completed future, it can proceed immediately, so its net waiting time is close to the explicitly specified sleeping time.

It must be emphasized that this is only the result of a particular scenario, dependent on implementation details. There is no guaranteed execution order for dependent actions. As you might have noticed yourself, without the .thenApply(Function.identity()) step, the implementation runs a different code path resulting in a different execution order of the dependent actions.

The dependencies form a tree and the implementation has to traverse it in an efficient manner without risking a stack overflow, hence it has to flatten it in some way and small changes to the shape of the dependency tree may influence the resulting order in a non-intuitive way.

Keating

I was expecting you here for 3 days now... thank you! – Datestamp

Why when you say to sleep for 1000ms, it sleeps for 993ms? I was expecting that saying sleep(1000 ms) would make it sleep for at least 1000ms and maybe a few milli or nano second more, but not less. Does the spec in fact allow this? – Riboflavin

Also, can you please elaborate on your last sentence? It sounds like in the original program, future is the root of a tree, the thenApply identity is the only child, and exceptionally child of the previous. This looks like a linked list, and there’s only one way to traverse it. So not sure why the removal of the Function.identity() node would cause the behavior to change. – Riboflavin

Nice explanation. I guess that's something we'll have to live with :-) In fact, this made me notice that it is not specific to exceptionally(): I observe the same behaviour if it is a simple thenApply(). I suppose it would be possible to have an implementation that gives more priority to the wake-up actions, however for now it seems we have to rely more on the *Async() methods and thenCompose() with fast composing functions when intermediate stages are reused (in blocking calls). – Caban

BTW, 2 additional notes: the code given here executes 4 background tasks, so by default on a quad-core the last task will not start before the first one finishes. Concerning identity(), I had indeed mentioned it at the end of the question. – Caban

@Didier L: yes, I noticed afterwards that you have mentioned the behavioral dependency to .thenApply(Function.identity()). Regarding the 4 background tasks, the ForkJoin pool will start new compensation threads if it knows that a worker thread is waiting, which is the case if you are waiting for another CompletableFuture. So C is the only task having a wait state without F/J knowing. – Keating

@snaran: in principle, each CompletableFuture can have an arbitrary number of child nodes (dependent actions), hence, form a tree. Therefore, the algorithm must be capable of traversing a tree. Of course, having just a single chain or a flat list of siblings are special cases of this tree. Considering that notifying a waiting thread is also a dependent action, exceptionally is only a sibling of several nodes. But with the thenApply, there is also one step down from the initial node before encountering these siblings. Without it, there is only a list (or stack) of siblings. – Keating

Regarding Thread.sleep, it says: “subject to the precision and accuracy of system timers and schedulers”… – Keating

On my machine, C only starts after Supplier finishes, and ends at about the same time as B and Main. It looks like the common pool does not create any new threads. – Caban

@Didier L: oh right, I forgot that the initial Supplier as well as the function passed to exceptionally do call Thread.sleep as well, so they’re blocking a thread without F/J noticing. There are also some corner cases with small no. of cpu cores. But you may try CompletableFuture<Object> latch=new CompletableFuture<>(); for(int i=0; i<16; i++) CompletableFuture.runAsync(() -> { System.out.println("waiting in "+Thread.currentThread()); latch.join(); System.out.println("wait over"); }); Thread.sleep(2000); latch.complete(null); ForkJoinPool.commonPool().awaitQuiescence(1, TimeUnit.DAYS); – Keating

@Holger, it is true that in general the execution is a tree. But in this case it is just a single linked list. So not sure why the imposition of a middle node (identity here) makes any difference. Maybe it really is an implementation detail, or maybe it is a bug. – Riboflavin