为什么两个连续的呼吁相同的方法产生不同的时代为执行？

StackOverflow https://stackoverflow.com/questions/804620

题

这里是一样的代码:

public class TestIO{
public static void main(String[] str){
    TestIO t = new TestIO();
    t.fOne();
    t.fTwo();
    t.fOne();
    t.fTwo();
}


public void fOne(){
    long t1, t2;
    t1 = System.nanoTime();
    int i = 10;
    int j = 10;
    int k = j*i;
    System.out.println(k);
    t2 = System.nanoTime();
    System.out.println("Time taken by 'fOne' ... " + (t2-t1));
}

public void fTwo(){
    long t1, t2;
    t1 = System.nanoTime();
    int i = 10;
    int j = 10;
    int k = j*i;
    System.out.println(k);
    t2 = System.nanoTime();
    System.out.println("Time taken by 'fTwo' ... " + (t2-t1));
}

}

这给出了以下产出：100 时间所采取的'带'...390273 100 时间所采取的'fTwo'...118451 100 时间所采取的'带'...53359 100 时间所采取的'fTwo'...115936 按任何关键的继续。..

为什么要花更多的时间(大多)来执行同样的方法的第一次于连续的电话？

我试着给 -XX:CompileThreshold=1000000 命令行，但是没有差别。

有帮助吗？

解决方案

有几个原因。 JIT（即时）编译器可能没有运行。 JVM可以执行不同调用之间的优化。您正在测量经过的时间，因此您的计算机上可能正在运行Java之外的其他内容。处理器和RAM高速缓存可能是“温暖”的。在随后的调用中。

您确实需要进行多次调用（数千次）以获得准确的每个方法执行时间。

其他提示

Andreas 和JIT的不可预测性都是正确的，但还有一个问题是类加载器：

对 fOne 的第一次调用与后者的完全不同，因为这是第一次调用 System.out.println ，这意味着类加载器将从磁盘或文件系统缓存（通常是缓存）打印文本所需的所有类。将参数 -verbose：class 提供给JVM，以查看在这个小程序中实际加载了多少个类。

我在运行单元测试时注意到了类似的行为 - 调用大型框架的第一个测试需要更长的时间（如果Guice在C2Q6600上大约需要250ms），即使测试代码是相同的，因为第一个调用是指类加载器加载数百个类。

由于您的示例程序太短，因此开销可能来自非常早期的JIT优化和类加载活动。垃圾收集器甚至可能在程序结束之前就没有启动。

<强>更新

现在我找到了一种可靠的方法来找出真正花费时间的东西。还没有人发现它，虽然它与类加载密切相关 - 它是原生方法的动态链接！

我按如下方式修改了代码，以便日志在测试开始和结束时显示（通过查看何时加载这些空标记类）。

    TestIO t = new TestIO();
    new TestMarker1();
    t.fOne();
    t.fTwo();
    t.fOne();
    t.fTwo();
    new TestMarker2();

运行程序的命令，使用正确的 JVM参数显示真实情况：

java -verbose:class -verbose:jni -verbose:gc -XX:+PrintCompilation TestIO

输出：

* snip 493 lines *
[Loaded java.security.Principal from shared objects file]
[Loaded java.security.cert.Certificate from shared objects file]
[Dynamic-linking native method java.lang.ClassLoader.defineClass1 ... JNI]
[Loaded TestIO from file:/D:/DEVEL/Test/classes/]
  3       java.lang.String::indexOf (166 bytes)
[Loaded TestMarker1 from file:/D:/DEVEL/Test/classes/]
[Dynamic-linking native method java.io.FileOutputStream.writeBytes ... JNI]
100
Time taken by 'fOne' ... 155354
100
Time taken by 'fTwo' ... 23684
100
Time taken by 'fOne' ... 22672
100
Time taken by 'fTwo' ... 23954
[Loaded TestMarker2 from file:/D:/DEVEL/Test/classes/]
[Loaded java.util.AbstractList$Itr from shared objects file]
[Loaded java.util.IdentityHashMap$KeySet from shared objects file]
* snip 7 lines *

时差的原因是： [动态链接本机方法java.io.FileOutputStream.writeBytes ... JNI]

我们还可以看到，JIT编译器不会影响此基准测试。只编译了三种方法（例如上面代码片段中的 java.lang.String :: indexOf ），它们都发生在调用 fOne 方法之前。

  1. 测试的代码非常简单。采取的最昂贵的行动是

     System.out.println(k);

    所以你要测量的是调试输出的写入速度。这种情况差异很大，甚至可能取决于屏幕上调试窗口的位置，如果需要滚动其大小等等。

  2. JIT / Hotspot逐步优化常用的代码路径。

  3. 处理器优化预期的代码路径。使用的路径更经常执行得更快。

  4. 您的样本量太小了。这样的微基准测试通常会进行预热阶段，您可以看到应该如何广泛地完成这项工作，例如 Java真的如此快速无所事事。

此外，JITting，其他因素可能是：

  • 该过程的输出流阻断，当你打电话系统。出。释放
  • 你过程中获得安排由另一个进程
  • 垃圾回收做了一些工作上的一个背景线

如果你想得到良好的基准，应

  • 运行代码你准大量的时候，几千至少，并计算的平均时间。
  • 忽略这次第几次电话(由于JITting，等等。)
  • 禁用的GC如果你能；这可能不是一个选择，如果你的代码生成大量的对象。
  • 采取日志记录(释放的电话)的代码基准.

有的基准图书馆对几个平台，这将有助于你做这个东西；他们还可以计算标准差和其他统计数据。

最可能的罪魁祸首是 JIT （即时）热点引擎。基本上，第一次执行代码时，机器代码被“记住”。通过JVM，然后在未来的执行中重复使用。

我认为这是因为第一次运行后第二次生成的代码已经过优化。

正如所建议的那样，JIT可能是罪魁祸首，但如果机器上的其他进程当时正在使用资源，那么I / O等待时间以及资源等待时间也是如此。

这个故事的寓意是，微基准测试是一个难题，特别是对于Java。我不知道你为什么要这样做，但是如果你试图在两种方法中选择一个问题，不要这样测量它们。使用策略设计模式，使用两种不同的方法运行整个程序并测量整个系统。即使从长远来看，这也会使处理时间出现小问题，并且可以让您更加真实地了解整个应用程序的性能在这一点上的瓶颈（提示：它可能比您想象的要小。）

好的最多可能的答案是初始化。JIT肯定是不正确的答案，因为它需要更多的周期开始之前达到最佳化。但是，在第一时间有可以是：

  • 看起来类(为缓存，因此没有第二查找所需要的)
  • 装载班(一次装载留在记忆)
  • 获得额外的代码从地图书馆(地代码是缓存)
  • 最后，它负荷的代码，以执行在L1缓。这是最propable情况下为加速在你的感觉，并在同一时间原因，为什么该基准(正在一个基准测试)没有说的多。如果你的代码是小足够的第二次调用的一个循环可以运行完全由内的CPU是快。在现实世界不会发生这种情况，因为项目是更大的和reusage L1缓远远不是那么大。
许可以下： CC-BY-SA 和 归因
不隶属于 StackOverflow
scroll top