Ключевое слово synchronized дает ожидаемый результат, но его не устраивает порядок, в котором метод вызывается разными потоками

Question

Ниже приведены мои 3 класса (потока), реализующие интерфейс Runnable:

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));
}

}

И ниже показан класс, объект которого является общим для этих потоков:

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;
}

}

И, наконец, вот как я запускаю потоки и передаю общий объект:

    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();
}

Это правильный вывод, который я получаю:

      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

Но если вы видите здесь, Thread-1 начал выполнять метод добавления (который синхронизирован) до того, как Thread-2 завершил его работа. Поскольку поток-2 перешел в состояние сна, он также взял блокировку с собой, и никакому другому потоку не должно быть разрешено вводить метод add (...). Thread-1 или Thread-3 могут начать выполнение метода add (...) только после завершения Thread-2. Итак, результат, которого я ожидал, был:

      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

Пожалуйста, скажите, что я делаю не так, или каким будет результат, если да, расскажите, почему.

Answer 1

Причина в том, что System.out.println() работает очень медленно.

Вы используете его для отправки сообщений как из методов run (), так и изнутри add(). Нет никакой гарантии, что сообщения в sysout совпадают.

Я переписал Shared следующим образом:

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();
    }
}

с каждым из потоков, который теперь выглядит так:

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);
    }
}

генерирует следующий вывод:

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

каждый поток заблокирован в add() как следует.

Только когда результат отображается позже, следующий поток уже начал вычисление.

Обратите внимание, что add() теперь сначала идет sysout (который медленный), и это происходит во время сна, что дает ему достаточно времени.

Answer 2

Вам необходимо синхронизировать s, как показано ниже:

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

Сделайте это в классах, Thread2 и Thread3. Проверьте здесь для объяснения.