19

下面的代码运行完全相同的计算 3 次(它做的不多:基本上是从 1 到 100m 的所有数字相加)。前两个块的运行速度比第三个快大约 10 倍。我已经运行了这个测试程序超过 10 次,结果显示的差异很小。

如果有的话,我希望第三个块运行得更快(JIT 编译),但典型的输出是:

35974537
36368455
296471550

有人可以解释发生了什么吗?(为了清楚起见,我不想在这里解决任何问题,只是想更好地了解发生了什么)

笔记:

  • 程序期间不运行 GC(用 监控-XX:+PrintGC
  • 使用 Oracle JDK 版本 1.6.0_30、1.7.0_02 和 1.7.0_05 测试
  • 还使用以下参数进行了测试:-XX:+PrintGC -Xms1000m -Xmx1000m -XX:NewSize=900m=> 相同的结果
  • 如果将块放入循环中,则所有运行都很快
  • 如果将块提取到方法中,则所有运行都很快(方法是否被调用 3 次或循环调用没有区别)
public static void main(String... args) {
    //three identical blocks
    {
        long start = System.nanoTime();
        CountByOne c = new CountByOne();
        int sum = 0;
        for (int i = 0; i < 100000000; i++) {
            sum += c.getNext();
        }
        if (sum != c.getSum()) throw new IllegalStateException(); //use sum
        long end = System.nanoTime();
        System.out.println((end - start));
    }
    {
        long start = System.nanoTime();
        CountByOne c = new CountByOne();
        int sum = 0;
        for (int i = 0; i < 100000000; i++) {
            sum += c.getNext();
        }
        if (sum != c.getSum()) throw new IllegalStateException(); //use sum
        long end = System.nanoTime();
        System.out.println((end - start));
    }
    {
        long start = System.nanoTime();
        CountByOne c = new CountByOne();
        int sum = 0;
        for (int i = 0; i < 100000000; i++) {
            sum += c.getNext();
        }
        if (sum != c.getSum()) throw new IllegalStateException(); //use sum
        long end = System.nanoTime();
        System.out.println((end - start));
    }
}

public static class CountByOne {

    private int i = 0;
    private int sum = 0;

    public int getSum() {
        return sum;
    }

    public int getNext() {
        i += 1;
        sum += i;
        return i;
    }
}
4

2 回答 2

11

简短:即时编译器是愚蠢的。

首先,您可以使用该选项-XX:+PrintCompilation查看 JIT 何时执行某项操作。然后你会看到这样的东西:

$ java -XX:+PrintCompilation weird
    168    1             weird$CountByOne::getNext (28 bytes)
    174    1 %           weird::main @ 18 (220 bytes)
    279    1 %           weird::main @ -2 (220 bytes)   made not entrant
113727636
    280    2 %           weird::main @ 91 (220 bytes)
106265475
427228826

因此,您会看到 main 方法有时在第一个和第二个块期间编译。

添加选项-XX:+PrintCompilation -XX:+UnlockDiagnosticVMOption将为您提供有关 JIT 正在做什么的更多信息。请注意,它需要hsdis-amd64.so在常见的 Linux 发行版上似乎不太可用。您可能需要自己从 OpenJDK 编译它。

你得到的是 getNext 和 main 的一大块汇编代码。

对我来说,在第一次编译中,似乎只编译了 main 中的第一个块,你可以通过行号来判断。它包含这样有趣的东西:

  0x00007fa35505fc5b: add    $0x1,%r8           ;*ladd
                                                ; - weird$CountByOne::getNext@6 (line 12)
                                                ; - weird::main@28 (line 31)
  0x00007fa35505fc5f: mov    %r8,0x10(%rbx)     ;*putfield i
                                                ; - weird$CountByOne::getNext@7 (line 12)
                                                ; - weird::main@28 (line 31)
  0x00007fa35505fc63: add    $0x1,%r14          ;*ladd
                                                ; - weird::main@31 (line 31)

(实际上它很长,由于循环的展开和内联)

显然,在重新编译 main 期间,编译了第二个和第三个块。那里的第二个块看起来与第一个版本非常相似。(再次只是摘录)

 0x00007fa35505f05d: add    $0x1,%r8           ;*ladd
                                                ; - weird$CountByOne::getNext@6 (line 12)
                                                ; - weird::main@101 (line 42)
  0x00007fa35505f061: mov    %r8,0x10(%rbx)     ;*putfield i
                                                ; - weird$CountByOne::getNext@7 (line 12)
                                                ; - weird::main@101 (line 42)
  0x00007fa35505f065: add    $0x1,%r13          ;*ladd

但是,第三个块的编译方式不同。没有内联和展开

这次整个循环看起来像这样:

  0x00007fa35505f20c: xor    %r10d,%r10d
  0x00007fa35505f20f: xor    %r8d,%r8d          ;*lload
                                                ; - weird::main@171 (line 53)
  0x00007fa35505f212: mov    %r8d,0x10(%rsp)
  0x00007fa35505f217: mov    %r10,0x8(%rsp)
  0x00007fa35505f21c: mov    %rbp,%rsi
  0x00007fa35505f21f: callq  0x00007fa355037c60  ; OopMap{rbp=Oop off=580}
                                                ;*invokevirtual getNext
                                                ; - weird::main@174 (line 53)
                                                ;   {optimized virtual_call}
  0x00007fa35505f224: mov    0x8(%rsp),%r10
  0x00007fa35505f229: add    %rax,%r10          ;*ladd
                                                ; - weird::main@177 (line 53)
  0x00007fa35505f22c: mov    0x10(%rsp),%r8d
  0x00007fa35505f231: inc    %r8d               ;*iinc
                                                ; - weird::main@180 (line 52)
  0x00007fa35505f234: cmp    $0x5f5e100,%r8d
  0x00007fa35505f23b: jl     0x00007fa35505f212  ;*if_icmpge
                                                ; - weird::main@168 (line 52)

我的猜测是 JIT 发现这部分代码没有被大量使用,因为它使用了来自第二个块执行的分析信息,因此没有对其进行大量优化。此外,从某种意义上说,JIT 似乎很懒惰,不会在编译完所有相关部分后重新编译一种方法。请记住,第一个编译结果根本不包含第二个/第三个块的源代码,因此 JIT 必须重新编译它。

于 2012-08-20T16:23:53.057 回答
2

您需要以不同的方法放置每个循环。您需要这样做的原因是 JIT 收集有关代码运行方式的统计信息,并用于优化代码。但是,一个方法在被调用 10000 次或循环运行 10000 次后才被优化。

在您的情况下,第一个循环触发整个方法进行优化,即使后面的循环尚未运行,因此没有收集统计​​信息。将每个循环放在自己的方法中,这不会发生。

于 2012-08-20T19:47:09.467 回答