Странное поведение на солнце.разное.Опасный.измерение compareAndSwap через JMH


Я решил измерить инкрементацию с помощью различных стратегий блокировки и использовать для этой цели JMH. Я использую JMH для проверки пропускной способности и среднего времени, а также простой пользовательский тест для проверки правильности. Существует шесть стратегий:

  • число атомов
  • число блокировок ReadWrite
  • синхронизация с volatile
  • блок синхронизации без volatile
  • солнце.разное.Опасный.compareAndSwap
  • солнце.разное.Опасный.getAndAdd
  • отсчет Несинхронизации

Эталонный код:

@State(Scope.Benchmark)
@BenchmarkMode({Mode.Throughput, Mode.AverageTime})
@OutputTimeUnit(TimeUnit.MICROSECONDS)
@Fork(1)
@Warmup(iterations = 5)
@Measurement(iterations = 5)
public class UnsafeCounter_Benchmark {
    public Counter unsync, syncNoV, syncV, lock, atomic, unsafe, unsafeGA;

    @Setup(Level.Iteration)
    public void prepare() {
        unsync = new UnsyncCounter();
        syncNoV = new SyncNoVolatileCounter();
        syncV = new SyncVolatileCounter();
        lock = new LockCounter();
        atomic = new AtomicCounter();
        unsafe = new UnsafeCASCounter();
        unsafeGA = new UnsafeGACounter();
    }

    @Benchmark
    public void unsyncCount() {
        unsyncCounter();
    }

    @CompilerControl(CompilerControl.Mode.DONT_INLINE)
    public void unsyncCounter() {
        unsync.increment();
    }

    @Benchmark
    public void syncNoVCount() {
        syncNoVCounter();
    }

    @CompilerControl(CompilerControl.Mode.DONT_INLINE)
    public void syncNoVCounter() {
        syncNoV.increment();
    }

    @Benchmark
    public void syncVCount() {
        syncVCounter();
    }

    @CompilerControl(CompilerControl.Mode.DONT_INLINE)
    public void syncVCounter() {
        syncV.increment();
    }

    @Benchmark
    public void lockCount() {
        lockCounter();
    }

    @CompilerControl(CompilerControl.Mode.DONT_INLINE)
    public void lockCounter() {
        lock.increment();
    }

    @Benchmark
    public void atomicCount() {
        atomicCounter();
    }

    @CompilerControl(CompilerControl.Mode.DONT_INLINE)
    public void atomicCounter() {
        atomic.increment();
    }

    @Benchmark
    public void unsafeCount() {
        unsafeCounter();
    }

    @CompilerControl(CompilerControl.Mode.DONT_INLINE)
    public void unsafeCounter() {
        unsafe.increment();
    }

    @Benchmark
    public void unsafeGACount() {
        unsafeGACounter();
    }

    @CompilerControl(CompilerControl.Mode.DONT_INLINE)
    public void unsafeGACounter() {
        unsafeGA.increment();
    }

    public static void main(String[] args) throws RunnerException {
        Options baseOpts = new OptionsBuilder()
                .include(UnsafeCounter_Benchmark.class.getSimpleName())
                .threads(100)
                .jvmArgs("-ea")
                .build();

        new Runner(baseOpts).run();
    }
}

И результаты стендовых испытаний:

JDK 8u20

Benchmark                                         Mode  Samples   Score    Error   Units
o.k.u.u.UnsafeCounter_Benchmark.atomicCount      thrpt        5  42.178 ± 17.643  ops/us
o.k.u.u.UnsafeCounter_Benchmark.lockCount        thrpt        5  24.044 ±  2.264  ops/us
o.k.u.u.UnsafeCounter_Benchmark.syncNoVCount     thrpt        5  22.849 ±  1.344  ops/us
o.k.u.u.UnsafeCounter_Benchmark.syncVCount       thrpt        5  20.235 ±  2.027  ops/us
o.k.u.u.UnsafeCounter_Benchmark.unsafeCount      thrpt        5  12.460 ±  1.326  ops/us
o.k.u.u.UnsafeCounter_Benchmark.unsafeGACount    thrpt        5  39.106 ±  2.966  ops/us
o.k.u.u.UnsafeCounter_Benchmark.unsyncCount      thrpt        5  93.076 ±  9.674  ops/us
o.k.u.u.UnsafeCounter_Benchmark.atomicCount       avgt        5   2.604 ±  0.133   us/op
o.k.u.u.UnsafeCounter_Benchmark.lockCount         avgt        5   4.161 ±  0.546   us/op
o.k.u.u.UnsafeCounter_Benchmark.syncNoVCount      avgt        5   4.440 ±  0.523   us/op
o.k.u.u.UnsafeCounter_Benchmark.syncVCount        avgt        5   5.073 ±  0.439   us/op
o.k.u.u.UnsafeCounter_Benchmark.unsafeCount       avgt        5   9.088 ±  5.964   us/op
o.k.u.u.UnsafeCounter_Benchmark.unsafeGACount     avgt        5   2.611 ±  0.164   us/op
o.k.u.u.UnsafeCounter_Benchmark.unsyncCount       avgt        5   1.047 ±  0.050   us/op

Большая часть измерения, как я ожидаю, за исключением UnsafeCounter_Benchmark.unsafeCount, который используется sun.misc.Unsafe.compareAndSwapLong с while петлей. Это самая медленная блокировка.

public void increment() {
    long before = counter;
    while (!unsafe.compareAndSwapLong(this, offset, before, before + 1L)) {
        before = counter;
    }
}

Я предполагаю, что низкая производительность связана с циклом while и JMH делает более высокую конкуренцию, но когда я проверил правильность по Executors, я получаю цифры, как я ожидайте:

Counter result: UnsyncCounter 97538676
Time passed in ms:259
Counter result: AtomicCounter 100000000
Time passed in ms:1805
Counter result: LockCounter 100000000
Time passed in ms:3904
Counter result: SyncNoVolatileCounter 100000000
Time passed in ms:14227
Counter result: SyncVolatileCounter 100000000
Time passed in ms:19224
Counter result: UnsafeCASCounter 100000000
Time passed in ms:8077
Counter result: UnsafeGACounter 100000000
Time passed in ms:2549

Код проверки корректности:

public class UnsafeCounter_Test {
    static class CounterClient implements Runnable {
        private Counter c;
        private int num;

        public CounterClient(Counter c, int num) {
            this.c = c;
            this.num = num;
        }

        @Override
        public void run() {
            for (int i = 0; i < num; i++) {
                c.increment();
            }
        }
    }

    public static void makeTest(Counter counter) throws InterruptedException {
        int NUM_OF_THREADS = 1000;
        int NUM_OF_INCREMENTS = 100000;
        ExecutorService service = Executors.newFixedThreadPool(NUM_OF_THREADS);
        long before = System.currentTimeMillis();
        for (int i = 0; i < NUM_OF_THREADS; i++) {
            service.submit(new CounterClient(counter, NUM_OF_INCREMENTS));
        }
        service.shutdown();
        service.awaitTermination(1, TimeUnit.MINUTES);
        long after = System.currentTimeMillis();
        System.out.println("Counter result: " + counter.getClass().getSimpleName() + " " + counter.getCounter());
        System.out.println("Time passed in ms:" + (after - before));
    }

    public static void main(String[] args) throws InterruptedException {
        makeTest(new UnsyncCounter());
        makeTest(new AtomicCounter());
        makeTest(new LockCounter());
        makeTest(new SyncNoVolatileCounter());
        makeTest(new SyncVolatileCounter());
        makeTest(new UnsafeCASCounter());
        makeTest(new UnsafeGACounter());
    }
}
Я знаю, что это очень ужасный тест, но в этом случае небезопасный CAS в два раза быстрее, чем варианты синхронизации, и все идет, как и ожидалось. Может ли кто-нибудь прояснить описанное поведение? Дополнительную информацию смотрите в разделе GitHub repo: Bench, небезопасный счетчик CAS
1 5

1 ответ:

Поразительно, как часто люди делают 90% утомительной работы, а 10% (где начинается самое интересное) оставляют для кого-то другого! Ладно, я беру все веселье на себя!

Позвольте мне повторить эксперимент сначала на моем i7-4790K, 8U40 EA:
Benchmark                                 Mode  Samples    Score    Error   Units
UnsafeCounter_Benchmark.atomicCount      thrpt        5   47.669 ± 18.440  ops/us
UnsafeCounter_Benchmark.lockCount        thrpt        5   14.497 ±  7.815  ops/us
UnsafeCounter_Benchmark.syncNoVCount     thrpt        5   11.618 ±  2.130  ops/us
UnsafeCounter_Benchmark.syncVCount       thrpt        5   11.337 ±  4.532  ops/us
UnsafeCounter_Benchmark.unsafeCount      thrpt        5    7.452 ±  1.042  ops/us
UnsafeCounter_Benchmark.unsafeGACount    thrpt        5   43.332 ±  3.435  ops/us
UnsafeCounter_Benchmark.unsyncCount      thrpt        5  102.773 ± 11.943  ops/us

Действительно, что-то кажется подозрительным в unsafeCount тесте. На самом деле, вы должны предполагать, что все данные являются подозрительными, прежде чем вы проверили их. Для nanobenchmarks вам нужно проверить сгенерированный код, чтобы увидеть, действительно ли вы что-то измеряете. хотите измерить. В JMH это очень быстро выполнимо С -prof perfasm. На самом деле, если вы посмотрите на самую горячую область unsafeCount там, вы заметите несколько забавных вещей:

  0.12%    0.04%    0x00007fb45518e7d1: mov    0x10(%r10),%rax    
 17.03%   23.44%    0x00007fb45518e7d5: test   %eax,0x17318825(%rip)
  0.21%    0.07%    0x00007fb45518e7db: mov    0x18(%r10),%r11    ; getfield offset
 30.33%   10.77%    0x00007fb45518e7df: mov    %rax,%r8
  0.00%             0x00007fb45518e7e2: add    $0x1,%r8           
  0.01%             0x00007fb45518e7e6: cmp    0xc(%r10),%r12d    ; typecheck 
                    0x00007fb45518e7ea: je     0x00007fb45518e80b ; bail to v-call
  0.83%    0.48%    0x00007fb45518e7ec: lock cmpxchg %r8,(%r10,%r11,1)
 33.27%   25.52%    0x00007fb45518e7f2: sete   %r8b
  0.12%    0.01%    0x00007fb45518e7f6: movzbl %r8b,%r8d          
  0.03%    0.04%    0x00007fb45518e7fa: test   %r8d,%r8d
                    0x00007fb45518e7fd: je     0x00007fb45518e7d1 ; back branch

Перевод: а) offset поле перечитывается на каждой итерации-потому что эффекты памяти CAS подразумевают неустойчивое чтение, и поэтому поле должно быть пессимистично перечитано; б) веселая часть состоит в том, что unsafe полетакже перечитывается для проверки типа-по той же причине.

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

--- a/utils bench/src/main/java/org/kirmit/utils/unsafe/concurrency/UnsafeCASCounter.java       
+++ b/utils bench/src/main/java/org/kirmit/utils/unsafe/concurrency/UnsafeCASCounter.java       
@@ -5,13 +5,13 @@ import sun.misc.Unsafe;

 public class UnsafeCASCounter implements Counter {
     private volatile long counter = 0;
-    private final Unsafe unsafe = UnsafeHelper.unsafe;
-    private long offset;
-    {
+    private static final Unsafe unsafe = UnsafeHelper.unsafe;
+    private static final long offset;
+    static {
         try {
             offset = unsafe.objectFieldOffset(UnsafeCASCounter.class.getDeclaredField("counter"));
         } catch (NoSuchFieldException e) {
-            e.printStackTrace();
+            throw new IllegalStateException("Whoops!");
         }
     }

Если вы сделаете это, производительность unsafeCount повысится:

Benchmark                              Mode  Samples   Score    Error   Units
UnsafeCounter_Benchmark.unsafeCount    thrpt        5  9.733 ± 0.673  ops/us

...что сейчас довольно близко к синхронизированным тестам, учитывая границы ошибок. Если вы посмотрите на -prof perfasm сейчас, это цикл unsafeCount:

  0.08%    0.02%    0x00007f7575191900: mov    0x10(%r10),%rax       
 28.09%   28.64%    0x00007f7575191904: test   %eax,0x161286f6(%rip) 
  0.23%    0.08%    0x00007f757519190a: mov    %rax,%r11
                    0x00007f757519190d: add    $0x1,%r11
                    0x00007f7575191911: lock cmpxchg %r11,0x10(%r10)
 47.27%   23.48%    0x00007f7575191917: sete   %r8b
  0.10%             0x00007f757519191b: movzbl %r8b,%r8d        
  0.02%             0x00007f757519191f: test   %r8d,%r8d
                    0x00007f7575191922: je     0x00007f7575191900  
Эта петля очень тугая, и кажется, что ничто не может заставить ее идти быстрее. Большую часть времени мы тратим на загрузку "обновленного" значения и его фактическое использование. Но мы много спорим! Чтобы выяснить, является ли конкуренция ведущая причина, давайте добавим отступления:
--- a/utils bench/src/main/java/org/kirmit/utils/unsafe/concurrency/UnsafeCASCounter.java       
+++ b/utils bench/src/main/java/org/kirmit/utils/unsafe/concurrency/UnsafeCASCounter.java       
@@ -20,6 +21,7 @@ public class UnsafeCASCounter implements Counter {
         long before = counter;
         while (!unsafe.compareAndSwapLong(this, offset, before, before + 1L)) {
             before = counter;
+            Blackhole.consumeCPU(1000);
         }
     }

...работает:

Benchmark                                 Mode  Samples    Score    Error   Units
UnsafeCounter_Benchmark.unsafeCount      thrpt        5   99.869 ± 107.933  ops/us

Вуаля. Мы делаем больше работы в цикле, но это избавляет нас от борьбы много. Я пытался объяснить это раньше в "Nanotrusting The Nanotime", было бы неплохо вернуться туда и прочитать больше о методологии бенчмаркинга, особенно когда измеряются операции с большим весом. Это подчеркивает ловушку во всем эксперименте, а не только с unsafeCount.

Упражнение для ОП и заинтересованные читатели: объясните, почему unsafeGACount и atomicCount выполняют гораздо быстрее, чем другие тесты. Теперь у тебя есть инструменты.

P.S. запускать N потоков на машине, имеющей C (C Проверка времени: 10 минут на профилирование и дополнительные эксперименты, 20 минут на запись. вверх. И сколько времени вы потратили на воспроизведение результата вручную? ;)