在JVM中发生了什么,以便当您在代码中的其他位置调用Java时,Java中的方法调用会变慢？

Question

下面的简短代码可以解决问题.基本上我是计时方法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

Answer 1

这里有很多事情,我不知道从哪里开始.但是我们从这里开始......

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

使用此技术无法测量addToStoarge()的延迟.它只是运行得太快意味着你可能低于时钟的分辨率.如果不运行这个,我猜测你的测量是由时钟边缘计数决定的.您需要增加工作单元以获得噪声水平较低的测量.

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

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