java - 为什么对同一方法的两次连续调用会产生不同的执行时间？

Question

这是一个示例代码：

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 'fOne' 花费的时间 ... 390273 100 'fTwo' 花费的时间 ... 118451 100 'fOne' 花费的时间 ... 53359 100 'fTwo' 花费的时间 ... 115936按任意键继续。. .

为什么第一次执行相同的方法比连续调用需要更多的时间（明显更多）？

我尝试给-XX:CompileThreshold=1000000命令行，但没有区别。

score 7 · Accepted Answer

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

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

score 7 · Accepted Answer

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

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

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

由于您的示例程序很短，因此开销可能来自早期的 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 *

时差的原因是这样的：[Dynamic-linking native method java.io.FileOutputStream.writeBytes ... JNI]

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

score 5 · Accepted Answer

测试的代码非常简单。采取的最昂贵的行动是
```
 System.out.println(k);
```
所以你要测量的是调试输出的写入速度。这变化很大，甚至可能取决于调试窗口在屏幕上的位置，是否需要滚动其大小等。
JIT/Hotspot 以增量方式优化常用代码路径。
处理器针对预期的代码路径进行优化。经常使用的路径执行得更快。
你的样本量太小了。这样的微基准测试通常会做一个热身阶段，您可以看到这应该做多广泛，就像Java 真的很快就什么都不做一样。

score 3 · Accepted Answer

除了 JITting，其他因素可能是：

调用 System.out.println 时进程的输出流阻塞
您的进程被另一个进程调度
垃圾收集器在后台线程上做一些工作

如果你想获得好的基准，你应该

运行您要进行大量基准测试的代码，至少数千次，然后计算平均时间。
忽略前几次调用的次数（由于 JITting 等）
如果可以，请禁用 GC；如果您的代码生成大量对象，这可能不是一个选项。
从被基准测试的代码中取出日志记录（println 调用）。

有几个平台上的基准测试库可以帮助您完成这些工作；他们还可以计算标准偏差和其他统计数据。

score 2 · Accepted Answer

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

score 1 · Accepted Answer

1

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

于 2009-04-29T22:52:17.210 回答

score 1 · Accepted Answer

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

这个故事的寓意是，microbenchmarking 是一个难题，尤其是对于 Java。我不知道您为什么要这样做，但是如果您要在解决问题的两种方法之间进行选择，请不要以这种方式衡量它们。使用策略设计模式并使用两种不同的方法运行整个程序并测量整个系统。从长远来看，这在处理时间上几乎没有什么影响，并且让您可以更真实地了解当时整个应用程序的性能有多少瓶颈（提示：它可能比您想象的要少。）

score 1 · Accepted Answer

那么最可能的答案是初始化。JIT 肯定不是正确的答案，因为它需要更多的周期才能开始优化。但在第一次可能有：

查找类（已缓存，因此无需第二次查找）
加载类（一旦加载就留在内存中）
从本机库获取附加代码（本机代码被缓存）
最后它加载要在 CPU 的 L1 缓存中执行的代码。在您的意义上，这是加速的最可能的案例，同时也是基准（作为微基准）没有说太多的原因。如果您的代码足够小，则循环的第二次调用可以完全从 CPU 内部运行，这非常快。在现实世界中，这不会发生，因为程序更大，而 L1 缓存的重用远没有那么大。

java - 为什么对同一方法的两次连续调用会产生不同的执行时间？

8 回答 8

Related

Reference