First callback call is quite fast and the rest are delayed ~50ms (non additive) and I don't know why.
public class CfTest {
final static long t0 = System.nanoTime();
public static void main(String[] args) {
CompletableFuture<Integer> cf1 = CompletableFuture.supplyAsync(()->{sleep(2000); return 100;});
CompletableFuture<Long> cf2 = CompletableFuture.supplyAsync(()->{sleep(1000); return 1L;});
CompletableFuture<Long> cfs = cf1.thenCombine(cf2, (a,b)->a+b);
cfs.thenAccept(x->debug("a1. " + x)); // Async process, sync when complete
cfs.thenAccept(x->debug("a2. " + x)); // Async process, sync when complete
cfs.thenAcceptAsync(x->debug("a3. " + x)); // Async process, async after complete too
debug("b. " + cfs.join()); // Wait and process
debug("c. " + cfs.join()); // Wait and process
}
private static void sleep(int i) {
try {
Thread.sleep(i);
} catch (InterruptedException e) {
throw new RuntimeException(e);
}
}
private static void debug(Object res) {
System.out.println(String.format("after %.3fs: %s", (System.nanoTime()-t0) / (float)TimeUnit.SECONDS.toNanos(1), res));
System.out.flush();
}
}
output:
after 2,067s: a1. 101
after 2,129s: a2. 101
after 2,129s: a3. 101
after 2,129s: b. 101
after 2,129s: c. 101
EDIT: Other cases that surprises me even more. I think CompletableFuture may not be the problem.
If I add this line:
...
cfs.thenAcceptAsync(x->debug("a3. " + x)); // Async process, async after complete too
System.out.println("Waiting..."); // <-- New Line
debug("b. " + cfs.join()); // Wait and process
debug("c. " + cfs.join()); // Wait and process
I get this output, no change:
Waiting...
after 2,066s: a1. 101
after 2,121s: a2. 101
after 2,122s: a3. 101
after 2,122s: b. 101
after 2,122s: c. 101
But if I add this line instead:
...
cfs.thenAcceptAsync(x->debug("a3. " + x)); // Async process, async after complete too
debug("Waiting..."); // <-- New Line
debug("b. " + cfs.join()); // Wait and process
debug("c. " + cfs.join()); // Wait and process
The delay is gone!!
after 0,068s: Waiting...
after 2,066s: a1. 101
after 2,067s: a2. 101
after 2,067s: b. 101
after 2,067s: a3. 101
after 2,068s: c. 101
If I add this line before join the delay is gone, so the delay must be related to class loading about String.format initialization:
...
cfs.thenAcceptAsync(x->debug("a3. " + x)); // Async process, async after complete too
String.format("test"); // <-- Delay is gone with this line too
debug("b. " + cfs.join()); // Wait and process
debug("c. " + cfs.join()); // Wait and process
output:
after 2,057s: a1. 101
after 2,068s: a2. 101
after 2,068s: b. 101
after 2,068s: a3. 101
after 2,069s: c. 101
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With