Java 루프가 천천히 실행되면 왜 그런가? [Sun Hotspot 1.5, SPARC
https://stackoverflow.com/questions/860231
-
21-08-2019 - |
italiano
english
français
española
中国
日本の
العربية
Deutsch
한국어
Português
Russian문제
Solaris SPARC 상자에서 일부 Java 코드를 벤치마킹 할 때 벤치마킹 기능을 처음 호출하면 매우 느리게 실행됩니다 (10 배의 차이).
- 첫 번째 | 1 | 25295.979 ms
- 두 번째 | 1 | 2256.990ms
- 세 번째 | 1 | 2250.575 ms
왜 이런거야? JIT 컴파일러가 의심됩니다. 이것을 확인할 방법이 있습니까?
편집하다: 일부 답변에 비추어 나는이 코드 가이 행동을 보여줄 수있는 가장 간단한 시험 사례임을 명확히하고 싶었다. 그래서 내 목표는 그것을 빨리 달리는 것이 아니라, 무슨 일이 일어나고 있는지 이해하여 실제 벤치 마크에서 그것을 피할 수 있습니다.
해결 : Tom Hawtin은 내 "느린"시간이 실제로 합리적이라고 정확하게 지적했습니다. 이 관찰 후, 나는 Debugger를 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 사이클이라고 부릅니다. 1GHz에서 1,000,000,000 회, 25S를 제공합니다.
이봐, 우리는 예측했다 느린 시각. 느린 시간은 빠릅니다. 벤치 마크가 어떤 식 으로든 깨진 후 빠른 시간은 반복적으로 2.5 사이클입니까? 사용 -서버를 사용하면 훨씬 더 어리석은 것을 알 수 있습니다.
다른 팁
아마도 원시 방법의 클래스 로딩 또는 동적 연결 일 것입니다. 다음 JVM 매개 변수로 Java를 실행하는 경우 ( 여기 전체 목록의 경우), 시간이 걸리는 것에 대한 정보를 인쇄합니다.
-verbose:class -verbose:jni -verbose:gc -XX:+PrintCompilation
각 측정 () 호출이 시작 및 종료를 정확히 찾으려면 해당 메소드 사이에 마커로 일부 새로운 클래스의 초기화를 추가하여 -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이있는 Windows에서 실행되었으므로 시스템이 약간 다르게 수행 할 수 있습니다. 예를 들어, 동적 방법의 링크 중 하나가 시스템에서 매우 느립니다. 또는 모든 클래스 로딩이 느려집니다. 비정상적으로 긴 일시 정지가 있는지 또는 모든 작업이 똑같이 느리는지 여부에 대한 로그를 살펴보십시오.
용의자로 클래스 로딩을 추가하십시오. 첫 번째 참조에서 클래스가 게으르게로드됩니다. 코드가 처음 실행되면 아마도 처음으로 일부 클래스를 참조하고있을 것입니다.
JIT 컴파일러가 이후 반복 속도의 속도를 높이는 이유인지 확인하는 가장 좋은 방법은 JIT 컴파일러가 꺼진 상태에서 벤치 마크를 실행하는 것입니다. 이를 위해 시스템 속성을 지정하십시오 java.compiler=NONE ( "없음"이라는 단어는 대문자에 있어야합니다).
클래스로드를하는 데 소요되는 시간은 벤치마킹 코드가 처음으로 느리게 실행될 수 있습니다. 마지막으로, Calling Rest.Start ()와 Thread 's Run () 메소드가 호출되는 사이에는 비 결정적 지연이 있습니다.
벤치 마크 프레임 워크를 찾는 것을 고려할 수 있습니다. 좋은 프레임 워크는 여러 반복을 실행하여 코드를 "워밍업"한 다음 다른 수의 반복으로 여러 타이밍을 수행합니다. 보다 Java 이론 및 실습 : 결함이있는 마이크로 렌치 마크의 해부학.
그것은 흥미로운 질문입니다. 나는 JIT 컴파일러를 의심하지만 이것들은 내 숫자입니다.
First | 1 | 2399.233 ms Second | 1 | 2322.359 ms Third | 1 | 2408.342 ms
아마도 Solaris는 실로 재미있는 일을하고있을 것입니다. 당신은 함께 시도 했습니까? nThreads = 10 정도?
nthread = runtime.getRuntime (). avideprocessors ()이를 통해 시스템의 모든 코어를 사용할 수있는 최적의 스레드 수를 제공합니다.
JIT를 끄려면 차이가 어떤 차이가 있는지 확인할 수 있습니다.
클래스로드 및 컴파일에 대한 정보를 기록하기 위해 VM을 얻을 수 있습니다. 다음 VM Args를 시도해보십시오. -xx :+printcompilation -xx :+traceclassload 이것은 후드 아래에서 무슨 일이 일어나고 있는지에 대한 더 많은 단서를 줄 수 있습니다.
편집 : Java 1.5에서 이러한 옵션이 작동하는지 확실하지 않습니다 (1.6에서 사용했습니다). 다시 확인하려고 노력하겠습니다 ... 다시 편집 : Java 1.5에서 작동합니다 (참고 +, 옵션이 필요하지 않거나 옵션을 끄십시오 ...)
핫스팟을 비활성화하고 코드를 해석 할 수 있도록 -xint의 Java 명령에 비표준 옵션을 사용할 수 있다고 생각합니다. 이것은 적어도 타이밍을 해석하기 위해 방정식에서 핫스팟을 제거 할 수 있습니다.
직장에서 핫스팟 컴파일러입니다. 기능을 처음 실행할 때 "해석"을 실행하고 실행 경로를 분석 한 다음 JIT 컴파일러는 후속 기능 호출을 최적화 할 수 있습니다.
가장 확실하게 핫스팟 컴파일러입니다. 64 비트 Solaris에서 실행중인 경우 서버 VM 및 Hotspot의 기본값은 첫 번째 실행을 최적화하기 시작합니다. 클라이언트 VM에서 핫스팟이 시작되기 전에 코드가 몇 번 실행해야 할 수도 있습니다. (Solaris 만 믿습니다. 가지다 서버 VM이지만 내가 틀렸을 수도 있습니다)
보다 http://java.sun.com/javase/6/docs/technotes/guides/vm/server-class.html 런처가 클라이언트와 서버 VM을 선택하는 방식과 다른 프로세서 및 OS에서 지원되는 내용.
