Пустые методы заметно медленнее в Java 11, чем Java 8

Я сравнивал производительность JDK 8 и 11, используя jmh 1.21, когда наткнулся на несколько удивительных чисел:

Java version: 1.8.0_192, vendor: Oracle Corporation Benchmark Mode Cnt Score Error Units MyBenchmark.emptyMethod avgt 25 0.362 ± 0.001 ns/op Java version: 9.0.4, vendor: Oracle Corporation Benchmark Mode Cnt Score Error Units MyBenchmark.emptyMethod avgt 25 0.362 ± 0.001 ns/op Java version: 10.0.2, vendor: Oracle Corporation Benchmark Mode Cnt Score Error Units MyBenchmark.emptyMethod avgt 25 0.723 ± 0.001 ns/op Java version: 11.0.1, vendor: Oracle Corporation Benchmark Mode Cnt Score Error Units MyBenchmark.emptyMethod avgt 25 0.724 ± 0.002 ns/op

OpenJDK 11 и 12 работают аналогично OracleJDK 11. Для краткости я опустил их номера.

Я понимаю, что микробенчмарки не указывают на поведение производительности реальных приложений. Тем не менее, мне любопытно, откуда эта разница. Есть идеи?

Вот эталон в целом:

pom.xml:

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd"> <modelVersion>4.0.0</modelVersion> <groupId>jmh</groupId> <artifactId>empty-method</artifactId> <version>1.0-SNAPSHOT</version> <packaging>jar</packaging> <name>JMH benchmark sample: Java</name> <dependencies> <dependency> <groupId>org.openjdk.jmh</groupId> <artifactId>jmh-core</artifactId> <version>${jmh.version}</version> </dependency> <dependency> <groupId>org.openjdk.jmh</groupId> <artifactId>jmh-generator-annprocess</artifactId> <version>${jmh.version}</version> <scope>provided</scope> </dependency> </dependencies> <properties> <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding> <jmh.version>1.21</jmh.version> <javac.target>1.8</javac.target> <uberjar.name>benchmarks</uberjar.name> </properties> <build> <plugins> <plugin> <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-enforcer-plugin</artifactId> <version>1.4.1</version> <executions> <execution> <id>enforce-versions</id> <goals> <goal>enforce</goal> </goals> <configuration> <rules> <requireMavenVersion> <version>3.0</version> </requireMavenVersion> </rules> </configuration> </execution> </executions> </plugin> <plugin> <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-compiler-plugin</artifactId> <version>3.8.0</version> <configuration> <compilerVersion>${javac.target}</compilerVersion> <source>${javac.target}</source> <target>${javac.target}</target> </configuration> </plugin> <plugin> <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-shade-plugin</artifactId> <version>3.2.1</version> <executions> <execution> <phase>package</phase> <goals> <goal>shade</goal> </goals> <configuration> <finalName>${uberjar.name}</finalName> <transformers> <transformer implementation="org.apache.maven.plugins.shade.resource.ManifestResourceTransformer"> <mainClass>org.openjdk.jmh.Main</mainClass> </transformer> </transformers> <filters> <filter>  <artifact>*:*</artifact> <excludes> <exclude>META-INF/*.SF</exclude> <exclude>META-INF/*.DSA</exclude> <exclude>META-INF/*.RSA</exclude> </excludes> </filter> </filters> </configuration> </execution> </executions> </plugin> </plugins> <pluginManagement> <plugins> <plugin> <artifactId>maven-clean-plugin</artifactId> <version>2.6.1</version> </plugin> <plugin> <artifactId>maven-deploy-plugin</artifactId> <version>2.8.2</version> </plugin> <plugin> <artifactId>maven-install-plugin</artifactId> <version>2.5.2</version> </plugin> <plugin> <artifactId>maven-jar-plugin</artifactId> <version>3.1.0</version> </plugin> <plugin> <artifactId>maven-javadoc-plugin</artifactId> <version>3.0.0</version> </plugin> <plugin> <artifactId>maven-resources-plugin</artifactId> <version>3.1.0</version> </plugin> <plugin> <artifactId>maven-site-plugin</artifactId> <version>3.7.1</version> </plugin> <plugin> <artifactId>maven-source-plugin</artifactId> <version>3.0.1</version> </plugin> <plugin> <artifactId>maven-surefire-plugin</artifactId> <version>2.22.0</version> </plugin> </plugins> </pluginManagement> </build> </project>

src/main/java/jmh/MyBenchmark.java:

package jmh; import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; import java.util.concurrent.TimeUnit; @BenchmarkMode(Mode.AverageTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) public class MyBenchmark { @Benchmark public void emptyMethod() { } }

Вот специфичный для Windows скрипт, который я использую. Это должно быть тривиально, чтобы перевести его на другие платформы:

set JAVA_HOME=C:\Program Files\Java\jdk1.8.0_192 call mvn -V -Djavac.target=1.8 clean install "%JAVA_HOME%\bin\java" -jar target\benchmarks.jar set JAVA_HOME=C:\Program Files\Java\jdk-9.0.4 call mvn -V -Djavac.target=9 clean install "%JAVA_HOME%\bin\java" -jar target\benchmarks.jar set JAVA_HOME=C:\Program Files\Java\jdk-10.0.2 call mvn -V -Djavac.target=10 clean install "%JAVA_HOME%\bin\java" -jar target\benchmarks.jar set JAVA_HOME=C:\Program Files\Java\oracle-11.0.1 call mvn -V -Djavac.target=11 clean install "%JAVA_HOME%\bin\java" -jar target\benchmarks.jar

Моя среда выполнения:

Apache Maven 3.6.0 (97c98ec64a1fdfee7767ce5ffb20918da4f719f3; 2018-10-24T14:41:47-04:00) Maven home: C:\Program Files\apache-maven-3.6.0\bin\.. Default locale: en_CA, platform encoding: Cp1252 OS name: "windows 10", version: "10.0", arch: "amd64", family: "windows"

В частности, я использую Microsoft Windows [Version 10.0.17763.195].

Ответы

Ответ 1

Вы измеряете пустые тесты, а не пустые методы. Другими словами, измерение минимального кода инфраструктуры, который обрабатывает сам тест. Это легко разобрать, потому что вы ожидаете только несколько инструкций по горячему пути. -prof perfasm или -prof xperfasm дадут вам самые горячие инструкции за считанные секунды.

Я думаю, что эффект связан с локальными рукопожатиями (JEP 312), см.:

8u191: 0,389 ± 0,029 нс/операция [пока все хорошо]

  3.60%  ↗  ...a2: movzbl 0x94(%r8),%r10d
  0.63%  │  ...aa: add    $0x1,%rbp
 32.82%  │  ...ae: test   %eax,0x1765654c(%rip) ; global safepoint poll
 58.14%  │  ...b4: test   %r10d,%r10d
         ╰  ...b7: je     ...a2

11.0.2: 0.585 ± 0.014 нс/оп [упс, регрессия]

  0.31%  ↗  ...70: movzbl 0x94(%r9),%r10d    
  0.19%  │  ...78: mov    0x108(%r15),%r11  ; reading the thread-local poll addr
 25.62%  │  ...7f: add    $0x1,%rbp          
 35.10%  │  ...83: test   %eax,(%r11)       ; thread-local safepoint poll
 34.91%  │  ...86: test   %r10d,%r10d
         ╰  ...89: je     ...70

11.0.2, -XX: - ThreadLocalHandshakes: 0,399 ± 0,048 нс/операция [назад к 8u перф.]

  5.64%  ↗  ...62: movzbl 0x94(%r8),%r10d    
  0.91%  │  ...6a: add    $0x1,%rbp          
 34.36%  │  ...6e: test   %eax,0x179be88c(%rip) ; global safepoint poll
 54.79%  │  ...74: test   %r10d,%r10d
         ╰  ...77: je     ...62

Я думаю, что это в значительной степени видно в основном в тесных петлях, как этот.

UPD: надеюсь, подробнее здесь.