synchronized keyword is giving the expected output but not satisfied with the order in which the method is called by different threads

Question

Below are my 3 classes(threads) implementing Runnable interface:

public class Thread1 implements Runnable {
Shared s;

public Thread1(Shared s){
    this.s = s;
}

@Override   
public void run() {
    System.out.println("Sum of 10 and 20 by " + Thread.currentThread().getName() + " is "+ s.add(10, 20));
}

}

public class Thread2 implements Runnable {
Shared s;

public Thread2(Shared s){
    this.s = s;
}
    
@Override
public void run() {
    System.out.println("Sum of 100 and 200 by " + Thread.currentThread().getName() + " is " + s.add(100, 200));
}

}

public class Thread3 implements Runnable {
Shared s;

public Thread3(Shared s){
    this.s = s;
}
    
@Override
public void run() {
    System.out.println("Sum of 1000 and 2000 by " + Thread.currentThread().getName() + " is " + s.add(1000, 2000));
}

}

And below is the class whose object is shared among these threads:

public class Shared {
private int x;
private int y;

synchronized public int add(int a, int b) {
    x = a;
    y = b;

    try {
        System.out.println(Thread.currentThread().getName() + "is going into sleep state");
        Thread.sleep(1000);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
    return x + y;
}

}

And finally this is how I'm starting threads and passing Shared object:

    public static void main(String[] args) {
    Shared s = new Shared();
    Thread t1 = new Thread(new Thread1(s), "Thread-1");
    Thread t2 = new Thread(new Thread2(s), "Thread-2");
    Thread t3 = new Thread(new Thread3(s), "Thread-3");
    
    t1.start();
    t2.start();
    t3.start();
}

This is the output I'm getting which is correct:

      Thread-2is going into sleep state
      Thread-1is going into sleep state
      Sum of 100 and 200 by Thread-2 is 300
      Thread-3is going into sleep state
      Sum of 10 and 20 by Thread-1 is 30
      Sum of 1000 and 2000 by Thread-3 is 3000

But if you see here, Thread-1 started executing the add method(which is synchronized) before Thread-2 finished its job. Since Thread-2 went into sleep state so it also took the lock with itself and no other thread should be allowed to enter the add(...) method. Thread-1 or Thread-3 could only start executing add(...) method after Thread-2 is done. So, the output I was expecting was :

      Thread-2is going into sleep state
      Sum of 100 and 200 by Thread-2 is 300
      Thread-1is going into sleep state
      Sum of 10 and 20 by Thread-1 is 30
      Thread-3is going into sleep state
      Sum of 1000 and 2000 by Thread-3 is 3000

Please tell what I'm doing wrong or this is how the output will be, if yes, please tell why.

Looks fine / synchronized. It's just printing the next "going to sleep" before the sum. If you want to ensure that the sum is printed first, you should add a synchronized (shared) { ...} block around Shared.add and the printout — ControlAltDel, Aug 03 '20 at 20:01
Yes, I was going to try synchronized(shared){...} but I wanted to know why synchronized keyword let another thread execute the method while the first thread was not done. — Abhishek Tomar, Aug 03 '20 at 20:14
Your code that prints the sum in run() method is not synchronized. That is why you can have "unexpected" order of printing, that doesn't imply that synchronization of add() isn't working. — suff, Aug 04 '20 at 08:23

score 2 · Answer 1 · answered Aug 03 '20 at 20:11

The reason is that the System.out.println() is very slow.

You use it to send messages from both within the run() methods and also from within add(). There is no guarantee that the messages in sysout coincide.

I have rewritten Shared as follows:

public class Shared {
    private int x;
    private int y;

    synchronized public int add(int a, int b) {
        x = a;
        y = b;

        try {
            long now = System.currentTimeMillis() - start;

            Thread.sleep(1000);

            // notice FIRST sleep and THEN sysout
            System.out.println(Thread.currentThread().getName() + " calculation has taken place at time " + now);

        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        return x + y;
    }

    public static long start;

    public static void main(String[] args) {

        start = System.currentTimeMillis();

        Shared s = new Shared();
        Thread t1 = new Thread(new Thread1(s), "Thread-1");
        Thread t2 = new Thread(new Thread2(s), "Thread-2");
        Thread t3 = new Thread(new Thread3(s), "Thread-3");

        t1.start();
        t2.start();
        t3.start();
    }
}

with each of the threads now looking like:

public class Thread1 implements Runnable {
    Shared s;

    public Thread1(Shared s) {
        this.s = s;
    }

    @Override
    public void run() {
        int result = s.add(10, 20);
        long now= System.currentTimeMillis()-Shared.start;
        System.out.println("Sum of 10 and 20 by " + Thread.currentThread().getName() + " is " + result+ " found at "+ now);
    }
}

generating the following output:

Thread-1 calculation has taken place at time 2
Sum of 10 and 20 by Thread-1 is 30 found at 1005
Thread-2 calculation has taken place at time 1005
Sum of 100 and 200 by Thread-2 is 300 found at 2006
Thread-3 calculation has taken place at time 2006
Sum of 1000 and 2000 by Thread-3 is 3000 found at 3007

each thread blocked in add() as it should.

Only when later the result is displayed, the next thread has already started calculating.

Notice that add() now there is first the sysout (which is slow) and it happens during the sleep, which gives it enough time.

Thank you, but I don't understand how the slowness of System.out.println is affecting my program and what do you mean by "There is no guarantee that the messages in sysout coincide."? Please clearify. — Abhishek Tomar, Aug 04 '20 at 05:56
It is because the message from the next thread's execution comes before the completion message of your previous thread. By delaying the message in add(), we give the previous thread time to send its message from run(). — aheger24, Aug 04 '20 at 08:58
Thank you, I get it now. I implemented your solution and now I understand how it's working — Abhishek Tomar, Aug 04 '20 at 09:44

Arvind Kumar Avinash · Accepted Answer · 2020-08-03T20:29:18.527

1

You need to synchronize s as shown below:

@Override
public void run() {
    synchronized (s) {
        System.out.println("Sum of 10 and 20 by " + Thread.currentThread().getName() + " is " + s.add(10, 20));
    }
}

Do this in the classes, Thread2 and Thread3 as well. Check this for an explanation.

edited Aug 03 '20 at 20:29

answered Aug 03 '20 at 20:18

Arvind Kumar Avinash

71,965
6
74
110

Thanks, this solved my problem. Using the code you mentioned, I don't need to make add(...) synchronized. – Abhishek Tomar Aug 04 '20 at 09:01

synchronized keyword is giving the expected output but not satisfied with the order in which the method is called by different threads

2 Answers2