Java Microbenchmark Harness – JMH

12 grudnia 2019marcin warycha - javaleader.plBez kategorii, Wpisy z kodem na GitHub0

Java Microbenchmark Harness – JMH

JMH (z ang. Java Microbenchmark Harness) to narzędzie do badania wydajności aplikacji napisanych w Javie. Badanie wydajności aplikacji pozwala odpowiedzieć m.in. na następujące pytania:

czy zastosowane rozwiązanie (algorytm) nie trwa zbyt długo?
jaka jest różnica w wydajności dla różnych implementacji danego problemu?
o ile wzrosła szybkość działania aplikacji po jej refaktoringu?

Czym jest benchmark?

Benchmark to test wzorcowy którego zadaniem jest porównanie wydajności różnych procesów. Wyniki testu wzorcowego dają informacje które procesy należy zoptymalizować. Mając dwa rozwiązania danego problemu łatwo można stwierdzić które z nich jest lepsze poddając je tym samym testom porównawczym. W pierwszej kolejności dokonywana jest przez narzędzie JMH tzw. rozgrzewka w której to nie następuje jeszcze odpowiedni pomiar. Celem rozgrzewki jest np. załadowanie przez JVM wszystkich potrzebnych klas. Następnie dokonywany jest dopiero właściwy pomiar według zdefiniowanych przez odpowiednie adnotacje parametrów.

Tworzymy nową aplikację Spring Boota – plik pom.xml – niezbędne zależności:

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-core</artifactId>
    <version>1.19</version>
</dependency>
<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-generator-annprocess</artifactId>
    <version>1.19</version>
</dependency>

Przetestujmy wydajność dwóch algorytmów do obliczania silni – algorytmu iteracyjnego oraz algorytmu rekurencyjnego:

Poniżej klasa która zawiera implementację dwóch typów algorytmów do obliczania silni – pytanie który z nich jest szybszy?

public class Factorial {
    public static int getFactorialFor(int number) {
        int factorial = 1;
        for (int i = 2; i <= number; i++) {
            factorial *= i;
        }
        return factorial;
    }
    public static int getFactorialRec(int number) {
        if (number == 0) {
            return 1;
        } else {
            return number * getFactorialRec(number-1);
        }
    }
}

Przykładowe testy benchmarkowe:

public class BenchmarkFactorial {
 
    private static final int SMALL_NUMBER = 4;
    private static final int LONG_NUMBER  = 100;
 
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 4)
    @Warmup(iterations = 3, time = 1)
    @Measurement(iterations = 5, time = 2)
    public int testFactorialWithLoopForWithSmallNumber() {
        return Factorial.getFactorialFor(SMALL_NUMBER);
    }
 
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 4)
    @Warmup(iterations = 3, time = 1)
    @Measurement(iterations = 5, time = 2)
    public int testFactorialWithRecursiveMethodWithSmallNumber() {
        return Factorial.getFactorialRec(SMALL_NUMBER);
    }
 
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 4)
    @Warmup(iterations = 3, time = 1)
    @Measurement(iterations = 5, time = 2)
    public int testFactorialWithLoopForWithLongNumber() {
        return Factorial.getFactorialFor(LONG_NUMBER);
    }
 
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 4)
    @Warmup(iterations = 3, time = 1)
    @Measurement(iterations = 5, time = 2)
    public int testFactorialWithRecursiveMethodWithLongNumber() {
        return Factorial.getFactorialRec(LONG_NUMBER);
    }
}

Wyjaśnienie użytych w testach adnotacji:

@Benchmark – wskazuje na metody, które są poddane analizie,
@BenchmarkMode(Mode.AverageTime) – tryb przeprowadzania testu benchmarkowego, wyróżniamy następujące tryby:
- Throughput – przepustowość – ile razy kod da radę wykonać się w ciągu sekundy,
- AverageTime – średni czas ze wszystkich prób, jaki był potrzebny na wykonanie kodu,
- Sample Time – statystyczne podejście do mierzenia czasu wykonania, wraz z podziałem na histogram oraz percentyle,
- Single Shot Time – ile czasu zajmie wykonanie benchmarku za pierwszym razem – bez rozgrzewki – Java warm-up,
- All – wszystkie powyższe tryby razem.
@OutputTimeUnit(TimeUnit.MICROSECONDS) – jednostka czasu w jakiej zostaną zaprezentowane wyniki,
@Fork(value = 1, warmups = 4) – value to ilość procesów w których uruchamiane są testy, warmups to ilość procesów rozgrzewkowych,
@Warmup(iterations = 2, time = 1) – iterations – ilość iteracji rozgrzewkowych, time – czas – domyślnie w sekundach,
@Measurement(iterations = 2, time = 2) – iterations – ilość iteracji w podanym czasie time (domyślnie w sekundach) branych pod uwagę w czasie wykonywania pomiaru. Więcej iteracji wymaga więcej czasu.

Zanim zaprezentuję wyniki wszystkich testów, przedstawię wynik dla pierwszego testu:

@Benchmark
@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.MICROSECONDS)
@Fork(value = 1, warmups = 4)
@Warmup(iterations = 3, time = 1)
@Measurement(iterations = 5, time = 2)
public int testFactorialWithLoopForWithSmallNumber() {
    return Factorial.getFactorialFor(SMALL_NUMBER);
}

wynik:

# JMH version: 1.19
# VM version: JDK 13.0.1, VM 13.0.1+9
# VM invoker: C:\Users\EMAWARY\Downloads\jdk-13.0.1_windows-x64_bin\jdk-13.0.1\bin\java.exe
# VM options: -Didea.launcher.port=60087 -Didea.launcher.bin.path=C:\Program Files\JetBrains\IntelliJ IDEA Community Edition 2018.2.1\bin -Dfile.encoding=UTF-8
# Warmup: 3 iterations, 1 s each
# Measurement: 5 iterations, 2 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: pl.javaleader.jmh.benchmarking.BenchmarkFactorial.testFactorialWithLoopForWithSmallNumber
 
# Run progress: 0,00% complete, ETA 00:01:05
# Warmup Fork: 1 of 4
# Warmup Iteration   1: 0,004 us/op
# Warmup Iteration   2: 0,004 us/op
# Warmup Iteration   3: 0,003 us/op
Iteration   1: 0,003 us/op
Iteration   2: 0,003 us/op
Iteration   3: 0,003 us/op
Iteration   4: 0,003 us/op
Iteration   5: 0,003 us/op
 
# Run progress: 20,00% complete, ETA 00:00:55
# Warmup Fork: 2 of 4
# Warmup Iteration   1: 0,004 us/op
# Warmup Iteration   2: 0,004 us/op
# Warmup Iteration   3: 0,003 us/op
Iteration   1: 0,002 us/op
Iteration   2: 0,002 us/op
Iteration   3: 0,002 us/op
Iteration   4: 0,002 us/op
Iteration   5: 0,002 us/op
 
# Run progress: 40,00% complete, ETA 00:00:41
# Warmup Fork: 3 of 4
# Warmup Iteration   1: 0,003 us/op
# Warmup Iteration   2: 0,003 us/op
# Warmup Iteration   3: 0,002 us/op
Iteration   1: 0,002 us/op
Iteration   2: 0,002 us/op
Iteration   3: 0,002 us/op
Iteration   4: 0,002 us/op
Iteration   5: 0,002 us/op
 
# Run progress: 60,00% complete, ETA 00:00:27
# Warmup Fork: 4 of 4
# Warmup Iteration   1: 0,003 us/op
# Warmup Iteration   2: 0,003 us/op
# Warmup Iteration   3: 0,002 us/op
Iteration   1: 0,002 us/op
Iteration   2: 0,002 us/op
Iteration   3: 0,003 us/op
Iteration   4: 0,003 us/op
Iteration   5: 0,002 us/op
 
# Run progress: 80,00% complete, ETA 00:00:13
# Fork: 1 of 1
# Warmup Iteration   1: 0,003 us/op
# Warmup Iteration   2: 0,003 us/op
# Warmup Iteration   3: 0,002 us/op
Iteration   1: 0,002 us/op
Iteration   2: 0,002 us/op
Iteration   3: 0,003 us/op
Iteration   4: 0,002 us/op
Iteration   5: 0,002 us/op
 
 
Result "pl.javaleader.jmh.benchmarking.BenchmarkFactorial.testFactorialWithLoopForWithSmallNumber":
  0,002 ±(99.9%) 0,001 us/op [Average]
  (min, avg, max) = (0,002, 0,002, 0,003), stdev = 0,001
  CI (99.9%): [0,001, 0,003] (assumes normal distribution)
 
 
# Run complete. Total time: 00:01:08
 
Benchmark                                                   Mode  Cnt  Score   Error  Units
BenchmarkFactorial.testFactorialWithLoopForWithSmallNumber  avgt    5  0,002 ± 0,001  us/op
 
Process finished with exit code 0

Interpretacja wyniku:

Wykonany został benchmark test dla jednego procesu z 4 procesami rozgrzewkowymi (warmups = 4). Do pomiaru użyto 5 iteracji (@Measurement(iterations = 5)). Podczas pomiaru wykonano 3 iteracje rozgrzewkowe (@Warmup(iterations = 3)). Wynik zaprezentowano w mikrosekundach (@OutputTimeUnit(TimeUnit.MICROSECONDS)).

Wyniki wszystkich testów dla poszczególnych algorytmów liczenia silni:

Result "pl.javaleader.jmh.benchmarking.BenchmarkFactorial.testFactorialWithRecursiveMethodWithSmallNumber":
  0,011 ±(99.9%) 0,004 us/op [Average]
  (min, avg, max) = (0,009, 0,011, 0,012), stdev = 0,001
  CI (99.9%): [0,007, 0,015] (assumes normal distribution)
 
 
# Run complete. Total time: 00:04:31
 
Benchmark                                                           Mode  Cnt  Score    Error  Units
BenchmarkFactorial.testFactorialWithLoopForWithLongNumber           avgt    5  0,052 ±  0,004  us/op
BenchmarkFactorial.testFactorialWithLoopForWithSmallNumber          avgt    5  0,002 ±  0,001  us/op
BenchmarkFactorial.testFactorialWithRecursiveMethodWithLongNumber   avgt    5  0,143 ±  0,007  us/op
BenchmarkFactorial.testFactorialWithRecursiveMethodWithSmallNumber  avgt    5  0,011 ±  0,004  us/op

Wnioski:

Algorytm rekurencyjny jest zdecydowanie mniej wydajny niż algorytm iteracyjny bo średni czas wykonania (Score) jest dłuższy.

Zarządzanie stanem benchmarku:

Zamiast generować kilka podobnych testów jak ma to miejsce w powyższym przykładzie – mamy przecież 4 testy benchmarkowe które są do siebie bardzo zbliżone to możemy skrócić kod do następującej postaci:

@State(Scope.Benchmark)

@State(Scope.Benchmark)
public class BenchmarkFactorial {
 
    @Param({"4", "100"})
    int param;
 
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 4)
    @Warmup(iterations = 3, time = 1)
    @Measurement(iterations = 5, time = 2)
    public int testFactorialWithLoopForWithSmallNumber() {
        return Factorial.getFactorialFor(param);
    }
 
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 4)
    @Warmup(iterations = 3, time = 1)
    @Measurement(iterations = 5, time = 2)
    public int testFactorialWithRecursiveMethodWithSmallNumber() {
        return Factorial.getFactorialRec(param);
    }
}

Testy zostaną wykonane wtedy dwa razy dla dwóch różnych parametrów.

Wynik:

Result "pl.javaleader.jmh.benchmarking.BenchmarkFactorial.testFactorialWithRecursiveMethodWithSmallNumber":
  0,146 ±(99.9%) 0,006 us/op [Average]
  (min, avg, max) = (0,144, 0,146, 0,148), stdev = 0,002
  CI (99.9%): [0,140, 0,153] (assumes normal distribution)
 
 
# Run complete. Total time: 00:04:31
 
Benchmark                                                           (param)  Mode  Cnt  Score    Error  Units
BenchmarkFactorial.testFactorialWithLoopForWithSmallNumber                4  avgt    5  0,005 ±  0,001  us/op
BenchmarkFactorial.testFactorialWithLoopForWithSmallNumber              100  avgt    5  0,055 ±  0,003  us/op
BenchmarkFactorial.testFactorialWithRecursiveMethodWithSmallNumber        4  avgt    5  0,007 ±  0,001  us/op
BenchmarkFactorial.testFactorialWithRecursiveMethodWithSmallNumber      100  avgt    5  0,146 ±  0,006  us/op

Wyróżniamy 3 stany benchmarku:

Benchmark – wszystkie wątki wykorzystają tę samą instancję parametrów,
Thread – własna instancja parametrów dla każdego wątku,
Group – własna instancja parametrów dla grupy wątków.

@State(Scope.Thread)

Przykład ze względu na użycie typu Tuple wymaga dodania do projektu zależności do biblioteki vavr – polecam w tym miejscu wpis – https://javaleader.pl/2019/10/21/java-8-na-wypasie-biblioteka-vavr.

Zależność do biblioteki vavr:

<dependency>
    <groupId>io.vavr</groupId>
    <artifactId>vavr</artifactId>
    <version>0.9.0</version>
</dependency>

@State(Scope.Thread)
public class Params {
 
    public Set<String> threadsId = new HashSet();
 
    public static final int SMALL_NUMBER = 2;
    public static final int LONG_NUMBER  = 100;
 
    public synchronized void getThreadsId() {
        System.out.println(threadsId);
    }
 
    public synchronized void addToSet(String arg){
        threadsId.add(arg);
    }
}

Dla każdego testu benchmarkowego jest przekazana inna instancja parametrów:

public class BenchmarkFactorial {
 
    @Benchmark
    @Threads(3)
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 0, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public Tuple testFactorialWithLoopFor(Params params) {
        params.addToSet(String.valueOf(Thread.currentThread().getId()) + " [testFactorialWithLoopFor] " + params);
        params.getThreadsId();
        int factorialForSmallNumber = Factorial.getFactorialFor(params.SMALL_NUMBER);
        int factorialForLongNumber  = Factorial.getFactorialFor(params.LONG_NUMBER);
        return Tuple.of(factorialForSmallNumber, factorialForLongNumber);
    }
 
    @Benchmark
    @Threads(3)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @BenchmarkMode(Mode.AverageTime)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 0, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public Tuple testFactorialWithRecursiveMethod(Params params) {
        params.addToSet(String.valueOf(Thread.currentThread().getId() + " [testFactorialWithRecursiveMethod] " + params));
        params.getThreadsId();
        int factorialRecSmallNumber = Factorial.getFactorialRec(params.SMALL_NUMBER);
        int factorialRecLongNumber  = Factorial.getFactorialRec(params.LONG_NUMBER);
        return Tuple.of(factorialRecSmallNumber, factorialRecLongNumber);
    }
}

wynik:

Result "pl.javaleader.jmh.benchmarking.BenchmarkFactorial.testFactorialWithRecursiveMethod":
  4850,733 us/op
 
 
# Run complete. Total time: 00:00:02
 
Benchmark                                            Mode  Cnt     Score   Error  Units
BenchmarkFactorial.testFactorialWithLoopFor          avgt       4124,100          us/op
BenchmarkFactorial.testFactorialWithRecursiveMethod  avgt       4850,733          us/op

Testy metod zostały uruchomione w 3 wątkach, ich średni czas wykonania dla algorytmu rekurencyjnego jest jak można się było spodziewać gorszy niż dla algorytmu iteracyjnego. Poniżej dowód na to, że dla każdego wątku jest oddzielna instancja parametrów:

testFactorialWithLoopFor:

3 wątki, dla każdego wątku inna instancja parametrów:

id watku: 15 – @7184f78b

id watku: 17 – @6dd83eac

id watku: 16 – @d739fcd

Iteration   1: [15 [LoopFor] Params_jmhType@7184f78b]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
[15 [LoopFor] Params_jmhType@7184f78b, 17 [LoopFor] Params_jmhType@6dd83eac, 16 [LoopFor] Params_jmhType@d739fcd]
5124,600 ±(99.9%) 123835,468 us/op

testFactorialWithRecursiveMethod:

3 wątki, dla każdego wątku inna instancja parametrów:

id watku: 15 – @7f431613

id watku: 17 – @63ef9444

id watku: 16 – @3b46013

Iteration   1: [15 [RecursiveMethod] Params_jmhType@7f431613, 16 [RecursiveMethod] Params_jmhType@3b46013]
[15 [RecursiveMethod] Params_jmhType@7f431613, 16 [RecursiveMethod] Params_jmhType@3b46013]
[15 [RecursiveMethod] Params_jmhType@7f431613, 16 [RecursiveMethod] Params_jmhType@3b46013, 17 [RecursiveMethod] Params_jmhType@63ef9444]
[15 [RecursiveMethod] Params_jmhType@7f431613, 16 [RecursiveMethod] Params_jmhType@3b46013, 17 [RecursiveMethod] Params_jmhType@63ef9444]
[15 [RecursiveMethod] Params_jmhType@7f431613, 16 [RecursiveMethod] Params_jmhType@3b46013, 17 [RecursiveMethod] Params_jmhType@63ef9444]
[15 [RecursiveMethod] Params_jmhType@7f431613, 16 [RecursiveMethod] Params_jmhType@3b46013, 17 [RecursiveMethod] Params_jmhType@63ef9444]
[15 [RecursiveMethod] Params_jmhType@7f431613, 16 [RecursiveMethod] Params_jmhType@3b46013, 17 [RecursiveMethod] Params_jmhType@63ef9444]
[15 [RecursiveMethod] Params_jmhType@7f431613, 16 [RecursiveMethod] Params_jmhType@3b46013, 17 [RecursiveMethod] Params_jmhType@63ef9444]
4850,733 ±(99.9%) 120851,079 us/op

@State(Scope.Group)

Przypadek kiedy instancja parametrów jest dokładnie taka sama dla wszystkich wątków z danej grupy:

@State(Scope.Group)
public class Params {
 
    public Set<String> threadsId = new HashSet();
 
    public static final int SMALL_NUMBER = 2;
    public static final int LONG_NUMBER  = 100;
 
    public synchronized void getThreadsId() {
        System.out.println(threadsId);
    }
 
    public synchronized void addToSet(String arg){
        threadsId.add(arg);
    }
}

public class BenchmarkFactorial {
 
    @Benchmark
    @GroupThreads(3)
    @Group("g1")
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 0, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public Tuple testFactorialWithLoopFor(Params params) {
        params.addToSet(String.valueOf(Thread.currentThread().getId()) + " [testFactorialWithLoopFor] " + params);
        params.getThreadsId();
        int factorialForSmallNumber = Factorial.getFactorialFor(params.SMALL_NUMBER);
        int factorialForLongNumber  = Factorial.getFactorialFor(params.LONG_NUMBER);
        return Tuple.of(factorialForSmallNumber, factorialForLongNumber);
    }
 
    @Benchmark
    @GroupThreads(3)
    @Group("g1")
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @BenchmarkMode(Mode.AverageTime)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 0, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public Tuple testFactorialWithRecursiveMethod(Params params) {
        params.addToSet(String.valueOf(Thread.currentThread().getId() + " [testFactorialWithRecursiveMethod] " + params));
        params.getThreadsId();
        int factorialRecSmallNumber = Factorial.getFactorialRec(params.SMALL_NUMBER);
        int factorialRecLongNumber  = Factorial.getFactorialRec(params.LONG_NUMBER);
        return Tuple.of(factorialRecSmallNumber, factorialRecLongNumber);
    }
}

wynik:

Benchmark                                               Mode  Cnt     Score   Error  Units
BenchmarkFactorial.g1                                   avgt       5376,767          us/op
BenchmarkFactorial.g1:testFactorialWithLoopFor          avgt       2666,567          us/op
BenchmarkFactorial.g1:testFactorialWithRecursiveMethod  avgt       8086,967          us/op

Testy metod zostały uruchomione sumarycznie w 6 wątkach dla grupy g1, widać średni czas wykonania testów dla całej grupy g1, jak i dla poszczególnych metod z grupy. Oczywiście algorytm rekurencyjny działa wolniej. Poniżej dowód na to, że dla każdego wątku jest taka sama instancja parametrów:

6 wątków, dla każdego wątku ta sama instancja parametrów:

id watku: 15 – @1c5fed2f

id watku: 17 – @1c5fed2f

id watku: 19 – @1c5fed2f

id watku: 18 – @1c5fed2f

id watku: 16 – @1c5fed2f

id watku: 20 – @1c5fed2f

Iteration   1: [15 [LoopFor] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]
[15 [LoopFor] Params_@1c5fed2f, 20 [RecursiveMethod] Params_@1c5fed2f, 19 [RecursiveMethod] Params_@1c5fed2f, 17 [LoopFor] Params_@1c5fed2f, 18 [RecursiveMethod] Params_@1c5fed2f, 16 [LoopFor] Params_@1c5fed2f]

Ponadto mamy możliwość wykorzystania dwóch dodatkowych mechanizmów:

Setup (wykonywane przed przekazaniem parametrów do danego benchmarku), domyślnie Level.Trial czyli raz na wszystkie iteracje testowe oraz rozgrzewające.
TearDown (po przekazaniu obiektu do benchmarku).

@State(Scope.Group)
public class Params {
 
    public Set<String> threadsId = new HashSet();
    public static final int SMALL_NUMBER = 2;
    public static final int LONG_NUMBER  = 100;
 
    public synchronized void addToSet(String arg) {
            threadsId.add(arg);
    }
    public synchronized void getThreadsId() {
        System.out.println(threadsId);
    }
 
    @Setup
    public synchronized void setup() {
        System.out.println("run setup " + threadsId);
    }
 
    @TearDown
    public synchronized void tearDown() {
        System.out.println("run tearDown " + threadsId);
    }
}

wynik po wykonaniu metody tearDown – za każdym razem widać tą sama, wspólną instancję parametrów:

run tearDown [
17 [testFactorialWithLoopFor] pl.javaleader.jmh.benchmarking.generated.Params_jmhType@3ab9c8a9,
20 [testFactorialWithRecursiveMethod] pl.javaleader.jmh.benchmarking.generated.Params_jmhType@3ab9c8a9,
15 [testFactorialWithRecursiveMethod] pl.javaleader.jmh.benchmarking.generated.Params_jmhType@3ab9c8a9,
19 [testFactorialWithRecursiveMethod] pl.javaleader.jmh.benchmarking.generated.Params_jmhType@3ab9c8a9, 
18 [testFactorialWithLoopFor] pl.javaleader.jmh.benchmarking.generated.Params_jmhType@3ab9c8a9,
16 [testFactorialWithLoopFor] pl.javaleader.jmh.benchmarking.generated.Params_jmhType@3ab9c8a9]

Martwy kod i jego wpływ na wyniki pomiarów:

Martwy kod to kod który nie ma żadnego wpływu na wynik naszego programu i jest przez kompilator usuwany celem jego optymalizacji np:

public String businessMethod(String param) {
    Supplier<String> supplier = ()-> "javaleader.pl";
        if (supplier == null) {
            throw new IllegalArgumentException("Supplier cannot be null");
        }
    return supplier.get();
}

po optymalizacji powyższy kod wygląda następująco:

public String businessMethod(String param) {
    Supplier<String> supplier = ()-> "javaleader.pl";
    return supplier.get();
}

martwy kod może doprowadzić do zakłamania wyniku pomiaru (nie zwracamy wartości supplier.get()):

public class BenchmarkDeadCode {
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 1, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public void  testDeadCode(Params params) {
        Supplier<String> supplier = ()-> "javaleader.pl";
        if (supplier == null) {
            throw new IllegalArgumentException("Supplier cannot be null");
        }
        supplier.get();
    }
}

wynik pomiaru:

Benchmark                                    Mode  Cnt  Score   Error  Units
BenchmarkFactorial.testFactorialWithLoopFor  avgt       0,010          us/op

dla zwrócenia wartości do typu Blackhole:

public class BenchmarkDeadCode {
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 1, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public void  testDeadCode(Params params, Blackhole blackhole) {
        Supplier<String> supplier = ()-> "javaleader.pl";
        if (supplier == null) {
            throw new IllegalArgumentException("Supplier cannot be null");
        }
        blackhole.consume(supplier.get());
    }
}

wynik pomiaru to:

Benchmark                       Mode  Cnt  Score   Error  Units
BenchmarkDeadCode.testDeadCode  avgt       0,016          us/op

dla zwróceni wartości przez metodę:

public class BenchmarkDeadCode {
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 1, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public String  testDeadCode(Params params) {
        Supplier<String> supplier = ()-> "javaleader.pl";
        if (supplier == null) {
            throw new IllegalArgumentException("Supplier cannot be null");
        }
        return supplier.get();
    }
}

wynik pomiaru to:

Benchmark                       Mode  Cnt  Score   Error  Units
BenchmarkDeadCode.testDeadCode  avgt  0,015          us/op

wyniki jasno dowodzą, że martwy kod prowadzi do zakłamania wyniku pomiaru.

Constant folding (składanie stałych) i ich wpływ na wyniki pomiarów:

Constant folding czyli optymalizacja po stronie JVM (składanie stałych) która polega na obliczaniu wyrażeń w czasie kompilacji – przykład kodu który w ten sposób jest optymalizowany to:

public class BenchmarkConstantFolding {
 
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 1, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public int testConstantFolding(Params params) {
        int a = 1;
        int b = 2;
        int sum = a + b;
        return sum;
    }
}

wynik:

Benchmark                                     Mode  Cnt  Score   Error  Units
BenchmarkConstantFolding.testConstantFolding  avgt       0,010          us/op

uniknięcie optymalizacji:

@State(Scope.Thread)
public class Params {
    int a = 1;
    int b = 2;
}

public class BenchmarkConstantFolding {
 
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 1, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public int testConstantFolding(Params params) {
        int a = params.a; 
        int b = params.b;
        int sum = a + b;
        return sum;
    }
}

wynik:

Benchmark                                      Mode  Cnt  Score   Error  Units
BenchmarkConstantFolding.testConstantFolding   avgt       0,019          us/op

Optymalizacja pętli i jej wpływ na wyniki pomiarów:

@State(Scope.Benchmark)
public class BenchmarkLoop {
 
    @Param({"100", "1000", "10000"})
    int param;
 
    @Benchmark
    @BenchmarkMode(Mode.AverageTime)
    @OutputTimeUnit(TimeUnit.MICROSECONDS)
    @Fork(value = 1, warmups = 1)
    @Warmup(iterations = 1, time = 1)
    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MICROSECONDS)
    public int testLoop() {
        int sum = 0;
        for (int i = 0; i < param; i++) {
            sum++;
        }
        return sum;
    }
}

wynik:

Benchmark               (param)  Mode  Cnt  Score   Error  Units
BenchmarkLoop.testLoop      100  avgt       0,028          us/op
BenchmarkLoop.testLoop     1000  avgt       0,008          us/op
BenchmarkLoop.testLoop    10000  avgt       0,021          us/op

jak widać powyżej wynik jest bardzo zbliżony pomimo znaczącego wzrostu ilości iteracji pętli. Świetna optymalizacja ze stron kompilatora!, ale z punktu widzenia testów benchmarkowych nie porządana! Unikajmy stosowania pętli w swoich benchmarkach!

Przykładem optymalizacji pętli ze strony kompilatora jest kod:

Przed optymalizacją:

while(i<100) {
 a = Sin(x)/Cos(x) + i;
 i++;
}

Po optymalizacji:

t = Sin(x)/Cos(x);
while(i<100) {
 a = t + i;
 i++;
}

Należy uważać na wszystkie optymalizacje które kompilator za nas wykonuje w testach becnhmarkowych. Może to nam dać zafałszowane wyniki wprowadzając w błąd, że metoda np. działa wystarczająco szybko, a potem okazuje się już na produkcji, że niestety, ale wcale tak nie jest…

Zobacz kod na GitHubie i zapisz się na bezpłatny newsletter!

https://github.com/mwarycha/JavaLeader.pl/tree/master/jmh

Group, wydajność, warmups, Thread, TearDown, Setup, Score, preformance, JMH, Java Microbenchmark Harness, Constant folding, Blackhole, Benchmark, JVM, tuple, vavr, pom.xml, spring boot

JavaLeader.pl

Praktyczna skarbnica wiedzy z Javy i nie tylko!

Leave a comment Anuluj pisanie odpowiedzi