Code becomes 6 times slower after doing extract method refactoring

Question

I know micro-benchmarking is hard. I'm not trying to build a poor micro-benchmark. Rather, I have run into this problem when making (what I thought to be) harmless refactoring. There is stripped down demo of the problem below.

The program builds an ArrayList of ten thousand random integers and then finds sum of the elements. In the example, summing is repeated a million times to improve signal v. noise ratio in the measurement of elapsed time. In real program, there's a million of slightly different lists, but the problematic effect holds regardless.

• App#arraySumInlined is the method version before refactoring with summing kept inline in the loop body.
• App#arraySumSubFunctionCall is the method version having loop body extracted into separate method.

Now, the surprising thing (to me) is that arraySumInlined takes ~7 sec, but arraySumSubFunctionCall takes ~42 sec. This seems to me like an impressive enough difference.

If I uncomment both arraySumInlined and arraySumSubFunctionCall then they complete in ~7 sec each. I.e. arraySumSubFunctionCall ceases to be that slow.

What's going on here? Are there any broader implications? E.g. never before have I thought of extract method refactoring as of something that could turn 7 sec method call into 42 sec one.

While researching this, I have found several questions involving JIT (e.g. Java method call performance and Why does this code using streams run so much faster in Java 9 than Java 8?), but they seem to deal with opposite cases: inlined code performing worse than code in a separate method.

Environment details: Windows 10 x64, Intel Core i3-6100.

? java -version
openjdk version "11.0.4" 2019-07-16
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.4+11)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.4+11, mixed mode)

? javac -version
javac 11.0.4

import java.util.ArrayList;
import java.util.Random;
import java.util.concurrent.TimeUnit;

public class App {

  public static void main(String[] args) {
    final int size = 10_000;
    final int iterations = 1_000_000;
    final var data = integerListWithRandomValues(size);

    //arraySumInlined(iterations, data);
    arraySumSubFunctionCall(iterations, data);
  }

  private static void arraySumSubFunctionCall(int iterations,
      final ArrayList<Integer> data) {
    final long start = System.nanoTime();
    long result = 0;
    for (int i = 0; i < iterations; ++i) {
      result = getSum(data);
    }
    final long end = System.nanoTime();
    System.out.println(String.format("%f sec (%d)",
        TimeUnit.NANOSECONDS.toMillis(end - start) / 1000.0, result));
  }

  private static void arraySumInlined(int iterations,
      final ArrayList<Integer> data) {
    final long start = System.nanoTime();
    long result = 0;
    for (int i = 0; i < iterations; ++i) {
      result = data.stream().mapToInt(e -> e).sum();
    }
    final long end = System.nanoTime();
    System.out.println(String.format("%f sec (%d)",
        TimeUnit.NANOSECONDS.toMillis(end - start) / 1000.0, result));
  }

  private static int getSum(final ArrayList<Integer> data) {
    return data.stream().mapToInt(e -> e).sum();
  }

  private static ArrayList<Integer> integerListWithRandomValues(final int size) {
    final var result = new ArrayList<Integer>();
    final var r = new Random();

    for (int i = 0; i < size; ++i) {
      result.add(r.nextInt());
    }

    return result;
  }
}

Answer 1

我对你的代码做了一些实验，这是我的结论：

1-如果您先将 arraySumSubFunctionCall() 放在 main() 中，然后再将 arraySumInlined() 放在 main() 中，那么执行时间会恢复到不同的状态：

public static void main(String[] args) {
    ...
    arraySumSubFunctionCall(iterations, data);
    arraySumInlined(iterations, data); 
}

这意味着 JIT 编译器优化发生在 arraySumInlined() 中，然后可以应用于 arraySumSubFunctionCall()。

2-如果在 getSum() 和 arraySumInlined() 中将常量 data.stream().mapToInt(e -> e).sum() 替换为真正的动态变量，例如 new Random().nextInt() ，则执行时间arraySumSubFunctionCall() 和 arraySumInlined() 又恢复到相同状态。

private static void arraySumInlined(int iterations,
      final ArrayList<Integer> data) {
    ...
    for (int i = 0; i < iterations; ++i) {
      result = new Random().nextInt();
    }
    ...
}


private static int getSum(final ArrayList<Integer> data) {
    return new Random().nextInt();
}

这意味着常量 data.stream().mapToInt(e -> e).sum() 是在 arraySumInlined() 中优化的内容，然后应用于 arraySumSubFunctionCall() 。

在现实生活中，我认为在本地 for 循环中重新计算 N 次相同的值并不经常发生，因此如果需要代码准备，您不应该被提取方法重构吓到。