Странное поведение на солнце.разное.Опасный.измерение 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 ответ:
Поразительно, как часто люди делают 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 минут на запись. вверх. И сколько времени вы потратили на воспроизведение результата вручную? ;)