Measure execution time of async method

Question

I have async method where I use DeferredResult as return type. I want write junit test for that method where I call this method in loop, e.g 100 times, and I need measure execution time for every call of that method.

Here is method sample:

@Transactional(readOnly = true)
@Override
public DeferredResult foo() {
    DeferredResult dr = new DeferredResult(5000L, "timeout");
    dr.onCompletion(() -> {
        // do some stuff
    });
    deferredResults.add(dr);

    return dr;        
}

created deferredResult I add into collection, and I iterate that collection in another method where I set some result, and then is dr returned.

Can you show my how should looks like test where I will be able measure execution time of multiple calls of that method?

@Test
public void executionTimeTest() {
    for (int i = 0; i < 100; i++) {
        asyncService.foo();
    }

    // here I need get execution time for each call
}

Thanks.

Answer 1

I think the best way to solve this question is adding additional data in DeferredResult class as it is recommended by spring docs. Precisely, the following sentence in spring docs points out this possibility.

Subclasses can extend this class to easily associate additional data or behavior with the DeferredResult. For example, one might want to associate the user used to create the DeferredResult by extending the class and adding an additional property for the user. In this way, the user could easily be accessed later without the need to use a data structure to do the mapping.

Given this possibility, you can extend the DeferredResult and add a start and end time:

public class MyDeferredResult extends DeferredResult {

    long startTime;
    long endTime;

    public MyDeferredResult(Long timeout, Object timeoutResult) {
        super(timeout, timeoutResult);
        this.startTime = System.currentTimeMillis();
    }

    @Override
    public boolean setResult(Object result) {
        boolean r = super.setResult(result);
        this.endTime = System.currentTimeMillis();
        return r;
    }

    public long totalTime() {
        return (endTime - startTime)/1000;
    }

}

Then, your Async Service can be similar to this one:

 public MyDeferredResult foo() {
    MyDeferredResult dr = new MyDeferredResult(5000L, "timeout");
    new Thread(() -> {
        Random r = new Random();
        System.out.println("async task started");
        try {
            Thread.sleep(r.nextInt(4) * 1000 );
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        System.out.println("async task finished");
        dr.setResult("test async result");
    }).start();
    deferredResults.add(dr);
    return dr;
}

boolean hasResults() {
    boolean result = true;
    for(MyDeferredResult dr: deferredResults) {
        result = result && dr.hasResult();
    }
    return result;
}

Finally, in your test, you can retrieve the total time of each execution:

   @Test
    public void executionTimeTest() {
        Service service = new Service();
        for (int i = 0; i < 10; i++) {
            service.foo();
        }

       while (!service.hasResults()) {
            System.out.println("No result yet");
       }

        for(MyDeferredResult dr: service.deferredResults) {
            System.out.println(dr.totalTime());
        }
    }