当永远不会执行的代码被注释掉时，Java程序会运行得更慢

我在其中一个Java程序中观察到一些奇怪的行为。 我试图尽可能地去除代码，同时仍然能够复制行为。 代码全部在下面。

public class StrangeBehaviour { static boolean recursionFlag = true; public static void main(String[] args) { long startTime = System.nanoTime(); for (int i = 0; i < 10000; i ++) { functionA(6, 0); } long endTime = System.nanoTime(); System.out.format("%.2f seconds elapsed.\n", (endTime - startTime) / 1000.0 / 1000 / 1000); } static boolean functionA(int recursionDepth, int recursionSwitch) { if (recursionDepth == 0) { return true; } return functionB(recursionDepth, recursionSwitch); } static boolean functionB(int recursionDepth, int recursionSwitch) { for (int i = 0; i < 16; i++) { if (StrangeBehaviour.recursionFlag) { if (recursionSwitch == 0) { if (functionA(recursionDepth - 1, 1 - recursionSwitch)) return true; } else { if (!functionA(recursionDepth - 1, 1 - recursionSwitch)) return false; } } else { // This block is never entered into. // Yet commenting out one of the lines below makes the program run slower! System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); } } return false; } } 

我有两个函数， functionA()和functionB() ，recursion调用对方。 这两个函数都采用一个recursionDepth参数来控制recursionDepth的终止。 functionA()最多一次调用functionB() ， recursionDepth不变。 functionB()调用functionA() 16次与recursionDepth - 1 。 recursionfunctionA()以0 recursionDepth调用时functionA() 。

functionB()有一个包含多个System.out.println()调用的代码块。 这个块永远不会被input，因为入口被设置为true的boolean recursionFlagvariablesvariables控制，并且在程序执行过程中永远不会改变。 但是，即使发出println()调用中的一个，也会导致程序运行速度变慢。 在我的机器上，所有println()调用的执行时间<0.2s，当其中一个调用被注释掉时，执行时间> 2s。

什么可能导致这种行为？ 我唯一的猜测是有一些天真的编译器优化是由与代码块的长度（或函数调用次数等）有关的参数触发的。 任何进一步的洞察将非常感谢！

编辑：我正在使用JDK 1.8。

Answer 1

完整的答案是k5_和Tony的答案的组合。

OP发布的代码在执行基准testing之前省略了热启动循环以触发热点编译; 因此，当打印语句包含在内时，加速10倍（在我的计算机上）将HotSpot花费在CPU指令上的字节码的编译时间和CPU指令的实际运行结合在一起。

如果在定时循环之前添加一个单独的预热循环，打印语句的加速只有2.5倍。

这表明当内联方法（如Tony解释的）时，HotSpot / JIT编译需要更长的时间，并且代码的运行需要更长的时间，可能是因为caching或分支预测/stream水线性能较差，如k5_所示。

 public static void main(String[] args) { // Added the following warmup loop before the timing loop for (int i = 0; i < 50000; i++) { functionA(6, 0); } long startTime = System.nanoTime(); for (int i = 0; i < 50000; i++) { functionA(6, 0); } long endTime = System.nanoTime(); System.out.format("%.2f seconds elapsed.\n", (endTime - startTime) / 1000.0 / 1000 / 1000); } 

Answer 2

评论的代码影响如何处理内联。 如果函数B变得更长/更大（更多的字节码指令），它将不会被内联到函数A中。

所以@J3D1能够使用VMOptions来手动closuresfunctionB（）的内联： -XX:CompileCommand=dontinline,com.jd.benchmarking.StrangeBeh‌​aviour::functionB这似乎消除了延迟与较短的function。

与vm选项可以显示内联-XX:+UnlockDiagnosticVMOptions -XX:+PrintInlining

更大的版本，不会内联functionB

 @ 8 StrangeBehaviour::functionB (326 bytes) callee is too large @ 21 StrangeBehaviour::functionA (12 bytes) @ 8 StrangeBehaviour::functionB (326 bytes) callee is too large @ 35 StrangeBehaviour::functionA (12 bytes) @ 8 StrangeBehaviour::functionB (326 bytes) callee is too large 

较短的版本将尝试内联functionB，导致一些进一步的尝试。

 @ 8 StrangeBehaviour::functionB (318 bytes) inline (hot) @ 21 StrangeBehaviour::functionA (12 bytes) inline (hot) @ 8 StrangeBehaviour::functionB (318 bytes) inline (hot) @ 35 StrangeBehaviour::functionA (12 bytes) recursive inlining is too deep @ 35 StrangeBehaviour::functionA (12 bytes) inline (hot) @ 8 StrangeBehaviour::functionB (318 bytes) inline (hot) @ 21 StrangeBehaviour::functionA (12 bytes) recursive inlining is too deep @ 35 StrangeBehaviour::functionA (12 bytes) recursive inlining is too deep @ 21 StrangeBehaviour::functionA (12 bytes) inline (hot) @ 8 StrangeBehaviour::functionB (318 bytes) inline (hot) @ 35 StrangeBehaviour::functionA (12 bytes) inline (hot) @ 8 StrangeBehaviour::functionB (318 bytes) recursive inlining is too deep @ 35 StrangeBehaviour::functionA (12 bytes) inline (hot) @ 8 StrangeBehaviour::functionB (318 bytes) inline (hot) @ 21 StrangeBehaviour::functionA (12 bytes) inline (hot) @ 8 StrangeBehaviour::functionB (318 bytes) recursive inlining is too deep @ 35 StrangeBehaviour::functionA (12 bytes) inline (hot) @ 8 StrangeBehaviour::functionB (318 bytes) recursive inlining is too deep 

主要是猜测，但更大/内联字节码将导致分支预测和caching问题

Answer 3

我在@ k5_，似乎有一个门槛，以确定是否内联一个函数。 如果JIT编译器决定将其内联，则会导致大量工作和时间，如-XX:+PrintCompilation显示：

  task-id 158 32 3 so_test.StrangeBehaviour::functionB (326 bytes) made not entrant 159 35 3 java.lang.String::<init> (82 bytes) 160 36 s 1 java.util.Vector::size (5 bytes) 1878 37 % 3 so_test.StrangeBehaviour::main @ 6 (65 bytes) 1898 38 3 so_test.StrangeBehaviour::main (65 bytes) 2665 39 3 java.util.regex.Pattern::has (15 bytes) 2667 40 3 sun.misc.FDBigInteger::mult (64 bytes) 2668 41 3 sun.misc.FDBigInteger::<init> (30 bytes) 2668 42 3 sun.misc.FDBigInteger::trimLeadingZeros (57 bytes) 2.51 seconds elapsed. 

上面是没有评论的信息，以下是将方法大小从326字节减小到318字节的评论。 而且你可以注意到输出的第一列中的任务id比后者大得多，这会导致更多的时间。

  task-id 126 35 4 so_test.StrangeBehaviour::functionA (12 bytes) 130 33 3 so_test.StrangeBehaviour::functionA (12 bytes) made not entrant 131 36 s 1 java.util.Vector::size (5 bytes) 14078 37 % 3 so_test.StrangeBehaviour::main @ 6 (65 bytes) 14296 38 3 so_test.StrangeBehaviour::main (65 bytes) 14296 39 % 4 so_test.StrangeBehaviour::functionB @ 2 (318 bytes) 14300 40 4 so_test.StrangeBehaviour::functionB (318 bytes) 14304 34 3 so_test.StrangeBehaviour::functionB (318 bytes) made not entrant 14628 41 3 java.util.regex.Pattern::has (15 bytes) 14631 42 3 sun.misc.FDBigInteger::mult (64 bytes) 14632 43 3 sun.misc.FDBigInteger::<init> (30 bytes) 14632 44 3 sun.misc.FDBigInteger::trimLeadingZeros (57 bytes) 14.50 seconds elapsed. 

如果将代码更改为以下内容（添加两行并将其从打印行中删除），则可以看到代码大小更改为326字节，现在运行速度更快：

  if (StrangeBehaviour.recursionFlag) { int a = 1; int b = 1; if (recursionSwitch == 0) { if (functionA(recursionDepth - 1, 1 - recursionSwitch)) return true; } else { if (!functionA(recursionDepth - 1, 1 - recursionSwitch)) return false; } } else { // This block is never entered into. // Yet commenting out one of the lines below makes the program run slower! System.out.println("..."); System.out.println("..."); System.out.println("..."); //System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); System.out.println("..."); } 

新的时间和JIT编译器信息：

  140 34 3 so_test.StrangeBehaviour::functionB (326 bytes) made not entrant 145 36 3 java.lang.String::<init> (82 bytes) 148 37 s 1 java.util.Vector::size (5 bytes) 162 38 4 so_test.StrangeBehaviour::functionA (12 bytes) 163 33 3 so_test.StrangeBehaviour::functionA (12 bytes) made not entrant 1916 39 % 3 so_test.StrangeBehaviour::main @ 6 (65 bytes) 1936 40 3 so_test.StrangeBehaviour::main (65 bytes) 2686 41 3 java.util.regex.Pattern::has (15 bytes) 2689 42 3 sun.misc.FDBigInteger::mult (64 bytes) 2690 43 3 sun.misc.FDBigInteger::<init> (30 bytes) 2690 44 3 sun.misc.FDBigInteger::trimLeadingZeros (57 bytes) 2.55 seconds elapsed. 

总之 ：

• 当方法大小超过一定限制时，JIT不会内联该函数;
• 如果我们把一条线减less到低于阈值的大小，JIT就决定将它内联;
• 内联该函数会导致大量的JIT任务，这会减慢程序的速度。

---

更新 ：

根据我最近的试验 ，这个问题的答案并不那么容易：

正如我的代码示例所示，正常的内联优化将会

• 加速节目
• 而且不会花费太多的编译器工作（在我的testing中，内联发生时甚至花费更less的工作）。

但在这个问题上，代码会导致很多JIT工作，并且会减慢程序，这似乎是JIT的一个bug。 为什么会导致JIT的这么多的工作，目前还不清楚。