Java multithreading (locks and synchronization)

Question

I am trying to apply a synchronized block with locks from some old tutorials. The app takes 2 seconds on tutorial, but mine has 4 seconds because of the Thread.sleep(1) part. I don't know why 1ms makes a 2 seconds difference. Without sleeping my code just takes 2ms, is it the JVM version? What am I missing?

worker worker = new worker();
Thread t1 = new Thread(worker::process);
Thread t2 = new Thread(worker::process);

long startThreads = System.currentTimeMillis();

t1.start();
t2.start();

try {
    t1.join();
    t2.join();
} catch (InterruptedException e) {
    e.printStackTrace();
}
long end = System.currentTimeMillis();
System.out.println("Time taken: " + (end - startThreads) + " ms");

class worker {
    ArrayList<Integer> list1 = new ArrayList<>();
    ArrayList<Integer> list2 = new ArrayList<>();
    final Object lock1 = new Object();
    final Object lock2 = new Object();
    Random random = new Random();
    public void stage1() {
        synchronized (lock1) {
            try {
                Thread.sleep(1);
            } catch (InterruptedException e) {
                throw new RuntimeException(e);
            }

            list1.add(random.nextInt(100));
        }
    }

    public void stage2() {
        synchronized (lock2) {
            try {
                Thread.sleep(1);
            } catch (InterruptedException e) {
                throw new RuntimeException(e);
            }
            list2.add(random.nextInt(100));

        }
    }

    public void process() {
        for (int i = 0; i < 1000; i++) {
            stage1();
            stage2();
        }
    }

    public void processsequntially() {
        for (int i = 0; i < 1000; i++) {
            stage1();
            stage2();
        }
    }

}

update when the loop goes 1 time i had solid 6~8 ms !!

public void process() {
        for (int i = 0; i < 1; i++) {
            stage1();
            stage2();
        }}

Answer 1

I can reproduce what you are seeing, ie around 4 seconds total running time. Note however that I observed less than (but close to) 4000ms at some point! If the code was running sequentially 4000 times the Thread.sleep(1) call, then it should have always overshoot 4 seconds (assuming Thread.sleep lasts for at least the given amount of time). So, before trying to figure out why they are running sequentially (if at all), I did some more tests to see if 4 seconds scale per Thread.sleep millisecond...

Running your code with 10ms sleep delay in both stageN methods prints:

Time taken: 31791 ms

Which is almost 32 seconds and not 40+ as one would expect if they thought that 4 seconds scale per millisecond delay.

Running your code with 100ms sleep delay in both stageN methods prints:

Time taken: 217190 ms

Which is almost 217 seconds and not 400+ as one would expect if they thought that 4 seconds scale per millisecond delay.

Both measurements were taken only once each (and only on my system of course), but this shows that as we increase the delay in Thread.sleep the time taken per millisecond indeed tends to 2 and not 4 seconds.

This suggests that there is a submillisecond delay incurred elsewhere in the code. According to the documentation of Thread.sleep, its accuracy is "subject to the precision and accuracy of system timers and schedulers" so it may be just that the incurred delay is also because of sleep.

For reference, follows the code executed for the latter case (100ms delay):

import java.util.ArrayList;
import java.util.Random;

public class Main {

    public static class Worker {

        ArrayList<Integer> list1 = new ArrayList<>();
        ArrayList<Integer> list2 = new ArrayList<>();
        final Object lock1 = new Object();
        final Object lock2 = new Object();
        Random random = new Random();

        public void stage1() {
            synchronized (lock1) {
                try {
                    Thread.sleep(100);
                } catch (InterruptedException e) {
                    throw new RuntimeException(e);
                }

                list1.add(random.nextInt(100));
            }
        }

        public void stage2() {
            synchronized (lock2) {
                try {
                    Thread.sleep(100);
                } catch (InterruptedException e) {
                    throw new RuntimeException(e);
                }
                list2.add(random.nextInt(100));

            }
        }

        public void process() {
            for (int i = 0; i < 1000; i++) {
                stage1();
                stage2();
            }
        }

        public void processsequntially() {
            for (int i = 0; i < 1000; i++) {
                stage1();
                stage2();
            }
        }
    }

    public static void main(final String[] args) {
        Worker worker = new Worker();
        Thread t1 = new Thread(worker::process);
        Thread t2 = new Thread(worker::process);

        long startThreads = System.currentTimeMillis();

        t1.start();
        t2.start();

        try {
            t1.join();
            t2.join();
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        long end = System.currentTimeMillis();
        System.out.println("Time taken: " + (end - startThreads) + " ms");
    }
}

Also a quote from the documentation of Random:

Instances of java.util.Random are threadsafe. However, the concurrent use of the same java.util.Random instance across threads may encounter contention and consequent poor performance.

Which, as far as I understand, further explains the incurred system delays and inaccuracies of the code runs (we are using a single Random instance for both Threads).