性能说明:预热后代码运行速度较慢

下面的代码运行完全相同的计算3次(它没有做太多:基本上添加从1到100米的所有数字)。 前两个块的运行速度比第三个块快约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; } } 

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

首先,您可以使用选项-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必须重新编译它。

您需要将每个循环放在不同的方法中。 您需要执行此操作的原因是JIT集合有关如何运行代码的统计信息,这用于优化代码。 但是,在调用10000次或循环运行10000次后,方法会被优化。

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