【问题标题】:What happens inside the JVM so that a method invocation in Java becomes slower when you call it somewhere else in your code?JVM 内部发生了什么,以至于当您在代码中的其他地方调用 Java 中的方法调用时会变慢?
【发布时间】:2017-04-07 15:21:01
【问题描述】:

下面的短代码隔离了问题。基本上我正在计时方法addToStorage。我从执行一百万次开始,我能够将它的时间缩短到大约 723 纳秒。然后我做了一个短暂的暂停(使用忙碌的旋转方法不释放 cpu 核心)并在不同的代码位置再次对该方法计时 N 次。令我惊讶的是,我发现 N 越小,addToStorage 延迟越大。

例如:

If N = 1 then I get 3.6 micros
If N = 2 then I get 3.1 and 2.5 micros
if N = 5 then I get 3.7, 1.8, 1.7, 1.5 and 1.5 micros

有谁知道为什么会发生这种情况以及如何解决它?我希望我的方法在尽可能快的时间内始终如一地执行,无论我在哪里调用它。

注意:我认为这与线程无关,因为我没有使用Thread.sleep。我还测试了使用taskset 将我的线程固定到 cpu 内核,结果相同。

import java.util.ArrayList;
import java.util.List;

public class JvmOdd {

    private final StringBuilder sBuilder = new StringBuilder(1024);
    private final List<String> storage = new ArrayList<String>(1024 * 1024);

    public void addToStorage() {

        sBuilder.setLength(0);

        sBuilder.append("Blah1: ").append(System.nanoTime()).append('\n');
        sBuilder.append("Blah2: ").append(System.nanoTime()).append('\n');
        sBuilder.append("Blah3: ").append(System.nanoTime()).append('\n');
        sBuilder.append("Blah4: ").append(System.nanoTime()).append('\n');
        sBuilder.append("Blah5: ").append(System.nanoTime()).append('\n');
        sBuilder.append("Blah6: ").append(System.nanoTime()).append('\n');
        sBuilder.append("Blah7: ").append(System.nanoTime()).append('\n');
        sBuilder.append("Blah8: ").append(System.nanoTime()).append('\n');
        sBuilder.append("Blah9: ").append(System.nanoTime()).append('\n');
        sBuilder.append("Blah10: ").append(System.nanoTime()).append('\n');

        storage.add(sBuilder.toString());
    }

    public static long mySleep(long t) {
        long x = 0;
        for(int i = 0; i < t * 10000; i++) {
            x += System.currentTimeMillis() / System.nanoTime();
        }
        return x;
    }

    public static void main(String[] args) throws Exception {

        int warmup = Integer.parseInt(args[0]);
        int mod = Integer.parseInt(args[1]);
        int passes = Integer.parseInt(args[2]);
        int sleep = Integer.parseInt(args[3]);

        JvmOdd jo = new JvmOdd();

        // first warm up

        for(int i = 0; i < warmup; i++) {
            long time = System.nanoTime();
            jo.addToStorage();
            time = System.nanoTime() - time;
            if (i % mod == 0) System.out.println(time);
        }

        // now see how fast the method is:

        while(true) {

            System.out.println();

            // Thread.sleep(sleep);
            mySleep(sleep);

            long minTime = Long.MAX_VALUE;

            for(int i = 0; i < passes; i++) {
                long time = System.nanoTime();
                jo.addToStorage();
                time = System.nanoTime() - time;
                if (i > 0) System.out.print(',');
                System.out.print(time);
                minTime = Math.min(time, minTime);
            }
            System.out.println("\nMinTime: " + minTime);
        }
    }
}

执行:

$ java -server -cp . JvmOdd 1000000 100000 1 5000
59103
820
727
772
734
767
730
726
840
736

3404
MinTime: 3404

【问题讨论】:

  • 我只能想到CPU缓存未命中,JVM本身不会发生这种情况。
  • 好点@JornVernee!对于 CPU 缓存未命中来说,差异不是太大了吗?此外,在第二次或第三次调用中,CPU 是否应该缓存它需要的内容?我们将如何进一步探索该假设?
  • 差异似乎不大,内存提取最多可能需要 1000 个 ALU 周期。这真的取决于你在什么 CPU 上运行,我不知道有什么方法可以测试它(也许在恢复之前转储 CPU 缓存,如果这可能取决于你的 CPU,而不是 Java)。
  • 请不要cross-post:softwareengineering.stackexchange.com/q/345768/1352“交叉发帖不受欢迎,因为它会导致零散的答案散布在整个网络。”
  • 您在分析中混入了非技术语义。您的代码中没有“暂停”。线程在执行mySleep 时很忙,只有您希望将其视为睡眠操作。将方法命名为 mySleep 也没有真正的目的,这与 JVM 无关。因此,由于代码中没有暂停,因此它也不会“暂停后变慢”。

标签: java jvm real-time latency hotspot


【解决方案1】:

这里发生了很多事情,我不知道从哪里开始。但是让我们从这里开始......

           long time = System.nanoTime();
            jo.addToStorage();
            time = System.nanoTime() - time;

使用此技术无法测量 addToStoarge() 的延迟。它只是运行得太快,这意味着您可能低于时钟的分辨率。如果不运行此程序,我的猜测是您的措施主要由时钟边沿计数决定。您需要增加工作单元的体积才能获得噪音水平较低的测量值。

至于发生了什么?有许多调用站点优化,最重要的是内联。内联将完全消除调用站点,但它是特定于路径的优化。如果您从不同的地方调用该方法,那将遵循执行虚拟方法查找然后跳转到该代码的缓慢路径。因此,要看到从不同路径进行内联的好处,还必须“预热”该路径。

我强烈建议您同时查看 JMH(随 JDK 提供)。那里有诸如黑洞之类的设施,这将有助于减少 CPU 时钟的影响。您可能还想借助 JITWatch(采用 OpenJDK 项目)之类的工具来评估工作台的质量,这些工具将获取 JIT 生成的日志并帮助您中断它们。

【讨论】:

  • 顺便说一句,mechanical sympathy google group 上对这个问题进行了很好的讨论。
  • 确实是一个很好的讨论...。我认为 mySleep() 方法不会被抛弃。在过去,我可以通过将 void 替换为返回值来防止死代码消除。然而,一旦 mySleep() 被内联,值依赖就会消失,之后内联的 mySleep() 可以被 DCE 化。
【解决方案2】:

这个主题有很多内容,但最重要的是,您不能编写像这样简单的基准测试并期望它能告诉您任何有用的信息。您将需要使用 JMH。

我建议看这个:https://www.infoq.com/presentations/jmh 关于微基准测试和 JMH

我的书中还有一章关于微基准测试和 JMH:http://shop.oreilly.com/product/0636920042983.do

【讨论】:

    【解决方案3】:

    Java 内部使用 JIT(仅在编译器中)。根据相同方法执行的次数,它可以优化指令并更好地执行。对于较小的值,方法的使用将是正常的,这可能不属于显示执行时间更多的优化。当同一个方法调用更多时间时,它使用 JIT 并且执行时间更短,因为优化了相同方法执行的指令。

    【讨论】:

      猜你喜欢
      • 2010-10-27
      • 2022-09-26
      • 2017-07-12
      • 1970-01-01
      • 2013-09-26
      • 2019-01-13
      • 2016-09-19
      • 2010-12-07
      • 2010-10-25
      相关资源
      最近更新 更多