Java CompletableFuture Example

1. Introduction

In this post, we feature a comprehensive article on Java CompletableFuture. Asynchronous operations are common in Java applications. There are lots of challenges when dealing with asynchronous operations, such as memory leaking, race condition, callback hell, disjointed error handling, etc. Java has provided the CompletableFuture<T> class to ease these challenges since version 8. It has about 50 methods to compose, combine, and execute asynchronous computation steps and to handle errors.

Java has provided the Future and ExecutorService interfaces since version 5 to handle the asynchronous operations. The Future interface is a placeholder for a result from an asynchronous operation which can be a Runnable or Callable instance. The ExecutorService interface submits an asynchronous operation and returns a Future object. The caller can use its get method to wait for the operation or cancel method to try to cancel the operation. Future has the following methods:

• isDone() – to check if the computation is completed.
• isCancelled() – to check if the task was cancelled before it is completed normally.
• get() – to block for its completion and to retrieve the result of the computation.
• get​(long timeout, TimeUnit unit) – to block if necessary for at most the given time for this future to complete, and then returns its result, if available.
• cancel() – to cancel execution of this task if possible.

Java 8 added a new interface – java.util.concurrent.CompletionStage – which defines a stage of a possible asynchronous computation. All methods return an instance of CompletionStage itself. Multiple Completionstages can be chained together to complete a group of tasks.

Java 8 introduced a new java.util.concurrent.CompletableFuture class which implements both Future and CompletionStage interfaces. It also provides suits of static factory methods as a starting point for executing task. Here are the methods used in this example:

• supplyAsync(Supplier supplier) – create a CompletableFuture instance out of Supplier functional type.
• runAsync(Runnable action) – create a CompletableFuture instance out of Runnable functional type.
• completeExceptionally(Throwable ex) – return true if this invocation caused this CompletableFuture to transition to a completed state, else false.
• thenRun(Runnable action) – execute the action when it completes normally.
• thenApply(Function f) – return a new CompletionStage.
• thenAccept(Consumer action) – return a new CompletionStage.
• thenCombine(Future fu, Function foo) – to combine a Future and a Function with two arguments to process both results.
• thenCompose(Function f) – to chain two Futures sequentially.

In this example, I will demonstrate how to use these commonly used methods in the CompletableFuture class with Junit classes. I will also create classes to process multiple orders concurrently via both Future and CompletableFuture.

2. Technologies used

The example code in this article was built and run using:

• Java 11
• Maven 3.6
• Logback 1.2.3
• Junit 4.12
• Eclipse Oxygen

3. Maven Project

I will create a simple Maven project which includes a Junit and logback dependencies. I will log the messages to show the thread’s information and show the total execution time as well as the memory used for each method.

pom.xml

<project xmlns="http://maven.apache.org/POM/4.0.0"
	xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
	xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
	<modelVersion>4.0.0</modelVersion>
	<groupId>org.jcg.zheng.demo</groupId>
	<artifactId>completeablefuture-demo</artifactId>
	<version>0.0.1-SNAPSHOT</version>
	<build>
		<sourceDirectory>src</sourceDirectory>
		<plugins>
			<plugin>
				<artifactId>maven-compiler-plugin</artifactId>
				<version>3.8.0</version>
				<configuration>
					<source>11</source>
					<target>11</target>
				</configuration>
			</plugin>
		</plugins>
	</build>

	<dependencies>
		<dependency>
			<groupId>ch.qos.logback</groupId>
			<artifactId>logback-access</artifactId>
			<version>1.2.3</version>
		</dependency>

		<dependency>
			<groupId>ch.qos.logback</groupId>
			<artifactId>logback-classic</artifactId>
			<version>1.2.3</version>
		</dependency>
		<dependency>
			<groupId>ch.qos.logback</groupId>
			<artifactId>logback-core</artifactId>
			<version>1.2.3</version>
		</dependency>
		<dependency>
			<groupId>junit</groupId>
			<artifactId>junit</artifactId>
			<version>4.12</version>
		</dependency>
	</dependencies>
</project>

3.1 TestBase

In this step, I will create a TestBase class which will be the base class for all the Junit test classes. It has setup and clear methods to log the “started” and “completed” messages and well as to calculate the total memory used.

TestBase.java

package org.jcg.zheng.demo.async;

import java.util.concurrent.TimeUnit;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.junit.After;
import org.junit.Before;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class TestBase {

    protected final Logger logger = LoggerFactory.getLogger(this.getClass());

    long allocatedMemoryBefore;
    long allocatedMemeoryAfter;
    protected long sleepInSeconds = 7;


    public TestBase() {
        super();
    }

    @Before
    public void setup() {
        allocatedMemoryBefore = getAllocatedMemory();
        logger.info(DataUtils.THREAD_STARTS);
    }

    long getAllocatedMemory() {
        long allocatedMemory = Runtime.getRuntime().totalMemory()
                - Runtime.getRuntime().freeMemory();
        return allocatedMemory;
    }

    @After
    public void clear() {
        allocatedMemeoryAfter = getAllocatedMemory();
        long memoryUsed = (allocatedMemeoryAfter - allocatedMemoryBefore) / 1000;
        logger.info(DataUtils.THREAD_COMPLETED + "Total memory used " + memoryUsed + "KB."
                + " Waiting for "
                + sleepInSeconds + " seconds");

        try {
            TimeUnit.SECONDS.sleep(sleepInSeconds);
        } catch (InterruptedException e) {
        }
    }

    protected void printNum(Integer d) {
        logger.info("printNum " + d.intValue());
    }

}

3.2 DataUtils

In this step, I will create a DataUtil class which contains the constants and two methods which are used for comparing the asynchronous operation between Future and CompletableFuture.

• sendEmail(Order o) – sleeps five seconds for the proceed order and sleeps for two seconds for the error order.
• processOrder(Order o) – sleeps five seconds and simulates some error orders for the testing purpose.

DataUtils.java

package org.jcg.zheng.demo.async.data;

import java.util.concurrent.TimeUnit;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class DataUtils {
    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    public static final String MAIN_THREAD_RESUMES = "Main thread resumes after the async task is completed. ";

    public static final String THREAD_STARTS = "started. ";
    public static final String THREAD_COMPLETED = "completed. ";
    public static final String THREAD_ABORTED = "Aborted!";

    public Order sendEmail(Order order) {
        logger.info("sendEmail " + DataUtils.THREAD_STARTS);
        try {
            if (OrderStatus.PROCESSED.equals(order.getStatus())) {
                order.setDetail("sent an email-processed.");
                TimeUnit.SECONDS.sleep(5);
            } else {
                order.setDetail("send an email-error.");
                TimeUnit.SECONDS.sleep(2);
            }
            logger.info("sendEmail " + DataUtils.THREAD_COMPLETED);
        } catch (InterruptedException e) {
            logger.info("sendEmail " + DataUtils.THREAD_ABORTED);
        }
        return order;
    }

    public Order processOrder(Order order) {
        logger.info("processOrder " + DataUtils.THREAD_STARTS);
        try {
            TimeUnit.SECONDS.sleep(5);
            if (order.getOrderId().intValue() % 5 == 0) {
                order.setDetail("processOrder failed.");
                order.setStatus(OrderStatus.ERROR);
            } else {
                order.setDetail("processOrder succeed.");
                order.setStatus(OrderStatus.PROCESSED);
            }
            logger.info("processOrder " + DataUtils.THREAD_COMPLETED);
        } catch (InterruptedException e) {
            logger.info("processOrder " + DataUtils.THREAD_ABORTED);
        }
        return order;
    }
}

3.3 OrderStatus

In this step, I will create an OrderStatus enum to track the status.

OrderStatus.java

package org.jcg.zheng.demo.async.data;

public enum OrderStatus {
    NEW, PROCESSED, ERROR, NOTIFIED;
}

3.4 Order

In this step, I will create an Order class which includes three data members: orderId, status, and detail. It has the process and emailNotification methods which invokes the processOrder and sendEmail methods from the DataUtils class.

Order.java

package org.jcg.zheng.demo.async.data;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Order {
    final Logger logger = LoggerFactory.getLogger(this.getClass());

    private Integer orderId;
    private OrderStatus status;
    private String detail;

    public Integer getOrderId() {
        return orderId;
    }

    public void setOrderId(Integer orderId) {
        this.orderId = orderId;
    }

    public OrderStatus getStatus() {
        return status;
    }

    public void setStatus(OrderStatus status) {
        this.status = status;
    }

    public String getDetail() {
        return detail;
    }

    public void setDetail(String detail) {
        this.detail = detail;
    }

    public Order emailNotification() {
        this.setStatus(OrderStatus.NOTIFIED);
        (new DataUtils()).sendEmail(this);
        logger.info("emailNotification for " + this.orderId);
        return this;
    }

    public Order process() {
        logger.info("process for " + this.orderId);
        (new DataUtils()).processOrder(this);
        return this;
    }

    @Override
    public String toString() {
        return "Order [orderId=" + orderId + ", status=" + status + ", detail=" + detail + "]";
    }

}

4. Asynchronous Tasks

I will create several classes to represent the asynchronous tasks. These classes will be used in both Junit and main classes. I will log the “started”, “completed”, and “aborted” messages for each operation.

4.1 RunnableTask

In this step, I will create a RunnableTask class which implements the Runnable interface. It simulates a “fire and forget “operation which completes in five seconds.

RunnableTask.java

package org.jcg.zheng.demo.async.tasks;

import java.util.concurrent.TimeUnit;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class RunnableTask implements Runnable {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    @Override
    public void run() {
        logger.info(DataUtils.THREAD_STARTS);
        try {
            TimeUnit.SECONDS.sleep(5);
            logger.info(DataUtils.THREAD_COMPLETED);
        } catch (InterruptedException e) {
            logger.info(DataUtils.THREAD_ABORTED);
        }
    }

}

4.2 CallableTask

In this step, I will create a CallableTask class which implements the Callable<String> interface. It simulates an operation which returns a String value in five seconds .

CallableTask.java

package org.jcg.zheng.demo.async.tasks;

import java.util.UUID;
import java.util.concurrent.Callable;
import java.util.concurrent.TimeUnit;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class CallableTask implements Callable {
    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    @Override
    public String call() throws Exception {
        logger.info(DataUtils.THREAD_STARTS);
        try {
            TimeUnit.SECONDS.sleep(5);
            logger.info(DataUtils.THREAD_COMPLETED);
            return UUID.randomUUID().toString();
        } catch (InterruptedException e) {
            logger.info(DataUtils.THREAD_ABORTED);
            return "ERROR";
        }
    }

}

4.3 ProcessOrderTask

In this step, I will create a ProcessOrderTask class which implements the Callable<Order> interface. It creates an Order object based on the orderId argument; invokes the DataUtils.processOrder method; and returns an Order object.

ProcessOrderTask.java

package org.jcg.zheng.demo.async.tasks;

import java.util.concurrent.Callable;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.jcg.zheng.demo.async.data.Order;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class ProcessOrderTask implements Callable<Order> {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    private Integer orderId;

    public ProcessOrderTask(Integer orderId) {
        super();
        this.orderId = orderId;
    }

    @Override
    public Order call() throws Exception {
        logger.info(DataUtils.THREAD_STARTS);
        Order dummyOrder = new Order();
        dummyOrder.setOrderId(orderId);
        (new DataUtils()).processOrder(dummyOrder);
        return dummyOrder;
    }

}

4.4 NotifyUserTask

In this step, I will create a NotifyUserTask class which implements the Callable<Order> interface. It invokes the DataUtils.sendEmail method and returns the updated Order object.

NotifyUserTask.java

package org.jcg.zheng.demo.async.tasks;

import java.util.concurrent.Callable;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.jcg.zheng.demo.async.data.Order;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class NotifyUserTask implements Callable<Order> {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    private Order order;

    public NotifyUserTask(Order order) {
        super();
        this.order = order;
    }

    @Override
    public Order call() throws Exception {
        logger.info(DataUtils.THREAD_STARTS);
        (new DataUtils()).sendEmail(order);
        logger.info(DataUtils.THREAD_COMPLETED);
        return order;
    }

}

4.5 SupplierTask

In this step, I will create a SupplierTask class which implements the Supplier<Integer> interface. It simulates an operation which returns an integer in five seconds.

SupplierTask.java

package org.jcg.zheng.demo.async.tasks;

import java.util.Random;
import java.util.concurrent.TimeUnit;
import java.util.function.Supplier;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class SupplierTask implements Supplier<Integer> {
    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    @Override
    public Integer get() {
        logger.info(DataUtils.THREAD_STARTS);
        try {
            TimeUnit.SECONDS.sleep(5);
            Random randon = new Random();
            logger.info(DataUtils.THREAD_COMPLETED);
            return randon.ints(1, 1000).findFirst().getAsInt();
        } catch (InterruptedException e) {
            logger.info(DataUtils.THREAD_ABORTED);
            return -1;
        }

    }
}

4.6 SupplierOrderTask

In this step, I will create a SupplierOrderTask class which implements the Callable<Order> interface. It simulates an operation which returns an Order object in five seconds .

SupplierOrderTask.java

package org.jcg.zheng.demo.async.tasks;

import java.util.function.Supplier;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.jcg.zheng.demo.async.data.Order;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class SupplierOrderTask implements Supplier<Order> {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    private Integer orderId;

    public SupplierOrderTask(Integer orderId) {
        super();
        this.orderId = orderId;
    }

    @Override
    public Order get() {
        logger.info(DataUtils.THREAD_STARTS + " for " + orderId);
        Order order = new Order();
        order.setOrderId(orderId);
        return (new DataUtils()).processOrder(order);
    }
}

5. Future

Java 5 added java.util.concurrent package which includes Runnable, Callable, Future, ExecutorService, etc interfaces to handle the asynchronous operations.

5.1 FutureTest

The main advantage of using the Future object is that the main thread can do other operations while other thread is working on the asynchronous task.

In this step, I will create a FutureTest to demonstrate that CallableTask blocks the main thread with the get method. I will also demonstrate how to cancel the submitted asynchronous task. Please note that the cancel operation is not guaranteed to cancel the operation.

FutureTest.java

package org.jcg.zheng.demo.async;

import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertTrue;

import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.Callable;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.TimeoutException;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.jcg.zheng.demo.async.tasks.CallableTask;
import org.jcg.zheng.demo.async.tasks.RunnableTask;
import org.junit.Test;

public class FutureTest extends TestBase {

    private ExecutorService service = Executors.newFixedThreadPool(10);
    private Runnable runableTask = new RunnableTask();
    private Callable<String> callableTask = new CallableTask();

    @Test
    public void get_block_runnable() throws InterruptedException, ExecutionException {
        Future future = service.submit(runableTask);
        assertFalse(future.isDone());

        future.get();

        logger.info(DataUtils.MAIN_THREAD_RESUMES);
        assertTrue(future.isDone());
    }

    @Test
    public void concurrent_with_runnable() throws InterruptedException {
        Future future = service.submit(runableTask);
        assertFalse(future.isDone());
    }

    @Test
    public void concurrent_with_runnable_no_blocking_with_more_threads()
            throws InterruptedException {
        List<Future> futures = new ArrayList<>();
        for (int i = 0; i < 5; i++) {
            futures.add(service.submit(runableTask));
        }

        futures.forEach(f -> assertFalse(f.isDone()));
    }

    @Test
    public void get_block_callable() throws InterruptedException, ExecutionException {
        Future<String> future = service.submit(callableTask);

        String name = future.get();

        logger.info(DataUtils.MAIN_THREAD_RESUMES + " with results from async task =" + name);
        assertTrue(future.isDone());
    }

    @Test(expected = java.util.concurrent.TimeoutException.class)
    public void get_with_timeout_block_callable_exceed_timeout()
            throws InterruptedException, ExecutionException, TimeoutException {
        Future<String> future = service.submit(callableTask);

        String name = future.get(3, TimeUnit.SECONDS);
    }

    @Test
    public void get_with_timeout_block_callable_within_timeout_limit()
            throws InterruptedException, ExecutionException, TimeoutException {
        Future<String> future = service.submit(callableTask);

        String name = future.get(7, TimeUnit.SECONDS);
        assertTrue(future.isDone());
        logger.info(DataUtils.MAIN_THREAD_RESUMES + " with results from async task =" + name);
    }

    @Test
    public void it_cancelled_before_async_thread_starts() {
        Future future = service.submit(runableTask);
        assertFalse(future.isDone());

        boolean cancelStatus = future.cancel(true);

        assertTrue(future.isCancelled());
        assertTrue(cancelStatus);
    }

    @Test
    public void it_aborted_after_async_starts_but_before_finish() {
        Future future = service.submit(runableTask);
        assertFalse(future.isDone());

        try {
            TimeUnit.SECONDS.sleep(2);
            boolean cancelStatus = future.cancel(true);

            assertTrue(future.isCancelled());
            assertTrue(cancelStatus);

        } catch (InterruptedException e) {
        }

    }

    @Test
    public void it_failed_cancel_after_async_thread_finish() {
        Future future = service.submit(runableTask);
        assertFalse(future.isDone());

        try {
            TimeUnit.SECONDS.sleep(6);
            boolean cancelStatus = future.cancel(true);

            assertFalse(future.isCancelled());
            assertFalse(cancelStatus);
        } catch (InterruptedException e) {
        }

    }

    @Test
    public void cancel_callable() {
        Future<String> future = service.submit(callableTask);
        assertFalse(future.isDone());

        boolean cancelStatus = future.cancel(true);

        assertTrue(future.isCancelled());
        assertTrue(cancelStatus);
    }

}

5.2 Demo FutureTest

In this step, I will execute the Junit tests and capture the output here.

Note: We can tell if both main and working threads run concurrently based on the thread name and the execution time in the output messages.

FutureTest output

C:\MaryZheng\Workspaces\completeablefuture-demo>mvn clean test -Dtest=FutureTest
[INFO] Scanning for projects...
[INFO]
[INFO] -------------< org.jcg.zheng.demo:completeablefuture-demo >-------------
[INFO] Building completeablefuture-demo 0.0.1-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ completeablefuture-demo ---
[INFO] Deleting C:\MaryZheng\Workspaces\completeablefuture-demo\target
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] Copying 1 resource
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:compile (default-compile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 19 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\classes
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] skip non existing resourceDirectory C:\MaryZheng\Workspaces\completeablefuture-demo\src\test\resources
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:testCompile (default-testCompile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 7 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\test-classes
[INFO]
[INFO] --- maven-surefire-plugin:2.12.4:test (default-test) @ completeablefuture-demo ---
[INFO] Surefire report directory: C:\MaryZheng\Workspaces\completeablefuture-demo\target\surefire-reports

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running org.jcg.zheng.demo.async.FutureTest
2019-05-22 21:32:52,379 426  [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:32:52,386 433  [pool-2-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:32:52,407 454  [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used 300KB. Waiting for 7 seconds
2019-05-22 21:32:57,393 5440 [pool-2-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - completed.
2019-05-22 21:32:59,412 7459 [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:32:59,414 7461 [pool-3-thread-1] INFO  o.j.z.demo.async.tasks.CallableTask - started.
2019-05-22 21:33:04,415 12462 [pool-3-thread-1] INFO  o.j.z.demo.async.tasks.CallableTask - completed.
2019-05-22 21:33:04,790 12837 [main] INFO  org.jcg.zheng.demo.async.FutureTest - Main thread resumes after the async task is completed.  with results from async task =e8bb4e24-6fe9-41db-9f00-6f88481fc1ad
2019-05-22 21:33:04,790 12837 [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used -9931KB. Waiting for 7 seconds
2019-05-22 21:33:11,793 19840 [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:33:11,794 19841 [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:33:18,795 26842 [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:33:18,796 26843 [pool-5-thread-1] INFO  o.j.z.demo.async.tasks.CallableTask - started.
2019-05-22 21:33:21,797 29844 [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used 526KB. Waiting for 7 seconds
2019-05-22 21:33:23,798 31845 [pool-5-thread-1] INFO  o.j.z.demo.async.tasks.CallableTask - completed.
2019-05-22 21:33:28,797 36844 [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:33:28,798 36845 [pool-6-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:33:33,799 41846 [pool-6-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - completed.
2019-05-22 21:33:34,798 42845 [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used 1050KB. Waiting for 7 seconds
2019-05-22 21:33:41,800 49847 [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:33:41,801 49848 [pool-7-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:33:46,803 54850 [pool-7-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - completed.
2019-05-22 21:33:46,803 54850 [main] INFO  org.jcg.zheng.demo.async.FutureTest - Main thread resumes after the async task is completed.
2019-05-22 21:33:46,803 54850 [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used 1046KB. Waiting for 7 seconds
2019-05-22 21:33:53,803 61850 [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:33:53,804 61851 [pool-8-thread-1] INFO  o.j.z.demo.async.tasks.CallableTask - started.
2019-05-22 21:33:58,805 66852 [pool-8-thread-1] INFO  o.j.z.demo.async.tasks.CallableTask - completed.
2019-05-22 21:33:58,806 66853 [main] INFO  org.jcg.zheng.demo.async.FutureTest - Main thread resumes after the async task is completed.  with results from async task =2d7e941c-efd8-4129-9652-c80c2d3091f4
2019-05-22 21:33:58,808 66855 [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used 524KB. Waiting for 7 seconds
2019-05-22 21:34:05,809 73856 [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:34:05,810 73857 [pool-9-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:34:07,810 75857 [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used 526KB. Waiting for 7 seconds
2019-05-22 21:34:07,810 75857 [pool-9-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - Aborted!
2019-05-22 21:34:14,811 82858 [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:34:14,812 82859 [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:34:21,813 89860 [main] INFO  org.jcg.zheng.demo.async.FutureTest - started.
2019-05-22 21:34:21,815 89862 [pool-11-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:34:21,816 89863 [pool-11-thread-2] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:34:21,820 89867 [main] INFO  org.jcg.zheng.demo.async.FutureTest - completed. Total memory used 1048KB. Waiting for 7 seconds
2019-05-22 21:34:21,821 89868 [pool-11-thread-5] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:34:21,821 89868 [pool-11-thread-3] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:34:21,822 89869 [pool-11-thread-4] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:34:26,816 94863 [pool-11-thread-1] INFO  o.j.z.demo.async.tasks.RunnableTask - completed.
2019-05-22 21:34:26,819 94866 [pool-11-thread-2] INFO  o.j.z.demo.async.tasks.RunnableTask - completed.
2019-05-22 21:34:26,822 94869 [pool-11-thread-5] INFO  o.j.z.demo.async.tasks.RunnableTask - completed.
2019-05-22 21:34:26,822 94869 [pool-11-thread-3] INFO  o.j.z.demo.async.tasks.RunnableTask - completed.
2019-05-22 21:34:26,823 94870 [pool-11-thread-4] INFO  o.j.z.demo.async.tasks.RunnableTask - completed.
Tests run: 10, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 97.01 sec

Results :

Tests run: 10, Failures: 0, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  01:48 min
[INFO] Finished at: 2019-05-22T21:34:28-05:00
[INFO] ------------------------------------------------------------------------

C:\MaryZheng\Workspaces\completeablefuture-demo>

6. CompletableFuture

Java 8 enhanced the java.util.concurrent package with the CompletableFuture class which implements both Future and CompletionStage interfaces. In this step, I will demonstrate its commonly used methods.

6.1 CompletableFutureTest

I will create a CompletableFutureTest to demonstrate the methods.

CompletableFutureTest.java

package org.jcg.zheng.demo.async;

import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertTrue;

import java.util.concurrent.Callable;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.Executors;
import java.util.concurrent.ForkJoinPool;

import org.jcg.zheng.demo.async.tasks.CallableTask;
import org.jcg.zheng.demo.async.tasks.ChainOperations_PrimitiveType;
import org.jcg.zheng.demo.async.tasks.RunnableTask;
import org.jcg.zheng.demo.async.tasks.SupplierTask;
import org.junit.Test;

public class CompletableFutureTest extends TestBase {
    private Runnable runableTask = new RunnableTask();
    private Callable<String> callableTask = new CallableTask();
    private SupplierTask supplierTask = new SupplierTask();

    @Test
    public void complete() throws InterruptedException, ExecutionException {
        CompletableFuture<String> future = new CompletableFuture<>();
        Executors.newCachedThreadPool().submit(callableTask);
        future.complete("Hello");
        assertEquals("Hello", future.get());

    }

    @Test
    public void get_block_Main_thread() throws InterruptedException, ExecutionException {
        CompletableFuture<Integer> future = CompletableFuture.supplyAsync(supplierTask);
        Integer tt = future.get();

        assertTrue(tt.intValue() > 0);
        assertTrue(future.isDone());
        future.thenAccept(d -> printNum(d)); // print from main thread

    }

    @Test
    public void runAsync_for_runable_block_on_get()
            throws InterruptedException, ExecutionException {
        // this is same as Future
        CompletableFuture<Void> future = CompletableFuture.runAsync(runableTask);
        future.get();
        assertTrue(future.isDone());
    }


    @Test
    public void non_blocking_thread_execution() throws InterruptedException {
        CompletableFuture<Integer> future = CompletableFuture.supplyAsync(supplierTask);
        future.thenAccept(d -> printNum(d));// print it from ForkJoinPool.commonPool-worker-#
        assertFalse(future.isDone());
    }

    @Test
    public void non_blocking_thread_execution_chain() throws InterruptedException {
        // print it from ForkJoinPool.commonPool-worker-#
        CompletableFuture.supplyAsync(supplierTask).thenAccept(d -> printNum(d));

    }

    @Test
    public void supplyAsync_thenAccept_Separate() throws InterruptedException {
        CompletableFuture<Integer> future = CompletableFuture.supplyAsync(supplierTask);
        future.thenAccept(d -> printNum(d));// print it from ForkJoinPool.commonPool-worker-#
        assertFalse(future.isDone());
    }

    @Test
    public void supplyAsync_thenAccept_chain() throws InterruptedException {
        // print it from ForkJoinPool.commonPool-worker-#
        CompletableFuture.supplyAsync(supplierTask).thenAccept(d -> printNum(d));

    }

    @Test
    public void chain_theApply_with_lambda() {
        CompletableFuture<String> future = CompletableFuture.completedFuture("Done")
                .thenApply(s -> {
                    return s.toUpperCase();
                });

        assertEquals("DONE", future.getNow(null));
        assertTrue(future.isDone());
    }

    @Test
    public void change_threadpool_to_user_worker_pool() {
        // ForkJoinPool-1-worker-19
        ForkJoinPool fjp = new ForkJoinPool(10);
        CompletableFuture<Integer> future = CompletableFuture.supplyAsync(supplierTask, fjp);
        future.thenAccept(d -> printNum(d));
        assertFalse(future.isDone());

    }

    @Test
    public void chain_thenAccept_with_thenRun() {
        CompletableFuture<Integer> future = CompletableFuture.supplyAsync(supplierTask);

        future.thenAccept(d -> printNum(d)).thenRun(() -> logger.info("Do step 1"))
                .thenRun(() -> logger.info("Do step 2"));
        assertFalse(future.isDone());
    }

    @Test
    public void chain_thenApply_thenAccept() {
        CompletableFuture<Integer> future = CompletableFuture.supplyAsync(supplierTask);
        future.thenApply(old -> old * 2).thenApply(old -> old + 2).thenAccept(d -> printNum(d));
        assertFalse(future.isDone());
    }

    @Test
    public void thenCompose() throws InterruptedException, ExecutionException {
        CompletableFuture<String> future = CompletableFuture.supplyAsync(() -> "Hello")
                .thenCompose(s -> CompletableFuture.supplyAsync(() -> s + " World!"));
        String helloworld = future.get();
        assertEquals("Hello World!", helloworld);
    }

    @Test
    public void thenCombine() {
        ChainOperations_PrimitiveType scP = new ChainOperations_PrimitiveType();
        scP.doubleNum(2).thenCombine(scP.doubleNum(4), (a, b) -> a + b)
                .thenAccept(d -> printNum(d));
        logger.info("It should print 12 =2 * 2 + 4 * 4");

    }

}

6.2 Demo CompletableFutureTest

In this step, I will execute the Junit tests and capture the output here.

CompletableFutureTest output

C:\MaryZheng\Workspaces\completeablefuture-demo>mvn clean test -Dtest=CompletableFutureTest
[INFO] Scanning for projects...
[INFO]
[INFO] -------------< org.jcg.zheng.demo:completeablefuture-demo >-------------
[INFO] Building completeablefuture-demo 0.0.1-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ completeablefuture-demo ---
[INFO] Deleting C:\MaryZheng\Workspaces\completeablefuture-demo\target
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] Copying 1 resource
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:compile (default-compile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 19 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\classes
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] skip non existing resourceDirectory C:\MaryZheng\Workspaces\completeablefuture-demo\src\test\resources
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:testCompile (default-testCompile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 7 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\test-classes
[INFO]
[INFO] --- maven-surefire-plugin:2.12.4:test (default-test) @ completeablefuture-demo ---
[INFO] Surefire report directory: C:\MaryZheng\Workspaces\completeablefuture-demo\target\surefire-reports

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running org.jcg.zheng.demo.async.CompletableFutureTest
2019-05-22 21:38:18,546 414  [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:38:18,562 430  [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - started.
2019-05-22 21:38:18,588 456  [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 326KB. Waiting for 7 seconds
2019-05-22 21:38:23,565 5433 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - completed.
2019-05-22 21:38:23,585 5453 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.d.async.CompletableFutureTest - printNum 76
2019-05-22 21:38:25,591 7459 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:38:25,591 7459 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - started.
2019-05-22 21:38:25,593 7461 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:38:30,593 12461 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - completed.
2019-05-22 21:38:30,593 12461 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.d.async.CompletableFutureTest - printNum 652
2019-05-22 21:38:32,596 14464 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:38:32,599 14467 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:38:32,600 14468 [ForkJoinPool-1-worker-19] INFO  o.j.z.demo.async.tasks.SupplierTask - started.
2019-05-22 21:38:37,601 19469 [ForkJoinPool-1-worker-19] INFO  o.j.z.demo.async.tasks.SupplierTask - completed.
2019-05-22 21:38:37,601 19469 [ForkJoinPool-1-worker-19] INFO  o.j.z.d.async.CompletableFutureTest - printNum 424
2019-05-22 21:38:39,601 21469 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:38:39,601 21469 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - started.
2019-05-22 21:38:44,601 26469 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - completed.
2019-05-22 21:38:44,604 26472 [main] INFO  o.j.z.d.async.CompletableFutureTest - printNum 411
2019-05-22 21:38:44,605 26473 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 522KB. Waiting for 7 seconds
2019-05-22 21:38:51,606 33474 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:38:51,606 33474 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - started.
2019-05-22 21:38:51,614 33482 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:38:56,608 38476 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - completed.
2019-05-22 21:38:56,608 38476 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.d.async.CompletableFutureTest - printNum 397
2019-05-22 21:38:56,608 38476 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.d.async.CompletableFutureTest - Do step 1
2019-05-22 21:38:56,608 38476 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.d.async.CompletableFutureTest - Do step 2
2019-05-22 21:38:58,615 40483 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:38:58,618 40486 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:38:58,619 40487 [pool-2-thread-1] INFO  o.j.z.demo.async.tasks.CallableTask - started.
2019-05-22 21:39:03,620 45488 [pool-2-thread-1] INFO  o.j.z.demo.async.tasks.CallableTask - completed.
2019-05-22 21:39:05,620 47488 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:39:05,621 47489 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - started.
2019-05-22 21:39:05,622 47490 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:39:10,622 52490 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - completed.
2019-05-22 21:39:10,622 52490 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.d.async.CompletableFutureTest - printNum 838
2019-05-22 21:39:12,622 54490 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:39:12,623 54491 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - started.
2019-05-22 21:39:12,627 54495 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:39:17,624 59492 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - completed.
2019-05-22 21:39:17,624 59492 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.d.async.CompletableFutureTest - printNum 560
2019-05-22 21:39:19,628 61496 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:39:19,629 61497 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - started.
2019-05-22 21:39:19,630 61498 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:39:24,630 66498 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.SupplierTask - completed.
2019-05-22 21:39:24,630 66498 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.d.async.CompletableFutureTest - printNum 111
2019-05-22 21:39:26,631 68499 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:39:26,632 68500 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.RunnableTask - started.
2019-05-22 21:39:31,634 73502 [ForkJoinPool.commonPool-worker-3] INFO  o.j.z.demo.async.tasks.RunnableTask - completed.
2019-05-22 21:39:31,634 73502 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 141KB. Waiting for 7 seconds
2019-05-22 21:39:38,634 80502 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:39:38,635 80503 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 0KB. Waiting for 7 seconds
2019-05-22 21:39:45,636 87504 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:39:45,649 87517 [main] INFO  o.j.z.d.async.CompletableFutureTest - printNum 12
2019-05-22 21:39:45,649 87517 [main] INFO  o.j.z.d.async.CompletableFutureTest - It should print 12 =2 * 2 + 4 * 4
2019-05-22 21:39:45,649 87517 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 348KB. Waiting for 7 seconds
2019-05-22 21:39:52,650 94518 [main] INFO  o.j.z.d.async.CompletableFutureTest - started.
2019-05-22 21:39:52,663 94531 [main] INFO  o.j.z.d.async.CompletableFutureTest - completed. Total memory used 141KB. Waiting for 7 seconds
Tests run: 13, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 101.673 sec

Results :

Tests run: 13, Failures: 0, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  01:52 min
[INFO] Finished at: 2019-05-22T21:39:59-05:00
[INFO] ------------------------------------------------------------------------

C:\MaryZheng\Workspaces\completeablefuture-demo>

6.3 ChainOperations_PrimitiveType

One of big advantages of CompletableFuture is to chain the operations. In this step, I will demonstrate how to execute two math operations with a CompletableFuture class.

ChainOperations_PrimitiveType.java

package org.jcg.zheng.demo.async.tasks;

import java.util.concurrent.CompletableFuture;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class ChainOperations_PrimitiveType {
    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    // f(n)= 2n + 2
    public void mathFunctionDemo(CompletableFuture<Integer> future) {
        logger.info(DataUtils.THREAD_STARTS);
        future.thenApply(num -> num * 2).thenApply(num -> num + 2)
                .thenAccept((n -> logger.info("calculated value=" + n)));
        logger.info(DataUtils.THREAD_COMPLETED);
    }

    public CompletableFuture<Integer> doubleNum(int num) {
        return CompletableFuture.supplyAsync(() -> num * 2);
    }

}

6.4 ChainOperations_PrimitiveTypeTest

In this step, I will create a Junit test class to test ChainOperations_PrimitiveType.

ChainOperations_PrimitiveTypeTest.java

package org.jcg.zheng.demo.async;

import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertTrue;

import java.util.concurrent.CompletableFuture;
import java.util.concurrent.TimeUnit;

import org.jcg.zheng.demo.async.tasks.ChainOperations_PrimitiveType;
import org.junit.Test;

public class ChainOperations_PrimitiveTypeTest extends TestBase {

    ChainOperations_PrimitiveType plDemo = new ChainOperations_PrimitiveType();

    @Test
    public void it_should_calculate_to_six() {
        CompletableFuture<Integer> future = new CompletableFuture<>();
        plDemo.mathFunctionDemo(future);
        boolean completed = future.complete(2);
        assertTrue(completed);
    }

    @Test
    public void exceed_timeout_limit() {
        CompletableFuture<Integer> future = new CompletableFuture<>();
        future.orTimeout(1, TimeUnit.NANOSECONDS);
        plDemo.mathFunctionDemo(future);
        boolean completed = future.complete(2);
        assertFalse(completed);
    }

    @Test
    public void complete_within_timeout_limit() {
        CompletableFuture<Integer> future = new CompletableFuture<>();
        future.completeOnTimeout(500, 3, TimeUnit.SECONDS);
        plDemo.mathFunctionDemo(future);
        boolean completed = future.complete(2);
        assertTrue(completed);
    }

}

6.5 Demo ChainOperations_PrimitiveTypeTest

In this step, I will execute the Junit tests and capture the output here.

ChainOperations_PrimitiveTypeTest output

C:\MaryZheng\Workspaces\completeablefuture-demo>mvn clean test -Dtest=ChainOperations_PrimitiveTypeTest
[INFO] Scanning for projects...
[INFO]
[INFO] -------------< org.jcg.zheng.demo:completeablefuture-demo >-------------
[INFO] Building completeablefuture-demo 0.0.1-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ completeablefuture-demo ---
[INFO] Deleting C:\MaryZheng\Workspaces\completeablefuture-demo\target
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] Copying 1 resource
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:compile (default-compile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 19 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\classes
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] skip non existing resourceDirectory C:\MaryZheng\Workspaces\completeablefuture-demo\src\test\resources
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:testCompile (default-testCompile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 7 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\test-classes
[INFO]
[INFO] --- maven-surefire-plugin:2.12.4:test (default-test) @ completeablefuture-demo ---
[INFO] Surefire report directory: C:\MaryZheng\Workspaces\completeablefuture-demo\target\surefire-reports

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running org.jcg.zheng.demo.async.ChainOperations_PrimitiveTypeTest
2019-05-22 22:24:47,144 461  [main] INFO  o.j.z.d.a.ChainOperations_PrimitiveTypeTest - started.
2019-05-22 22:24:47,162 479  [main] INFO  o.j.z.d.a.t.ChainOperations_PrimitiveType - started.
2019-05-22 22:24:47,166 483  [main] INFO  o.j.z.d.a.t.ChainOperations_PrimitiveType - completed.
2019-05-22 22:24:47,212 529  [main] INFO  o.j.z.d.a.ChainOperations_PrimitiveTypeTest - completed. Total memory used 587KB. Waiting for 7 seconds
2019-05-22 22:24:54,215 7532 [main] INFO  o.j.z.d.a.ChainOperations_PrimitiveTypeTest - started.
2019-05-22 22:24:54,216 7533 [main] INFO  o.j.z.d.a.t.ChainOperations_PrimitiveType - started.
2019-05-22 22:24:54,216 7533 [main] INFO  o.j.z.d.a.t.ChainOperations_PrimitiveType - completed.
2019-05-22 22:24:54,230 7547 [main] INFO  o.j.z.d.a.t.ChainOperations_PrimitiveType - calculated value=6
2019-05-22 22:24:54,231 7548 [main] INFO  o.j.z.d.a.ChainOperations_PrimitiveTypeTest - completed. Total memory used 293KB. Waiting for 7 seconds
2019-05-22 22:25:01,232 14549 [main] INFO  o.j.z.d.a.ChainOperations_PrimitiveTypeTest - started.
2019-05-22 22:25:01,233 14550 [main] INFO  o.j.z.d.a.t.ChainOperations_PrimitiveType - started.
2019-05-22 22:25:01,234 14551 [main] INFO  o.j.z.d.a.t.ChainOperations_PrimitiveType - completed.
2019-05-22 22:25:01,234 14551 [main] INFO  o.j.z.d.a.t.ChainOperations_PrimitiveType - calculated value=6
2019-05-22 22:25:01,235 14552 [main] INFO  o.j.z.d.a.ChainOperations_PrimitiveTypeTest - completed. Total memory used 0KB. Waiting for 7 seconds
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 21.713 sec

Results :

Tests run: 3, Failures: 0, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  33.569 s
[INFO] Finished at: 2019-05-22T22:25:08-05:00
[INFO] ------------------------------------------------------------------------

C:\MaryZheng\Workspaces\completeablefuture-demo>

7. Process Orders

In this step, I will create a business application which processes a large amount of orders. For each order, it processes the order items, then emails the user with a status, finally prints out the order after both steps are completed.

7.1 ProcessOrders_BeforeCompletableFuture

In this step, I will create a ProcessOrders_BeforeCompletableFuture class which initializes a thread pool with ten threads and loops through the order and submits two asynchronous tasks for both ProcessOrder and NotifyUser via the Future interface. I will create a Junit test class to demonstrate the execution based on the order count.

ProcessOrders_BeforeCompletableFuture.java

package org.jcg.zheng.demo.async;

import java.util.concurrent.Callable;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.jcg.zheng.demo.async.data.Order;
import org.jcg.zheng.demo.async.tasks.NotifyUserTask;
import org.jcg.zheng.demo.async.tasks.ProcessOrderTask;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class ProcessOrders_BeforeCompletableFuture {

    final Logger logger = LoggerFactory.getLogger(this.getClass());

    public void processOrder(int orderCounts) {
        ExecutorService service = Executors.newFixedThreadPool(orderCounts);

        logger.info(DataUtils.THREAD_STARTS);
        for (int i = 0; i < orderCounts; i++) {
            Callable<Order> orderTask = new ProcessOrderTask(i);
            Future<Order> future = service.submit(orderTask);

            try {
                Order order = future.get();
                logger.info(DataUtils.MAIN_THREAD_RESUMES + " with results from async task ="
                        + order.toString());

                Callable<Order> emailTask = new NotifyUserTask(order);
                future = service.submit(emailTask);

                order = future.get();

                logger.info(DataUtils.MAIN_THREAD_RESUMES + " with results from async task ="
                        + order.toString());
            } catch (InterruptedException | ExecutionException e) {
            }
        }
    }

}

7.2 ProcessOrders_BeforeCompletableFutureTest

In this step, I will create several test cases to process 1, 10, and 100 Orders.

ProcessOrders_BeforeCompletableFutureTest.java

package org.jcg.zheng.demo.async;

import org.jcg.zheng.demo.async.ProcessOrders_BeforeCompletableFuture;
import org.junit.Test;

public class ProcessOrders_BeforeCompletableFutureTest extends TestBase {

    @Test
    public void process_order_notifyUser_not_scale_1() {
        ProcessOrders_BeforeCompletableFuture po = new ProcessOrders_BeforeCompletableFuture();
        po.processOrder(1); // 7 seconds
    }

    @Test
    public void process_order_notifyUser_not_scale_10() {
        ProcessOrders_BeforeCompletableFuture po = new ProcessOrders_BeforeCompletableFuture();
        po.processOrder(10); // 100 seconds with 5.1MB memory used
    }

    @Test
    public void process_order_notifyUser_not_scale_100() {
        ProcessOrders_BeforeCompletableFuture po = new ProcessOrders_BeforeCompletableFuture();
        po.processOrder(100);// tool 941 seconds with
    }

}

7.3 Demo ProcessOrders_BeforeCompletableFutureTest

In this step, I will execute the junit test and capture the output to show the thread execution of the processing 1, 10, and 100 Orders.

Note: I add @Ignore for the 100 orders test case to save space here. You can run it yourself to see how long it takes to completes 100 orders. Mine took about 900 seconds.

ProcessOrders_BeforeCompletableFutureTest output

C:\MaryZheng\Workspaces\completeablefuture-demo>mvn  test -Dtest=ProcessOrders_BeforeCompletableFutureTest
[INFO] Scanning for projects...
[INFO]
[INFO] -------------< org.jcg.zheng.demo:completeablefuture-demo >-------------
[INFO] Building completeablefuture-demo 0.0.1-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] Copying 1 resource
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:compile (default-compile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 19 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\classes
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] skip non existing resourceDirectory C:\MaryZheng\Workspaces\completeablefuture-demo\src\test\resources
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:testCompile (default-testCompile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 7 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\test-classes
[INFO]
[INFO] --- maven-surefire-plugin:2.12.4:test (default-test) @ completeablefuture-demo ---
[INFO] Surefire report directory: C:\MaryZheng\Workspaces\completeablefuture-demo\target\surefire-reports

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running org.jcg.zheng.demo.async.ProcessOrders_BeforeCompletableFutureTest
2019-05-22 22:40:29,009 565  [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFutureTest - started.
2019-05-22 22:40:29,038 594  [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - started.
2019-05-22 22:40:29,058 614  [pool-2-thread-1] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:40:29,076 632  [pool-2-thread-1] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:40:34,079 5635 [pool-2-thread-1] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:40:34,119 5675 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=0, status=ERROR, detail=processOrder failed.]
2019-05-22 22:40:34,123 5679 [pool-2-thread-2] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:40:34,123 5679 [pool-2-thread-2] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:40:36,124 7680 [pool-2-thread-2] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:40:36,124 7680 [pool-2-thread-2] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:40:36,125 7681 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=0, status=ERROR, detail=send an email-error.]
2019-05-22 22:40:36,134 7690 [pool-2-thread-3] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:40:36,137 7693 [pool-2-thread-3] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:40:41,138 12694 [pool-2-thread-3] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:40:41,138 12694 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=1, status=PROCESSED, detail=processOrder succeed.]
2019-05-22 22:40:41,140 12696 [pool-2-thread-4] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:40:41,140 12696 [pool-2-thread-4] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:40:46,142 17698 [pool-2-thread-4] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:40:46,142 17698 [pool-2-thread-4] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:40:46,142 17698 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=1, status=PROCESSED, detail=sent an email-processed.]
2019-05-22 22:40:46,143 17699 [pool-2-thread-5] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:40:46,144 17700 [pool-2-thread-5] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:40:51,144 22700 [pool-2-thread-5] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:40:51,144 22700 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=2, status=PROCESSED, detail=processOrder succeed.]
2019-05-22 22:40:51,146 22702 [pool-2-thread-6] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:40:51,146 22702 [pool-2-thread-6] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:40:56,146 27702 [pool-2-thread-6] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:40:56,146 27702 [pool-2-thread-6] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:40:56,146 27702 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=2, status=PROCESSED, detail=sent an email-processed.]
2019-05-22 22:40:56,147 27703 [pool-2-thread-7] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:40:56,148 27704 [pool-2-thread-7] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:41:01,149 32705 [pool-2-thread-7] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:41:01,149 32705 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=3, status=PROCESSED, detail=processOrder succeed.]
2019-05-22 22:41:01,150 32706 [pool-2-thread-8] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:41:01,151 32707 [pool-2-thread-8] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:41:06,152 37708 [pool-2-thread-8] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:41:06,152 37708 [pool-2-thread-8] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:41:06,152 37708 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=3, status=PROCESSED, detail=sent an email-processed.]
2019-05-22 22:41:06,154 37710 [pool-2-thread-9] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:41:06,154 37710 [pool-2-thread-9] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:41:11,155 42711 [pool-2-thread-9] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:41:11,155 42711 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=4, status=PROCESSED, detail=processOrder succeed.]
2019-05-22 22:41:11,157 42713 [pool-2-thread-10] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:41:11,157 42713 [pool-2-thread-10] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:41:16,157 47713 [pool-2-thread-10] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:41:16,157 47713 [pool-2-thread-10] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:41:16,157 47713 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=4, status=PROCESSED, detail=sent an email-processed.]
2019-05-22 22:41:16,158 47714 [pool-2-thread-1] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:41:16,158 47714 [pool-2-thread-1] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:41:21,159 52715 [pool-2-thread-1] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:41:21,159 52715 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=5, status=ERROR, detail=processOrder failed.]
2019-05-22 22:41:21,159 52715 [pool-2-thread-2] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:41:21,160 52716 [pool-2-thread-2] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:41:23,161 54717 [pool-2-thread-2] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:41:23,161 54717 [pool-2-thread-2] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:41:23,162 54718 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=5, status=ERROR, detail=send an email-error.]
2019-05-22 22:41:23,163 54719 [pool-2-thread-3] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:41:23,163 54719 [pool-2-thread-3] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:41:28,163 59719 [pool-2-thread-3] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:41:28,163 59719 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=6, status=PROCESSED, detail=processOrder succeed.]
2019-05-22 22:41:28,164 59720 [pool-2-thread-4] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:41:28,164 59720 [pool-2-thread-4] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:41:33,164 64720 [pool-2-thread-4] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:41:33,164 64720 [pool-2-thread-4] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:41:33,164 64720 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=6, status=PROCESSED, detail=sent an email-processed.]
2019-05-22 22:41:33,165 64721 [pool-2-thread-5] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:41:33,165 64721 [pool-2-thread-5] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:41:38,166 69722 [pool-2-thread-5] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:41:38,166 69722 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=7, status=PROCESSED, detail=processOrder succeed.]
2019-05-22 22:41:38,166 69722 [pool-2-thread-6] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:41:38,167 69723 [pool-2-thread-6] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:41:43,167 74723 [pool-2-thread-6] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:41:43,167 74723 [pool-2-thread-6] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:41:43,167 74723 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=7, status=PROCESSED, detail=sent an email-processed.]
2019-05-22 22:41:43,168 74724 [pool-2-thread-7] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:41:43,168 74724 [pool-2-thread-7] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:41:48,169 79725 [pool-2-thread-7] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:41:48,169 79725 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=8, status=PROCESSED, detail=processOrder succeed.]
2019-05-22 22:41:48,170 79726 [pool-2-thread-8] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:41:48,170 79726 [pool-2-thread-8] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:41:53,170 84726 [pool-2-thread-8] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:41:53,170 84726 [pool-2-thread-8] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:41:53,170 84726 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=8, status=PROCESSED, detail=sent an email-processed.]
2019-05-22 22:41:53,171 84727 [pool-2-thread-9] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:41:53,171 84727 [pool-2-thread-9] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:41:58,171 89727 [pool-2-thread-9] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:41:58,171 89727 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=9, status=PROCESSED, detail=processOrder succeed.]
2019-05-22 22:41:58,172 89728 [pool-2-thread-10] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:41:58,172 89728 [pool-2-thread-10] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:42:03,172 94728 [pool-2-thread-10] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:42:03,172 94728 [pool-2-thread-10] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:42:03,172 94728 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=9, status=PROCESSED, detail=sent an email-processed.]
2019-05-22 22:42:03,193 94749 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFutureTest - completed. Total memory used -1827KB. Waiting for 7 seconds
2019-05-22 22:42:10,197 101753 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFutureTest - started.
2019-05-22 22:42:10,197 101753 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - started.
2019-05-22 22:42:10,198 101754 [pool-3-thread-1] INFO  o.j.z.d.a.tasks.ProcessOrderTask - started.
2019-05-22 22:42:10,199 101755 [pool-3-thread-1] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:42:15,199 106755 [pool-3-thread-1] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:42:15,199 106755 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=0, status=ERROR, detail=processOrder failed.]
2019-05-22 22:42:15,200 106756 [pool-3-thread-1] INFO  o.j.z.d.async.tasks.NotifyUserTask - started.
2019-05-22 22:42:15,200 106756 [pool-3-thread-1] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:42:17,201 108757 [pool-3-thread-1] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:42:17,201 108757 [pool-3-thread-1] INFO  o.j.z.d.async.tasks.NotifyUserTask - completed.
2019-05-22 22:42:17,201 108757 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFuture - Main thread resumes after the async task is completed.  with results from async task =Order [orderId=0, status=ERROR, detail=send an email-error.]
2019-05-22 22:42:17,201 108757 [main] INFO  o.j.z.d.a.ProcessOrders_BeforeCompletableFutureTest - completed. Total memory used 522KB. Waiting for 7 seconds
Tests run: 3, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 115.912 sec

Results :

Tests run: 3, Failures: 0, Errors: 0, Skipped: 1

[WARNING] Could not delete temp direcotry C:\MaryZheng\Workspaces\completeablefuture-demo\target\surefire because File C:\MaryZheng\Workspaces\completeablefuture-demo\target\surefire\surefirebooter6661281796760593701.jar unable to be deleted.
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  02:07 min
[INFO] Finished at: 2019-05-22T22:42:24-05:00
[INFO] ------------------------------------------------------------------------

C:\MaryZheng\Workspaces\completeablefuture-demo>

7.4 ProcessOrders_CompletableFuture

In this step, I will create a ProcessOrders_CompletableFuture class which initializes a thread pool with ten threads and loops through the order with chained operations. It has two methods to process a list of orders:

• processOrders – starts with a SupplierOrderTask asynchronously, then applies the Order::emailNotification method, then log a message. This runs faster.
• chainOrderProcess – chains the Order::process and Order::emailNotification methods for a given future.

ProcessOrders_CompletableFuture.java

package org.jcg.zheng.demo.async;

import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.ForkJoinPool;

import org.jcg.zheng.demo.async.data.DataUtils;
import org.jcg.zheng.demo.async.data.Order;
import org.jcg.zheng.demo.async.tasks.SupplierOrderTask;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class ProcessOrders_CompletableFuture {

    ForkJoinPool fjp = new ForkJoinPool(10);

    final Logger logger = LoggerFactory.getLogger(this.getClass());

    public void processOrders(int orderCounts) {
        logger.info(DataUtils.THREAD_STARTS);
        List<CompletableFuture<Order>> futures = new ArrayList<>();

        for (int i = 0; i < orderCounts; i++) {
            SupplierOrderTask order = new SupplierOrderTask(i);

            CompletableFuture<Order> future = CompletableFuture.supplyAsync(order, fjp)
                    .thenApply(Order::emailNotification).whenComplete((o, r) -> {
                        logger.info("Send email for " + o.toString());
                    });

            futures.add(future);
            logger.info("future isDone=" + future.isDone());
        }
    }

    public void processOrders_chain(int orderCounts) {
        logger.info(DataUtils.THREAD_STARTS);


        List<CompletableFuture<Order>> futures = new ArrayList<>();

        for (int i = 0; i < orderCounts; i++) {
            CompletableFuture<Order> future = new CompletableFuture<>();
            chainOrderProcess(future);
            Order order = new Order();
            order.setOrderId(i);
            boolean completed = future.complete(order);
            logger.info("future completed=" + completed);
            futures.add(future);
        }

    }

    // process order, then notify user via an email, then output
    private void chainOrderProcess(CompletableFuture<Order> future) {
        logger.info(DataUtils.THREAD_STARTS);
        future.thenApply(Order::process).thenApply(Order::emailNotification)
                .thenAccept(System.out::println);
        logger.info(DataUtils.THREAD_COMPLETED);
    }

}

7.5 ProcessOrders_CompletableFutureTest

I will create a junit test to process 1, 10, 50, 100 orders and compare the execution time and memory used.

ProcessOrders_CompletableFuture.java

package org.jcg.zheng.demo.async;

import org.junit.Ignore;
import org.junit.Test;

public class ProcessOrders_CompletableFutureTest extends TestBase {

    @Test
    public void process_order_notifyUser_chain_1() {
        ProcessOrders_CompletableFuture po = new ProcessOrders_CompletableFuture();
        po.processOrders_chain(1);
        sleepInSeconds = 3; // 7 seconds, 300KB memory used
    }

    @Test
    public void process_order_notifyUser_chain_10() {
        ProcessOrders_CompletableFuture po = new ProcessOrders_CompletableFuture();
        po.processOrders_chain(10);
        sleepInSeconds = 11; // 80 seconds, memory used -1045KB
    }

    @Test
    public void process_order_notifyUser_10() {
        ProcessOrders_CompletableFuture po = new ProcessOrders_CompletableFuture();
        po.processOrders(10);
        sleepInSeconds = 11; // 11 seconds, Total memory used 1112KB
    }

    @Ignore
    @Test
    public void process_order_notifyUser_chain_50() {
        ProcessOrders_CompletableFuture po = new ProcessOrders_CompletableFuture();
        po.processOrders_chain(50);
        sleepInSeconds = 11;// used 360 seconds
    }

    @Ignore
    @Test
    public void process_order_notifyUser_50() {
        ProcessOrders_CompletableFuture po = new ProcessOrders_CompletableFuture();
        po.processOrders(50);
        sleepInSeconds = 110;// used 35 seconds
    }

    @Test
    public void process_order_notifyUser_100() {
        ProcessOrders_CompletableFuture po = new ProcessOrders_CompletableFuture();
        po.processOrders_chain(100);
        sleepInSeconds = 11;// 700 seconds, Total memory used -5579KB
    }

}

7.6 Demo ProcessOrders_CompletableFutureTest

In this step, I will execute the junit test and capture the output to show the thread execution of the processing 1, 10, and 100 Orders.

ProcessOrders_CompletableFutureTest output

C:\MaryZheng\Workspaces\completeablefuture-demo>mvn  test -Dtest=ProcessOrders_CompletableFutureTest
[INFO] Scanning for projects...
[INFO]
[INFO] -------------< org.jcg.zheng.demo:completeablefuture-demo >-------------
[INFO] Building completeablefuture-demo 0.0.1-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] Copying 1 resource
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:compile (default-compile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 19 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\classes
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ completeablefuture-demo ---
[WARNING] Using platform encoding (Cp1252 actually) to copy filtered resources, i.e. build is platform dependent!
[INFO] skip non existing resourceDirectory C:\MaryZheng\Workspaces\completeablefuture-demo\src\test\resources
[INFO]
[INFO] --- maven-compiler-plugin:3.8.0:testCompile (default-testCompile) @ completeablefuture-demo ---
[INFO] Changes detected - recompiling the module!
[WARNING] File encoding has not been set, using platform encoding Cp1252, i.e. build is platform dependent!
[INFO] Compiling 7 source files to C:\MaryZheng\Workspaces\completeablefuture-demo\target\test-classes
[INFO]
[INFO] --- maven-surefire-plugin:2.12.4:test (default-test) @ completeablefuture-demo ---
[INFO] Surefire report directory: C:\MaryZheng\Workspaces\completeablefuture-demo\target\surefire-reports

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running org.jcg.zheng.demo.async.ProcessOrders_CompletableFutureTest
2019-05-22 22:46:25,677 422  [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFutureTest - started.
2019-05-22 22:46:25,696 441  [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:46:25,699 444  [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:46:25,715 460  [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:46:25,731 476  [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 0
2019-05-22 22:46:25,733 478  [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:46:30,737 5482 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:46:30,737 5482 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:46:32,739 7484 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:46:32,740 7485 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 0
Order [orderId=0, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:46:32,784 7529 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:46:32,784 7529 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:46:32,784 7529 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:46:32,785 7530 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 1
2019-05-22 22:46:32,785 7530 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:46:37,786 12531 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:46:37,786 12531 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:46:39,787 14532 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:46:39,787 14532 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 1
Order [orderId=1, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:46:39,787 14532 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:46:39,787 14532 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:46:39,787 14532 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:46:39,787 14532 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 2
2019-05-22 22:46:39,787 14532 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:46:44,788 19533 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:46:44,788 19533 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:46:46,788 21533 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:46:46,788 21533 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 2
Order [orderId=2, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:46:46,788 21533 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:46:46,788 21533 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:46:46,788 21533 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:46:46,789 21534 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 3
2019-05-22 22:46:46,790 21535 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:46:51,791 26536 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:46:51,791 26536 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:46:53,791 28536 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:46:53,791 28536 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 3
Order [orderId=3, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:46:53,791 28536 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:46:53,791 28536 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:46:53,792 28537 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:46:53,792 28537 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 4
2019-05-22 22:46:53,792 28537 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:46:58,793 33538 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:46:58,793 33538 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:47:00,793 35538 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:47:00,793 35538 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 4
Order [orderId=4, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:47:00,795 35540 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:47:00,795 35540 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:47:00,795 35540 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:47:00,795 35540 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 5
2019-05-22 22:47:00,795 35540 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:05,796 40541 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:47:05,796 40541 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:47:07,797 42542 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:47:07,797 42542 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 5
Order [orderId=5, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:47:07,799 42544 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:47:07,799 42544 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:47:07,800 42545 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:47:07,800 42545 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 6
2019-05-22 22:47:07,800 42545 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:12,801 47546 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:47:12,801 47546 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:47:14,803 49548 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:47:14,803 49548 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 6
Order [orderId=6, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:47:14,804 49549 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:47:14,804 49549 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:47:14,804 49549 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:47:14,804 49549 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 7
2019-05-22 22:47:14,804 49549 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:19,804 54549 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:47:19,804 54549 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:47:21,804 56549 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:47:21,804 56549 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 7
Order [orderId=7, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:47:21,805 56550 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:47:21,805 56550 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:47:21,805 56550 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:47:21,805 56550 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 8
2019-05-22 22:47:21,805 56550 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:26,806 61551 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:47:26,806 61551 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:47:28,807 63552 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:47:28,807 63552 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 8
Order [orderId=8, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:47:28,808 63553 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:47:28,809 63554 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:47:28,810 63555 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:47:28,811 63556 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 9
2019-05-22 22:47:28,811 63556 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:33,813 68558 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:47:33,813 68558 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:47:35,813 70558 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:47:35,813 70558 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 9
Order [orderId=9, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:47:35,813 70558 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:47:35,834 70579 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFutureTest - completed. Total memory used -5981KB. Waiting for 11 seconds
2019-05-22 22:47:46,839 81584 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFutureTest - started.
2019-05-22 22:47:46,840 81585 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:47:46,840 81585 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:47:46,840 81585 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - completed.
2019-05-22 22:47:46,840 81585 [main] INFO  org.jcg.zheng.demo.async.data.Order - process for 0
2019-05-22 22:47:46,840 81585 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:51,840 86585 [main] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:47:51,840 86585 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:47:53,841 88586 [main] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:47:53,841 88586 [main] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 0
Order [orderId=0, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:47:53,842 88587 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future completed=true
2019-05-22 22:47:53,842 88587 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFutureTest - completed. Total memory used 0KB. Waiting for 3 seconds
2019-05-22 22:47:56,844 91589 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFutureTest - started.
2019-05-22 22:47:56,844 91589 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - started.
2019-05-22 22:47:56,859 91604 [ForkJoinPool-3-worker-19] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 0
2019-05-22 22:47:56,860 91605 [ForkJoinPool-3-worker-19] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:56,860 91605 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,861 91606 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,861 91606 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,862 91607 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,862 91607 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,862 91607 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,863 91608 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,864 91609 [ForkJoinPool-3-worker-23] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 2
2019-05-22 22:47:56,866 91611 [ForkJoinPool-3-worker-23] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:56,867 91612 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,864 91609 [ForkJoinPool-3-worker-5] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 1
2019-05-22 22:47:56,867 91612 [ForkJoinPool-3-worker-5] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:56,867 91612 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,868 91613 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - future isDone=false
2019-05-22 22:47:56,868 91613 [main] INFO  o.j.z.d.a.ProcessOrders_CompletableFutureTest - completed. Total memory used 1605KB. Waiting for 11 seconds
2019-05-22 22:47:56,870 91615 [ForkJoinPool-3-worker-27] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 3
2019-05-22 22:47:56,870 91615 [ForkJoinPool-3-worker-27] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:56,871 91616 [ForkJoinPool-3-worker-9] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 4
2019-05-22 22:47:56,871 91616 [ForkJoinPool-3-worker-9] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:56,873 91618 [ForkJoinPool-3-worker-13] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 5
2019-05-22 22:47:56,874 91619 [ForkJoinPool-3-worker-13] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:56,874 91619 [ForkJoinPool-3-worker-31] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 6
2019-05-22 22:47:56,874 91619 [ForkJoinPool-3-worker-31] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:56,876 91621 [ForkJoinPool-3-worker-3] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 8
2019-05-22 22:47:56,877 91622 [ForkJoinPool-3-worker-3] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:56,877 91622 [ForkJoinPool-3-worker-17] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 7
2019-05-22 22:47:56,877 91622 [ForkJoinPool-3-worker-17] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:47:56,879 91624 [ForkJoinPool-3-worker-21] INFO  o.j.z.d.a.tasks.SupplierOrderTask - started.  for 9
2019-05-22 22:47:56,879 91624 [ForkJoinPool-3-worker-21] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder started.
2019-05-22 22:48:01,860 96605 [ForkJoinPool-3-worker-19] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,860 96605 [ForkJoinPool-3-worker-19] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:01,867 96612 [ForkJoinPool-3-worker-23] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,867 96612 [ForkJoinPool-3-worker-23] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:01,868 96613 [ForkJoinPool-3-worker-5] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,868 96613 [ForkJoinPool-3-worker-5] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:01,870 96615 [ForkJoinPool-3-worker-27] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,870 96615 [ForkJoinPool-3-worker-27] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:01,872 96617 [ForkJoinPool-3-worker-9] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,872 96617 [ForkJoinPool-3-worker-9] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:01,874 96619 [ForkJoinPool-3-worker-31] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,874 96619 [ForkJoinPool-3-worker-31] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:01,874 96619 [ForkJoinPool-3-worker-13] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,874 96619 [ForkJoinPool-3-worker-13] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:01,877 96622 [ForkJoinPool-3-worker-3] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,877 96622 [ForkJoinPool-3-worker-17] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,878 96623 [ForkJoinPool-3-worker-3] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:01,879 96624 [ForkJoinPool-3-worker-17] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:01,880 96625 [ForkJoinPool-3-worker-21] INFO  o.j.zheng.demo.async.data.DataUtils - processOrder completed.
2019-05-22 22:48:01,880 96625 [ForkJoinPool-3-worker-21] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail started.
2019-05-22 22:48:03,861 98606 [ForkJoinPool-3-worker-19] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,861 98606 [ForkJoinPool-3-worker-19] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 0
2019-05-22 22:48:03,862 98607 [ForkJoinPool-3-worker-19] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=0, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:48:03,868 98613 [ForkJoinPool-3-worker-23] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,868 98613 [ForkJoinPool-3-worker-23] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 2
2019-05-22 22:48:03,868 98613 [ForkJoinPool-3-worker-23] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=2, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:48:03,868 98613 [ForkJoinPool-3-worker-5] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,868 98613 [ForkJoinPool-3-worker-5] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 1
2019-05-22 22:48:03,868 98613 [ForkJoinPool-3-worker-5] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=1, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:48:03,870 98615 [ForkJoinPool-3-worker-27] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,870 98615 [ForkJoinPool-3-worker-27] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 3
2019-05-22 22:48:03,870 98615 [ForkJoinPool-3-worker-27] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=3, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:48:03,872 98617 [ForkJoinPool-3-worker-9] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,872 98617 [ForkJoinPool-3-worker-9] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 4
2019-05-22 22:48:03,872 98617 [ForkJoinPool-3-worker-9] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=4, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:48:03,875 98620 [ForkJoinPool-3-worker-13] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,875 98620 [ForkJoinPool-3-worker-31] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,875 98620 [ForkJoinPool-3-worker-13] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 5
2019-05-22 22:48:03,875 98620 [ForkJoinPool-3-worker-31] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 6
2019-05-22 22:48:03,876 98621 [ForkJoinPool-3-worker-13] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=5, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:48:03,876 98621 [ForkJoinPool-3-worker-31] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=6, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:48:03,879 98624 [ForkJoinPool-3-worker-3] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,879 98624 [ForkJoinPool-3-worker-3] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 8
2019-05-22 22:48:03,879 98624 [ForkJoinPool-3-worker-17] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,881 98626 [ForkJoinPool-3-worker-17] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 7
2019-05-22 22:48:03,881 98626 [ForkJoinPool-3-worker-17] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=7, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:48:03,879 98624 [ForkJoinPool-3-worker-3] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=8, status=NOTIFIED, detail=send an email-error.]
2019-05-22 22:48:03,881 98626 [ForkJoinPool-3-worker-21] INFO  o.j.zheng.demo.async.data.DataUtils - sendEmail completed.
2019-05-22 22:48:03,881 98626 [ForkJoinPool-3-worker-21] INFO  org.jcg.zheng.demo.async.data.Order - emailNotification for 9
2019-05-22 22:48:03,881 98626 [ForkJoinPool-3-worker-21] INFO  o.j.z.d.a.ProcessOrders_CompletableFuture - Send email for Order [orderId=9, status=NOTIFIED, detail=send an email-error.]
Tests run: 6, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 102.762 sec

Results :

Tests run: 6, Failures: 0, Errors: 0, Skipped: 3

[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  01:53 min
[INFO] Finished at: 2019-05-22T22:48:08-05:00
[INFO] ------------------------------------------------------------------------

C:\MaryZheng\Workspaces\completeablefuture-demo>

8. Summary

In this tutorial, I demonstrated the basic usage of the CompletableFuture class and created two Java classes to process a list of orders with two operations. I also compared how easy it is to use CompletableFuture to chain the operations.

9. Download the Source Code

This was a Maven project which includes Junit test classes and application classes to process a list of orders with the CompletableFuture class.

Do you want to know how to develop your skillset to become a Java Rockstar?

Subscribe to our newsletter to start Rocking right now!

To get you started we give you our best selling eBooks for FREE!

1. JPA Mini Book

2. JVM Troubleshooting Guide

3. JUnit Tutorial for Unit Testing

4. Java Annotations Tutorial

5. Java Interview Questions

6. Spring Interview Questions

7. Android UI Design

and many more ....

I agree to the Terms and Privacy Policy

Sign up

Thank you!

We will contact you soon.