Почему cyclicBarrier нельзя получить сразу после выполнения барьерного действия?

Question

Давайте рассмотрим следующий фрагмент кода:

public static void main(String[] args) throws InterruptedException {
    CyclicBarrier cb = new CyclicBarrier(3, () -> {
        logger.info("Barrier action starting");
        try {
            Thread.sleep(5000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        logger.info("Barrier action finishing");
    });
    for (int i = 0; i < 6; i++) {
        int counter = i;
        Thread.sleep(100);
        new Thread(() -> {
            try {
                logger.info("Try to acquire barrier for {}", counter);
                cb.await();
                logger.info("barrier acquired for {}", counter);

            } catch (Exception e) {
                e.printStackTrace();
            }

        }).start();
    }
}

Я создал барьер с размером = 3 и действием барьера, которое занимает 5 секунд.

Я вижу следующий вывод:

2019-10-27 15:23:09.393  INFO   --- [       Thread-0] my.playground.RemoteServiceFacade        : Try to acquire barrier for 0
2019-10-27 15:23:09.492  INFO   --- [       Thread-1] my.playground.RemoteServiceFacade        : Try to acquire barrier for 1
2019-10-27 15:23:09.593  INFO   --- [       Thread-2] my.playground.RemoteServiceFacade        : Try to acquire barrier for 2
2019-10-27 15:23:09.594  INFO   --- [       Thread-2] my.playground.RemoteServiceFacade        : Barrier action starting
2019-10-27 15:23:09.693  INFO   --- [       Thread-3] my.playground.RemoteServiceFacade        : Try to acquire barrier for 3
2019-10-27 15:23:09.794  INFO   --- [       Thread-4] my.playground.RemoteServiceFacade        : Try to acquire barrier for 4
2019-10-27 15:23:09.897  INFO   --- [       Thread-5] my.playground.RemoteServiceFacade        : Try to acquire barrier for 5
2019-10-27 15:23:14.594  INFO   --- [       Thread-2] my.playground.RemoteServiceFacade        : Barrier action finishing
2019-10-27 15:23:14.595  INFO   --- [       Thread-2] my.playground.RemoteServiceFacade        : barrier acquired for 2
2019-10-27 15:23:14.595  INFO   --- [       Thread-5] my.playground.RemoteServiceFacade        : Barrier action starting
2019-10-27 15:23:19.596  INFO   --- [       Thread-5] my.playground.RemoteServiceFacade        : Barrier action finishing
2019-10-27 15:23:19.597  INFO   --- [       Thread-0] my.playground.RemoteServiceFacade        : barrier acquired for 0
2019-10-27 15:23:19.597  INFO   --- [       Thread-4] my.playground.RemoteServiceFacade        : barrier acquired for 4
2019-10-27 15:23:19.597  INFO   --- [       Thread-3] my.playground.RemoteServiceFacade        : barrier acquired for 3
2019-10-27 15:23:19.597  INFO   --- [       Thread-1] my.playground.RemoteServiceFacade        : barrier acquired for 1
2019-10-27 15:23:19.597  INFO   --- [       Thread-5] my.playground.RemoteServiceFacade        : barrier acquired for 5

Итак, мы можем видеть, что:

1. Первое барьерное действие длится 15:23:09 - 15:23:14
2. Второе барьерное действие длится 15:23: 14 - 15: 23: 19

Но только один поток смог войти в систему после завершения первого барьерного действия:

2019-10-27 15:23:14.595  INFO   --- [       Thread-2] my.playground.RemoteServiceFacade        : barrier acquired for 2

Я ожидал, что 3 потока смогут получить приблизительнов 15:23:14, поскольку размер CyclicBarrier равен 3.

Не могли бы вы объяснить это поведение?

PS

Я пытался запустить этот кодмного времени и всегда похожий результат.

PS2.

Я попытался немного изменить время:

public static void main(String[] args) throws InterruptedException {
    CyclicBarrier cb = new CyclicBarrier(3, () -> {
        logger.info("Barrier action starting");
        try {
            Thread.sleep(500);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        logger.info("Barrier action finishing");
    });
    for (int i = 0; i < 6; i++) {
        int counter = i;
        Thread.sleep(1000);
        new Thread(() -> {
            try {
                logger.info("Try to acquire barrier for {}", counter);
                cb.await();
                logger.info("barrier acquired for {}", counter);

            } catch (Exception e) {
                e.printStackTrace();
            }

        }).start();
    }
}

И я вижу ожидаемые результаты:

2019-10-27 23:22:14.497  INFO   --- [       Thread-0] my.playground.RemoteServiceFacade        : Try to acquire barrier for 0
2019-10-27 23:22:15.495  INFO   --- [       Thread-1] my.playground.RemoteServiceFacade        : Try to acquire barrier for 1
2019-10-27 23:22:16.495  INFO   --- [       Thread-2] my.playground.RemoteServiceFacade        : Try to acquire barrier for 2
2019-10-27 23:22:16.496  INFO   --- [       Thread-2] my.playground.RemoteServiceFacade        : Barrier action starting
2019-10-27 23:22:16.998  INFO   --- [       Thread-2] my.playground.RemoteServiceFacade        : Barrier action finishing
2019-10-27 23:22:16.998  INFO   --- [       Thread-0] my.playground.RemoteServiceFacade        : barrier acquired for 0
2019-10-27 23:22:16.998  INFO   --- [       Thread-2] my.playground.RemoteServiceFacade        : barrier acquired for 2
2019-10-27 23:22:16.998  INFO   --- [       Thread-1] my.playground.RemoteServiceFacade        : barrier acquired for 1
2019-10-27 23:22:17.495  INFO   --- [       Thread-3] my.playground.RemoteServiceFacade        : Try to acquire barrier for 3
2019-10-27 23:22:18.495  INFO   --- [       Thread-4] my.playground.RemoteServiceFacade        : Try to acquire barrier for 4
2019-10-27 23:22:19.496  INFO   --- [       Thread-5] my.playground.RemoteServiceFacade        : Try to acquire barrier for 5
2019-10-27 23:22:19.499  INFO   --- [       Thread-5] my.playground.RemoteServiceFacade        : Barrier action starting
2019-10-27 23:22:20.002  INFO   --- [       Thread-5] my.playground.RemoteServiceFacade        : Barrier action finishing
2019-10-27 23:22:20.003  INFO   --- [       Thread-5] my.playground.RemoteServiceFacade        : barrier acquired for 5
2019-10-27 23:22:20.003  INFO   --- [       Thread-3] my.playground.RemoteServiceFacade        : barrier acquired for 3
2019-10-27 23:22:20.003  INFO   --- [       Thread-4] my.playground.RemoteServiceFacade        : barrier acquired for 4

Answer 1

Захватывающий вопрос, это не супер тривиально, но я постараюсь объяснить это как можно более кратко.

Хотя многопоточность не гарантирует какого-либо порядка выполнения, для этого ответа давайте представим, что сначала происходят две последовательности:

1. Все потоки запускаются в одно и то же время
2. Все потоки одновременно вызывают barrier.await().

В этом случае вы увидите вывод типа

Try to acquire barrier for 0
Try to acquire barrier for 1
Try to acquire barrier for 2
Try to acquire barrier for 3
Try to acquire barrier for 4
Try to acquire barrier for 5

Текущее состояние ваших 6 потоковследующие:

1. Потоки 0 и 1 await на общем Condition, поскольку три потока еще не достигли барьера "пока"

2. Нить 2 по-прежнему работает в качестве нити "отключения" для барьера

3. Потоки 3, 4 и 5 будут ожидать наlock.lock вызов барьера (тот же экземпляр Lock, в котором был создан Condition.

Когда барьер видит нить 2, он ранее записал 0 и1 как достигнув барьера, так что он знает, что этот цикл завершен и выпустит 0 и 1. Но перед тем, как освободить два других потока, ему нужно запустить barrierAction, который вы определили как спящий, на 5 секунд, и он это сделает.

Затем вы увидите вывод

Barrier action starting
Barrier action finishing

Поток 2 все еще удерживает блокировку, равен RUNNABLE и готов к выходу из барьера, так что он делает это, и вы видите этоoutput.

barrier acquired for 2

Но до того, как существует поток 2, он будет сигнализировать всем другим потокам, ожидающим текущий барьер. Вот где это становится сложнее, await на 0 и 1 делается на общем Condition. Condition является общим для всех барьерных «поколений». Таким образом, несмотря на то, что первые два потока await предшествовали вторым 3 потокам lock, когда signalAll завершено, потоки первого поколения все еще должны ждать своей очереди на пробуждение.

На данный момент у нас есть 5 потоков в состоянии BLOCKED (3, 4 и 5) или TIMED_WAITING (0, 1). В этом примере важно время, когда они блокируют / ждут на Lock. Если все они происходят в том порядке, в котором очередь для критической секции была бы:

Thread-0 -> Thread-1 -> Thread-5 -> Thread-4 -> Thread-3 
   |                                               |
  TAIL                                            HEAD

, так что следующие освобожденные потоки будут Thread-3, затем 4, а затем 5. Причина, по которой эта очередь выглядит так, заключается в том, что все потоки достигают lock одновременно, и все они в очереди, потоки 0 и 1, очевидно, сначала достигают его и, таким образом, попадают в критическую секцию барьера, но затемawait в то время как поток 2 входит, чтобы разбудить их, но теперь 0 и 1 помещаются в конец очереди, и 3, 4 и 5 будут вызваны следующими.

Когдапоток 2 покидает барьер, и signalAll потоки 3 и 4 будут работать, и, поскольку они являются частью второго поколения, будут приостановлены, пока поток 5 не пройдет и не запустит действие barrier. Затем он печатает

Barrier action starting
Barrier action finishing

Наконец, поток 5 снова будет signalAll, а остальные потоки завершатся.

В этом случае вы увидите поток 5 Первый завершен, а остальные следуют

barrier acquired for 5
barrier acquired for 0
barrier acquired for 1
barrier acquired for 3
barrier acquired for 4