How to compute the total execution time in multithread application

Question

There is an application that I need to test to see the relationship between number of threads and the total duration of an execution in an multithreaded application. That is what I am trying at the moment:

    //Start time of thread executions.
    long start = System.currentTimeMillis();
    //Here, I am initializing the thread list which will store each thread.
    MyThreadClass[] threads = new MyThreadClass[numOfThreads];
    //Start each thread.
    for (int i = 0; i < threads.length; i++) {
        threads[i] = new MyThreadClass(/*Constructor parameters here*/);
        //Start the thread.
        threads[i].start();
        //There is a variable assignment to change the parameter of a constructor on next iteration.
    }
    //Join all the threads.
    for (MyThreadClass thread : threads) {
        thread.join();
    }

    //After all threads are done, compute the elapsed time to get computation time.
    long finish = System.currentTimeMillis();
    long duration = finish - start;
    System.out.println("Total duration of the computation with " + threads.length + " thread is " + duration + " milliseconds.");

But here is the problem when I have tested the application by wrapping the code inside the main() with some for loop to test. I believe, something is irrational with those number.

Total duration of the computation with 1 thread is 50 milliseconds.
Total duration of the computation with 2 thread is 25 milliseconds.
Total duration of the computation with 3 thread is 25 milliseconds.
Total duration of the computation with 4 thread is 15 milliseconds.
Total duration of the computation with 5 thread is 19 milliseconds.
Total duration of the computation with 6 thread is 16 milliseconds.
Total duration of the computation with 7 thread is 15 milliseconds.
Total duration of the computation with 8 thread is 25 milliseconds.
Total duration of the computation with 9 thread is 20 milliseconds.
Total duration of the computation with 10 thread is 20 milliseconds.
Total duration of the computation with 11 thread is 30 milliseconds.
Total duration of the computation with 12 thread is 34 milliseconds.
Total duration of the computation with 13 thread is 34 milliseconds.
Total duration of the computation with 14 thread is 18 milliseconds.
Total duration of the computation with 15 thread is 18 milliseconds.
Total duration of the computation with 16 thread is 18 milliseconds.
Total duration of the computation with 17 thread is 15 milliseconds.
Total duration of the computation with 18 thread is 19 milliseconds.
Total duration of the computation with 19 thread is 17 milliseconds.
Total duration of the computation with 20 thread is 13 milliseconds.
Total duration of the computation with 21 thread is 13 milliseconds.
Total duration of the computation with 22 thread is 13 milliseconds.
Total duration of the computation with 23 thread is 12 milliseconds.
Total duration of the computation with 24 thread is 12 milliseconds.
Total duration of the computation with 25 thread is 14 milliseconds.
Total duration of the computation with 26 thread is 15 milliseconds.
Total duration of the computation with 27 thread is 18 milliseconds.
Total duration of the computation with 28 thread is 20 milliseconds.
Total duration of the computation with 29 thread is 20 milliseconds.
Total duration of the computation with 30 thread is 15 milliseconds.
Total duration of the computation with 31 thread is 22 milliseconds.
Total duration of the computation with 32 thread is 23 milliseconds.
Total duration of the computation with 33 thread is 17 milliseconds.
Total duration of the computation with 34 thread is 33 milliseconds.
Total duration of the computation with 35 thread is 20 milliseconds.
Total duration of the computation with 36 thread is 27 milliseconds.
Total duration of the computation with 37 thread is 20 milliseconds.
Total duration of the computation with 38 thread is 23 milliseconds.
Total duration of the computation with 39 thread is 26 milliseconds.
Total duration of the computation with 40 thread is 20 milliseconds.
Total duration of the computation with 41 thread is 30 milliseconds.
Total duration of the computation with 42 thread is 22 milliseconds.
Total duration of the computation with 43 thread is 20 milliseconds.
Total duration of the computation with 44 thread is 20 milliseconds.
Total duration of the computation with 45 thread is 20 milliseconds.
Total duration of the computation with 46 thread is 21 milliseconds.
Total duration of the computation with 47 thread is 26 milliseconds.
Total duration of the computation with 48 thread is 22 milliseconds.
Total duration of the computation with 49 thread is 22 milliseconds.
Total duration of the computation with 50 thread is 16 milliseconds.
Total duration of the computation with 51 thread is 14 milliseconds.
Total duration of the computation with 52 thread is 18 milliseconds.
Total duration of the computation with 53 thread is 12 milliseconds.
Total duration of the computation with 54 thread is 20 milliseconds.
Total duration of the computation with 55 thread is 21 milliseconds.
Total duration of the computation with 56 thread is 30 milliseconds.
Total duration of the computation with 57 thread is 30 milliseconds.
Total duration of the computation with 58 thread is 30 milliseconds.
Total duration of the computation with 59 thread is 25 milliseconds.
Total duration of the computation with 60 thread is 15 milliseconds.
Total duration of the computation with 61 thread is 10 milliseconds.
Total duration of the computation with 62 thread is 18 milliseconds.
Total duration of the computation with 63 thread is 12 milliseconds.
Total duration of the computation with 64 thread is 15 milliseconds.

Process finished with exit code 0

For instance, time that is required to perform the task with 7 threads is the same with 64 threads. There is something wrong in there, but I could not manage to fix it. I have tested the program without an iteration already, that is by providing some inputs for the total number of threads manually and nothing has changed. run() function performs a for iteration only and MyThreadClass extends Thread class of Java. I suppose, I need a some sort of mechanism to kill the threads after they have completed, but I suppose joining them already does that. Please point out anything that seems wrong to you. Thanks in advance.

Edit: the loop inside the run() iterates a million times. That is the fixed variable of the experiment you might say.

That's not how you benchmark properly, use a [framework like JMH](https://www.baeldung.com/java-microbenchmark-harness). It's also not how you run concurrent tasks btw, use `ExecutorService` or `CompletableFuture`. — daniu, May 07 '20 at 13:35
By executor service, I have tried [this](https://stackoverflow.com/a/27902237/7941061) approach, if that s what you mean. There was nothing seems wrong in thread outputs but the time was wrong again. — zodiac645, May 07 '20 at 13:44
Again, you can't rely on your numbers at all with the way you measure your time. It's also not clear what you think is wrong exactly; if you expect "the more threads, the better the overall time", you'll be disappointed. — daniu, May 07 '20 at 13:49
I just supposed that 64 threads do better job than 24 threads for example. By better job, I mean less time, but in the output above 24 threads take 12 ms while 64 threads 15 ms. — zodiac645, May 07 '20 at 13:53

kofemann · Answer 1 · 2020-05-07T13:52:37.680

You can create a custom ThreadPoolExecutor That will track each task execution times, something like this:

import java.util.concurrent.BlockingQueue;
import java.util.concurrent.LinkedBlockingDeque;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;

public class TimeTrackingExecutor extends ThreadPoolExecutor  {

    private AtomicLong totalExecutionTime = new AtomicLong();
    ThreadLocal<Long> times = new ThreadLocal<>();

    public TimeTrackingExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
    }

    @Override
    protected void beforeExecute(Thread t, Runnable r) {
        times.set(System.nanoTime());
    }

    @Override
    protected void afterExecute(Runnable r, Throwable t) {
        long delta = System.nanoTime() -  times.get();
        totalExecutionTime.addAndGet(delta);
    }

    public long getTotalExecutionTime() {
        return totalExecutionTime.get();
    }

}

The methods beforeExecute and afterExecute called before and after each tast is started: https://docs.oracle.com/javase/8/docs/api/java/util/concurrent/ThreadPoolExecutor.html

By changing thread pools core/max size you can see the correlation with number of threads.

How to compute the total execution time in multithread application

1 Answers1