第一次Java循环运行时，为什么？
在对Solaris SPARC盒子上的一些Java代码进行基准测试时，我注意到我第一次调用基准测试函数时，它运行得很慢（10倍差异）：
- 首先| 1 | 25295.979毫秒
- 第二| 1 | 2256.990毫秒
- 第三| 1 | 2250.575毫秒
为什么是这样？ 我怀疑是JIT编译器，有没有办法validation这个？
编辑：根据一些答案，我想澄清一下，这段代码是最简单的测试案例，我可以找到展示这种行为。 所以我的目标不是让它快速运行，而是要了解发生了什么，所以我可以在我真正的基准测试中避免它。
解决： 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
因此，HotSpot从内部循环中删除了内存访问，将其加速了一个数量级。
经验教训：算一算！ 我应该自己完成汤姆的计算。
基准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次。
使用to accessor方法的循环，称之为25个循环。 1 GHz时1,000,000,000次，可提供25秒。
嘿，我们预测了SLOW的时间。 慢的时候很快。 快速时间是在基准以某种方式被打破之后 - 一次迭代2.5个周期？ 使用-server可能会发现它变得更加愚蠢。
可能是本机方法的类加载或动态链接。 如果使用以下JVM参数运行Java（请参阅此处获取完整列表），它将打印有关时间的信息：
-verbose:class -verbose:jni -verbose:gc -XX:+PrintCompilation
要准确找出每个measure（）调用的开始和结束位置，请在这些方法之间添加一些新类的初始化作为标记，以便-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等类，这里是结果。
在第一次调用measure（）期间，总共加载了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
这是在Windows上使用jdk1.6.0_11运行的，因此您的系统可能会做一些不同的事情。 例如，动态方法的这些链接中的一个可能在您的系统上exception缓慢。 或者所有类加载都比较慢。 尝试查看日志，是否存在exception长的暂停，或者所有这些操作是否都同样慢。
作为嫌疑人添加类加载。 在第一次引用时懒惰地加载类。 因此，代码第一次运行时，您可能是第一次引用某些类。
validationJIT编译器是否是后续迭代加速的原因的最佳方法是在关闭JIT编译器的情况下运行基准测试。 为此，请指定系统属性java.compiler=NONE （单词“none”必须为大写）。
进行类加载所花费的时间也会导致基准测试代码第一次运行得更慢。 最后，在调用Thread.start（）和调用Thread的run（）方法之间存在一个不确定的延迟。
您可能需要考虑寻找基准框架。 一个好的框架将通过运行多次迭代来“预热”代码，然后使用不同的迭代次数执行多个计时。 参见Java理论与实践：有缺陷的微基准的剖析 。
这是一个有趣的问题。 我怀疑JIT编译器，但这些是我的数字：
首先| 1 | 2399.233毫秒 第二| 1 | 2322.359毫秒 第三| 1 | 2408.342毫秒
可能Solaris正在做一些有趣的线程; 你试过nThreads = 10左右吗？
我建议你制作nThread = Runtime.getRuntime（）。availableProcessors（）这将为你提供使用系统中所有核心的最佳线程数。
您可以尝试关闭JIT，看看它有什么不同。
您可以让VM记录有关类加载和编译的信息，尝试以下VM args：-XX：+ PrintCompilation -XX：+ TraceClassLoading这可能会提供一些关于幕后发生的事情的进一步线索。
编辑：我不确定这些选项是否适用于java 1.5（我在1.6中使用过它们）。 我将尝试检查…再次编辑：它适用于java 1.5（请注意，您需要+，而不是 – ，或者您关闭选项…）
我相信您也可以使用-Xint的java命令的非标准选项来禁用HotSpot并仅解释您的代码。 这至少可以使HotSpot脱离等式来解释你的时间。
这是工作中的热点编译器。 AFAIK，第一次运行该函数，运行“解释”并分析执行路径，然后JIT编译器可以优化后续函数调用。
它肯定是热点编译器。 如果您在64位solaris上运行，则默认为服务器VM，并且热点仅在首次执行时开始优化。 在客户端VM上，代码可能需要在热点启动之前运行几次。（我相信solaris只有服务器虚拟机，但我可能错了）
有关启动程序如何在客户端和服务器VM之间进行选择以及不同处理器和操作系统支持的内容，请参阅http://java.sun.com/javase/6/docs/technotes/guides/vm/server-class.html 。