初めてのJavaループで実行が遅く、いかがでしょうか?【日ホットスポット1.5、sparc]
-
21-08-2019 - |
質問
中のベンチマークの一部でJavaコードをSolaris SPARCボックスだから、なくてはならない初めてのベンチマーキング機能で非常にゆっくりと(10倍違い):
- はじめに|1|25295.979ms
- 秒|1|2256.990ms
- 三|1|2250.575ms
これはなぜであろうか。疑いはJITコンパイラがあるのかを検証す。
編集: 照らし、その答えたいと思ったことを明らかにこのコードは最も単純な 可能なテストケースで見出展す。私の目標なん で速く走るには何が行われているのかが理解できることで実 ベンチマーク
解決: Tom Hawtinを正しく指摘私の"遅い"の時間が実際にリーズナブル。この観測、付属のデバッガは、Javaのプロセス。中には、内側のループは以下のようなものです:
0xf9037218: cmp %l0, 100
0xf903721c: bge,pn %icc,0xf90371f4 ! 0xf90371f4
0xf9037220: nop
0xf9037224: ld [%l3 + 92], %l2
0xf9037228: ld [%l2 + 8], %l6
0xf903722c: add %l6, 1, %l5
0xf9037230: st %l5, [%l2 + 8]
0xf9037234: inc %l0
0xf9037238: ld [%l1], %g0
0xf903723c: ba,pt %icc,0xf9037218 ! 0xf9037218
次回のループは以下のようなものです:
0xf90377d4: sub %l2, %l0, %l3
0xf90377d8: add %l3, %l0, %l2
0xf90377dc: add %l2, 1, %l4
0xf90377e0: inc %l0
0xf90377e4: cmp %l0, 100
0xf90377e8: bl,pn %icc,0xf90377d8 ! 0xf90377d8
でのホットスポット取り外したメモリアクセスから内側のループスピードでの大きくなりました。
レッスン: の数学!私はするべきであったという反省点もトムスの計算です。
ベンチマークのJavaコード:
private int counter;
private int nThreads;
private void measure(String tag) throws Exception {
MyThread threads[] = new MyThread[nThreads];
int i;
counter = 0;
for (i = 0; i < nThreads; i++)
threads[i] = new MyThread();
long start = System.nanoTime();
for (i = 0; i < nThreads; i++)
threads[i].start();
for (i = 0; i < nThreads; i++)
threads[i].join();
if (tag != null)
System.out.format("%-20s | %-2d | %.3f ms \n", tag, nThreads,
new Double((System.nanoTime() - start) / 1000000.0));
}
public MyBench() {
try {
this.nThreads = 1;
measure("First");
measure("Second");
measure("Third");
} catch (Exception e) {
System.out.println("Error: " + e);
}
}
private class MyThread extends Thread {
public void run() {
while (counter < 10000000) {
// work
for (int j = 0; j < 100; j++)
counter++;
counter -= 99;
}
}
}
解決
醜くて非現実的なコード (マイクロベンチマークのもの):
while (counter < 10000000) {
// work
for (int j = 0; j < 100; j++)
counter++;
counter -= 99;
}
では、これは何をしているのでしょうか、どのくらいの速度で実行する必要があるのでしょうか。
内側のループはカウンターを 100 回インクリメントし、その後カウンターは 99 ずつデクリメントされます。したがって、1 ずつ増加します。カウンタは外部クラスのメンバー変数であるため、多少のオーバーヘッドがあることに注意してください。これは 10,000,000 回実行されます。したがって、内側のループは 1,000,000,000 回実行されます。
アクセサ メソッドを使用するループ。これを 25 サイクルと呼びます。1 GHz で 1,000,000,000 回、25 秒になります。
ねえ、私たちは予測しました 遅い 時間。遅い時間は早い。速い時間はベンチマークを何らかの方法で破った後のものです - 1 回の反復で 2.5 サイクル?-server を使用すると、さらに愚かなことになるかもしれません。
他のヒント
おそらくそれのクラスローディングまたは動的リンクの方法。行った場合、JavaのJVMパラメータの参照 こちらの のための完全なリストを入力してください印刷に関する情報に何が起きているのに時間:
-verbose:class -verbose:jni -verbose:gc -XX:+PrintCompilation
見を正確に測定()の呼び出しの開始と終了、追加initializationsの新しい授業との方法としてマーカー、 -verbose:class
までなんとポイントのログのマーカーのクラスがロードされます。見 この答え 類似の測定できます。
見どのコードは、変更でこのように:
public MyBench() {
try {
this.nThreads = 1;
new Mark1();
measure("First");
new Mark2();
measure("Second");
new Mark3();
measure("Third");
new Mark4();
} catch (Exception e) {
System.out.println("Error: " + e);
}
}
private static class Mark1 {
}
private static class Mark2 {
}
private static class Mark3 {
}
private static class Mark4 {
}
それを見た時のJVMの駆者Mark1。授業が、ここにい。
期間中の最初の呼び出の測定()の計85授業に積まれ、11のネイティブメソッドがダイナミックは、5つの方法JIT成:
[Loaded MyBench$Mark1 from file:/D:/DEVEL/Test/classes/]
[Loaded java.net.InetSocketAddress from shared objects file]
[Loaded java.net.InetAddress from shared objects file]
[Loaded MyBench$MyThread from file:/D:/DEVEL/Test/classes/]
[Loaded sun.security.action.GetBooleanAction from shared objects file]
[Dynamic-linking native method java.net.InetAddress.init ... JNI]
[Loaded java.net.InetAddress$Cache from shared objects file]
[Loaded java.lang.Enum from shared objects file]
[Loaded java.net.InetAddress$Cache$Type from shared objects file]
[Loaded java.net.InetAddressImplFactory from shared objects file]
[Dynamic-linking native method java.net.InetAddressImplFactory.isIPv6Supported ... JNI]
22 MyBench::access$508 (12 bytes)
[Loaded java.net.InetAddressImpl from shared objects file]
[Loaded java.net.Inet4AddressImpl from shared objects file 1% MyBench$MyThread::run @ 14 (48 bytes)
]
[Loaded sun.net.spi.nameservice.NameService from shared objects file]
[Loaded java.net.InetAddress$1 from shared objects file]
[Loaded java.net.Inet4Address from shared objects file]
[Dynamic-linking native method java.net.Inet4Address.init ... JNI]
[Dynamic-linking native method java.net.PlainSocketImpl.socketCreate ... JNI]
[Dynamic-linking native method java.net.PlainSocketImpl.socketBind ... JNI]
[Dynamic-linking native method java.net.PlainSocketImpl.socketListen ... JNI]
[Loaded java.net.Socket from shared objects file]
[Dynamic-linking native method java.net.PlainSocketImpl.socketAccept ... JNI]
[Loaded java.lang.Integer$IntegerCache from shared objects file]
[Loaded java.util.Formatter from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded java.util.regex.Pattern$6 from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded java.text.DecimalFormatSymbols from shared objects file]
[Loaded java.util.spi.LocaleServiceProvider from shared objects file]
[Loaded java.text.spi.DecimalFormatSymbolsProvider from shared objects file]
[Loaded sun.util.LocaleServiceProviderPool from shared objects file]
[Loaded java.util.LinkedHashSet from shared objects file]
[Loaded sun.util.LocaleServiceProviderPool$1 from shared objects file]
[Loaded java.util.ServiceLoader from shared objects file]
[Loaded java.util.ServiceLoader$LazyIterator from shared objects file]
[Loaded java.util.ServiceLoader$1 from shared objects file]
[Loaded java.util.HashMap$EntrySet from shared objects file]
[Loaded java.util.LinkedHashMap$LinkedHashIterator from shared objects file]
[Loaded java.util.LinkedHashMap$EntryIterator from shared objects file]
[Loaded sun.misc.Launcher$1 from shared objects file]
23 ! java.io.BufferedReader::readLine (304 bytes)
[Loaded sun.misc.Launcher$2 from shared objects file]
[Loaded sun.misc.URLClassPath$2 from shared objects file]
[Loaded java.lang.ClassLoader$2 from shared objects file]
[Loaded sun.misc.URLClassPath$1 from shared objects file]
[Loaded java.net.URLClassLoader$3 from shared objects file]
[Loaded sun.misc.CompoundEnumeration from shared objects file]
24 sun.nio.cs.UTF_8$Decoder::decodeArrayLoop (553 bytes)
[Loaded java.io.FileNotFoundException from shared objects file]
[Loaded java.net.URLClassLoader$3$1 from shared objects file]
[Dynamic-linking native method java.security.AccessController.doPrivileged ... JNI]
[Loaded sun.util.resources.LocaleData from shared objects file]
[Loaded sun.util.resources.LocaleData$1 from shared objects file]
[Loaded java.util.ResourceBundle$Control from shared objects file]
[Loaded sun.util.resources.LocaleData$LocaleDataResourceBundleControl from shared objects file]
[Loaded java.util.Arrays$ArrayList from shared objects file]
[Loaded java.util.Collections$UnmodifiableCollection from shared objects file]
25 java.lang.String::startsWith (78 bytes)
[Loaded java.util.Collections$UnmodifiableList from shared objects file]
[Loaded java.util.Collections$UnmodifiableRandomAccessList from shared objects file]
[Loaded java.util.ResourceBundle from shared objects file]
[Loaded java.util.ResourceBundle$1 from shared objects file]
[Dynamic-linking native method java.util.ResourceBundle.getClassContext ... JNI]
[Loaded java.util.ResourceBundle$RBClassLoader from shared objects file]
[Loaded java.util.ResourceBundle$RBClassLoader$1 from shared objects file]
[Loaded java.util.ResourceBundle$CacheKey from shared objects file]
[Loaded java.util.ResourceBundle$CacheKeyReference from shared objects file]
[Loaded java.util.ResourceBundle$LoaderReference from shared objects file]
[Loaded java.util.ResourceBundle$SingleFormatControl from shared objects file]
[Loaded sun.util.LocaleDataMetaInfo from shared objects file]
[Loaded java.util.AbstractList$Itr from shared objects file]
[Loaded java.util.ListResourceBundle from shared objects file]
[Loaded sun.text.resources.FormatData from shared objects file]
[Dynamic-linking native method java.lang.Class.isAssignableFrom ... JNI]
[Loaded java.util.ResourceBundle$BundleReference from shared objects file]
[Loaded sun.text.resources.FormatData_fi from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded sun.text.resources.FormatData_fi_FI from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded java.util.Currency from shared objects file]
[Loaded java.util.Currency$1 from shared objects file]
[Loaded java.util.CurrencyData from shared objects file]
[Loaded sun.reflect.UnsafeFieldAccessorFactory from shared objects file]
[Loaded sun.reflect.UnsafeQualifiedStaticFieldAccessorImpl from shared objects file]
[Loaded sun.reflect.UnsafeQualifiedStaticObjectFieldAccessorImpl from shared objects file]
[Loaded java.util.spi.CurrencyNameProvider from shared objects file]
[Loaded sun.util.resources.OpenListResourceBundle from shared objects file]
[Loaded sun.util.resources.LocaleNamesBundle from shared objects file]
[Loaded sun.util.resources.CurrencyNames from shared objects file]
[Loaded sun.util.resources.CurrencyNames_fi_FI from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded java.util.regex.MatchResult from shared objects file]
[Loaded java.util.regex.Matcher from shared objects file]
[Loaded java.util.regex.ASCII from shared objects file]
[Loaded java.util.Formatter$FormatString from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded java.util.Formatter$FormatSpecifier from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded java.util.Formatter$Flags from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded java.util.Formatter$Conversion from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded java.util.Formatter$FixedString from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded java.util.Formattable from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Dynamic-linking native method java.io.FileOutputStream.writeBytes ... JNI]
First | 1 | [Loaded sun.misc.FormattedFloatingDecimal from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded sun.misc.FormattedFloatingDecimal$1 from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded sun.misc.FormattedFloatingDecimal$Form from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
[Loaded sun.misc.FormattedFloatingDecimal$2 from C:\Program Files\Java\jdk1.6.0_11\jre\lib\rt.jar]
2072,825 ms
期間中に、法JIT成:
[Loaded MyBench$Mark2 from file:/D:/DEVEL/Test/classes/]
26 MyBench$MyThread::run (48 bytes)
Second | 1 | 2058,669 ms
の話は作業のう:
[Loaded MyBench$Mark3 from file:/D:/DEVEL/Test/classes/]
Third | 1 | 2093,659 ms
このために、窓jdk1.6.0_11、システムにもう少しとは異なります。例えば、かつlinkingsの動力学法は非常に遅いる必要があります。又はそのすべてのクラスローディングが遅くなります。うというものがログかどうかが異常に長い休止、またはるかどうかの業務も同様に遅くなります。
容疑者としてでクラスのロードを追加します。クラスは、最初の参照で遅延ロードされています。だから、コードが実行される最初の時間は、あなたはおそらく初めていくつかのクラスを参照しています。
JITコンパイラが後の反復で高速化の理由であるかどうかを確認するための最良の方法はオフにJITコンパイラでベンチマークを実行することです。これを行うには、システムプロパティのjava.compiler=NONE
(「なし」は大文字であってはならない単語)を指定します。
時間が費やさクラスローディングも、ベンチマークのコードが遅く最初に実行する可能性があります。最後に、Thread.start()と呼ばれているスレッドのrun()メソッドを呼び出す間の非決定的な遅延があります。
あなたはベンチマークのフレームワークを見つけることを検討する必要があります。良いフレームワークは、反復の数が異なる複数のタイミングを行い、その後、数回の繰り返しを実行して、コードを「ウォームアップ」します。欠陥マイクロベンチマークでの解剖学: Javaの理論と実践を参照してください。
これは面白い質問ですね。私は、JITコンパイラを疑うだろうが、これらは私の番号です。
First | 1 | 2399.233 ms Second | 1 | 2322.359 ms Third | 1 | 2408.342 ms
おそらくSolarisのスレッドと面白いことをやっています。あなたがnThreads = 10
またはそうしようとしている?
私はあなたがnThread = Runtime.getRuntime()を作る示唆している。availableProcessorsを()これは、あなたのシステム内のすべてのコアを使用するスレッドの最適な数を提供します。
あなたはそれが作るものの違いを参照してJITをオフにしてみてくださいすることができます。
次のVMの引数を試し、クラスローディングとコンパイルについての情報をログに記録するVMを取得することができます。 -XX:+ PrintCompilation -XX:+ TraceClassLoading これは、ボンネットの下に何が起こっているかのように、いくつかの更なる手がかりを与えるかもしれない。
編集:私はそれらのオプションは、Java 1.5(私は1.6でそれらを使用しました)で働くか分かりません。私はチェックしてみましょう... EDIT再び:それは、Java 1.5で動作します -
(注意あなたは、+必要はありません...、またはオプションをオフにします)私はあなたにもホットスポットを無効にすると、あなたのコードのみ解釈している-Xintのjavaコマンドのための非標準オプションを使用することができると信じています。これは、少なくとも、あなたのタイミングを解釈するための方程式のうち、ホットスポットを取ることができます。
これは、職場でのホットスポットコンパイラです。私の知る限り、それは機能を実行する最初の時間は、「解釈」で実行され、実行パスを解析し、次いで、JITコンパイラは、後続の関数呼び出しを最適化することができます。
これは最も確かにホットスポットコンパイラです。サーバーVMおよびホットスポットに64ビットのSolarisがデフォルトで実行している場合は、単に最初の実行に最適化を開始。クライアントVM上のコードはでホットスポットキックの前に数回実行する必要があります。
(私はSolarisのみのはのサーバーのVMを持っていますが、私は間違っている可能性がありますと信じて)