为什么 JMH 会针对简单的快速排序报告如此奇怪的时间——显然与 N * log(N) 不成比例?

Why does JMH report such strange times for a simple Quicksort --obviously disproportionate to N * log(N)?

出于研究(我自己的)排序算法的意图,我决定将其性能与经典 quicksort 进行比较,令我大吃一惊的是,我发现我实现quicksortN log(N)远不成正比。我彻底地试图在我的 quicksort 中找到一个错误,但没有成功。它是排序算法的简单版本,使用不同大小的 Integer 数组,填充随机数,我不知道错误可能潜入何处。我什至计算了所有执行的比较和交换根据我的代码,它们的数量与 N log(N) 相当成正比。我完全糊涂了,无法理解我观察到的现实。以下是对包含 1,000、2,000、4,000、8,000 和 16,000 个随机值的数组进行排序的基准测试结果(用 JMH 测量):

Benchmark                       Mode  Cnt       Score     Error  Units    2N / N ratio          
QSortBenchmarks.sortArray01000  avgt    5     561.505 ±   2.992  us/op              
QSortBenchmarks.sortArray02000  avgt    5    2433.307 ±  11.770  us/op    4.334 
QSortBenchmarks.sortArray04000  avgt    5    8510.448 ±  34.051  us/op    3.497 
QSortBenchmarks.sortArray08000  avgt    5   38269.492 ± 161.010  us/op    4.497 
QSortBenchmarks.sortArray16000  avgt    5  147132.524 ± 261.963  us/op    3.845 

显然我观察到的时间复杂度与O(n log(n))相去甚远,几乎O(n^2)。可能有最微小的怀疑,即随机种子的降临如此不幸,以至于数组中的值恰好接近最坏情况。这个概率非常接近于0,但不是0。但是用几个不同的随机种子的结果与那个非常相似。

这里是比较和交换的次数(40 次迭代,每个大小的数组随机填充):

                     Avr. Comparisons      Avr. Swaps                     2N / N ratio
sortArray01000():           12119.925,       2398.925             
sortArray02000():           26581.600,       5268.525                     2.193, 2.196
sortArray04000():           59866.925,      11451.625                     2.252, 2.174
sortArray08000():          127731.025,      25006.425                     2.134, 2.184
sortArray16000():          273409.925,      54481.525                     2.141, 2.179

大家可以看到,运算次数比较符合O(Nlog(N))规律

甚至有可能怀疑单个操作的成本取决于我们处理的数组的大小,我已经检查过它是否属实(使用一种简单的方法来反转不同大小的数组)- - 不,正如预期的那样,事实并非如此。时间非常接近O(n)

我唯一能想到的是我的代码中有一些棘手的逻辑错误,但我想不通。

有人可以帮我吗?

代码如下:

import java.io.IOException;
import java.util.Locale;
import java.util.Random;
import java.util.function.Consumer;

import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;

/**
 * Why does quicksort take time disproportionate to N * log(N)?
 * Rectified for Whosebug
 * 21.05.17 16:20:01
 */

@State(value = Scope.Benchmark)
@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(java.util.concurrent.TimeUnit.MICROSECONDS)
@Fork(value = 2)
@Warmup(iterations = 5, time = 10)
@Measurement(iterations = 5, time = 10)
public class QSortBenchmarks {

  private static final int LOOPS_TO_ITERATE = 40; // 40;

  private static final int RAND_SEED = 123456789;
  private static final int RAND_LIMIT = 10000;
  private static final Random RAND = new Random(RAND_SEED); // Constant seed for reproducibility;

  private static int cmpCount = 0, swapCount = 0;
  private static int cmpTotal = 0, swapTotal = 0;

  private static final Integer[] array01000 = new Integer[1000];
  private static final Integer[] array02000 = new Integer[2000];
  private static final Integer[] array04000 = new Integer[4000];
  private static final Integer[] array08000 = new Integer[8000];
  private static final Integer[] array16000 = new Integer[16000];

  @Setup
  public static void initData() {
    cmpCount = 0; swapCount = 0;

    fillWithRandoms(array01000);
    fillWithRandoms(array02000);
    fillWithRandoms(array04000);
    fillWithRandoms(array08000);
    fillWithRandoms(array16000);
  }

  public static void main(String[] args) throws IOException, RunnerException {
    Locale.setDefault(Locale.US);
    initData();

    runJMH(); // Run benchmarks. Comment-out it, if you want just to count comparisons etc.
//    System.exit(0); // If don't want to count comparisons and swaps

    System.out.printf("\nRand seed = %d, rand limit = %d, iterations = %d\n",
                      RAND_SEED, RAND_LIMIT, LOOPS_TO_ITERATE);

    System.out.print("sortArray01000(): ");
    loopOverMethod(qq -> sortArray01000());

    System.out.print("sortArray02000(): ");
    loopOverMethod(qq -> sortArray02000());

    System.out.print("sortArray04000(): ");
    loopOverMethod(qq -> sortArray04000());

    System.out.print("sortArray08000(): ");
    loopOverMethod(qq -> sortArray08000());

    System.out.print("sortArray16000(): ");
    loopOverMethod(qq -> sortArray16000());
  }

  private static void loopOverMethod(Consumer<Object> method) {
    cmpTotal = 0; swapTotal = 0;
    for (int loops = 0; loops < LOOPS_TO_ITERATE; loops++ ) {
      initData();
      method.accept(null);;
      cmpTotal += cmpCount; swapTotal += swapCount;
    }
    System.out.printf("avrg compares: %12.3f,  swaps: %12.3f\n",
                      (double)cmpTotal / LOOPS_TO_ITERATE, (double)swapTotal / LOOPS_TO_ITERATE);
  }

  /**
   * @throws RunnerException
   */
  private static void runJMH() throws RunnerException {
    final Options opt = new OptionsBuilder()
        .include(QSortBenchmarks.class.getSimpleName())
        .forks(1)
        .build();
    new Runner(opt).run();
  }

  private static void fillWithRandoms(Integer[] array) {
    for (int i = 0; i < array.length; i++) { // // Fill it with LIST_SIZE random values
      array[i] = (int)(RAND.nextDouble() * RAND_LIMIT);
    }
  }

  @Benchmark
  public static void sortArray01000() {
    final Integer[] array = array01000;
    quickSort(array, 0, array.length - 1);
  }

  @Benchmark
  public static void sortArray02000() {
    final Integer[] array = array02000;
    quickSort(array, 0, array.length - 1);
  }

  @Benchmark
  public static void sortArray04000() {
    final Integer[] array = array04000;
    quickSort(array, 0, array.length - 1);
  }

  @Benchmark
  public static void sortArray08000() {
    final Integer[] array = array08000;
    quickSort(array, 0, array.length - 1);
  }

  @Benchmark
  public static void sortArray16000() {
    final Integer[] array = array16000;
    quickSort(array, 0, array.length - 1);
  }

  private static void quickSort(Integer[] array, int lo, int hi) {
    if (hi <= lo) return;
    final int j = partition(array, lo, hi);
    quickSort(array, lo, j - 1);
    quickSort(array, j + 1, hi);
  }

  private static int partition(Integer[] array, int lo, int hi) {
    int i = lo, j = hi + 1;
    while (true) {
      while (compare(array[++i], array[lo]) < 0) // while (array[++i] < array[lo])
        if (i == hi) break;
      while (compare(array[lo], array[--j]) < 0) // while (array[lo] < array[--j])
        if (j == lo) break;
      if (i >= j) break;
      swapItems(array, i, j);
    }
    swapItems(array, lo, j);
    return j;
  }

  private static int compare(Integer v1, Integer v2) {
    cmpCount++;
    return v1.compareTo(v2);
  }

  private static void swapItems(Integer[] array, int i, int j) {
    swapCount++;
    final Integer tmp = array[i];
    array[i] = array[j];
    array[j] = tmp;
  }

}

更新 21-05-18 10:08Z

情况已经明朗。 JMH 显示了如此奇怪的结果,与实际执行时间毫无共同之处。使用 System.nanoTime() 的简单手工基准测试,对于 10,000、20,000、40,000、80,000 和 160,000 个项目的数组,显示以下时间:

Rand seed = 123, rand limit = 1000000, iterations = 1000
sortArray_010k(): avrg time:    1049.538 mks/op
sortArray_020k(): avrg time:    2282.189 mks/op
sortArray_040k(): avrg time:    4976.079 mks/op
sortArray_080k(): avrg time:   10762.461 mks/op
sortArray_160k(): avrg time:   23115.345 mks/op

而相同数组的 JMH 结果如下:

Benchmark                       Mode  Cnt      Score     Error  Units
QSortBenchmarks.sortArray_010k  avgt    5    109.454 ±   0.444  ms/op
QSortBenchmarks.sortArray_020k  avgt    5    373.518 ±  17.439  ms/op
QSortBenchmarks.sortArray_040k  avgt    5   1350.420 ±  26.733  ms/op
QSortBenchmarks.sortArray_080k  avgt    5   6519.015 ±  48.770  ms/op
QSortBenchmarks.sortArray_160k  avgt    5  26837.697 ± 926.132  ms/op

手工制作的基准测试显示的数字非常符合 N log(N),看起来很逼真,并且与观察到的执行时间(以秒为单位)非常吻合。而且比JMH.

的数字少了100倍到1000多倍

这是获得它们的修改后的loopOverMethod()

  private static void loopOverMethod(Consumer<Object> method) {
    for (int loops = 0; loops < 100; loops++ ) { // Kinda warmup
      initData();
      method.accept(null);
    }

    long time = 0;
    cmpTotal = 0; swapTotal = 0;
    for (int loops = 0; loops < LOOPS_TO_ITERATE; loops++ ) {
      initData();
      time -= System.nanoTime();
      method.accept(null);
      time += System.nanoTime();
      cmpTotal += cmpCount; swapTotal += swapCount;
    }
    System.out.printf("avrg time: \t%10.3f mks\n", 
                      time * 1e-3 / LOOPS_TO_ITERATE);
  }

但是现在又出现了一个问题。为什么 JMH 显示如此奇怪的结果?我使用它的方式有什么问题?显然我必须修改我使用 JMH 的其他项目。倒是个不愉快的消息。


更新 21-05-19 10:08Z

把它放在这里作为问题的更新,因为评论不允许插入引号。 Thomas Kleger 给出的全面答案是绝对正确的。按照他的建议,我得到了以下结果:

JMH:

Benchmark                       Mode  Cnt      Score    Error  Units
QSortBenchmarks.sortArray_010k  avgt    5    975.028 ± 23.907  us/op
QSortBenchmarks.sortArray_020k  avgt    5   2253.627 ± 94.108  us/op
QSortBenchmarks.sortArray_040k  avgt    5   4836.680 ± 80.964  us/op
QSortBenchmarks.sortArray_080k  avgt    5  10041.063 ± 27.796  us/op
QSortBenchmarks.sortArray_160k  avgt    5  21232.223 ± 32.008  us/op

手工制作的基准:

Rand seed = 123, rand limit = 1000000, iterations = 1000
sortArray_010k(): avrg time:    1060.951 mks
sortArray_020k(): avrg time:    2296.533 mks
sortArray_040k(): avrg time:    5021.629 mks
sortArray_080k(): avrg time:   10855.963 mks
sortArray_160k(): avrg time:   23335.923 mks

现在的结果看起来很合理,我对它们完全满意。

三点共同作用于您的实施:

In the very early versions of quicksort, the leftmost element of the partition would often be chosen as the pivot element. Unfortunately, this causes worst-case behavior on already sorted arrays

  • 您的算法就地对数组进行排序,这意味着在第一次通过后对“随机”数组进行排序。 (为了计算 JMH 对数据进行多次传递的平均时间)。

要解决此问题,您可以更改基准测试方法。例如,您可以将 sortArray01000() 更改为

@Benchmark
public static void sortArray01000() {
  final Integer[] array = Arrays.copyOf(array01000, array01000.length);
  quickSort(array, 0, array.length - 1);
}

或者您可以修改 @Setup 注释,以便在每次调用基准方法之前执行它:

@Setup(Level.Invocation)
public static void initData() {
    //...
}

@Setup 注释采用一个参数来确定何时执行设置方法。

三个级别是(https://hg.openjdk.java.net/code-tools/jmh/file/2be2df7dbaf8/jmh-core/src/main/java/org/openjdk/jmh/annotations/Level.java):

  • Level.Trial:每个基准测试前
  • Level.Iteration:每次迭代前
  • Level.Invocation:在每次执行基准方法之前

默认级别为Level.Trial (https://hg.openjdk.java.net/code-tools/jmh/file/2be2df7dbaf8/jmh-core/src/main/java/org/openjdk/jmh/annotations/Setup.java#l54)。

这对你的测试意味着什么?

要理解这一点,您必须了解 JMH 如何执行您的基准测试:

  • 它开始试用您的一种基准方法
  • 在此试验期间,它进行了 5 次预热迭代和 5 次测量迭代
  • 在每次迭代期间,它会在一个紧密循环中调用您的基准方法,直到 10 秒过去 - 如果您的基准方法需要 500us,这意味着它将在每次迭代期间被调用大约 20'000 次,或大约 200'000 次全面试用期间

现在有了 @Setup(Level.Trial) 和一个对输入数据进行适当排序的基准方法,这意味着只有第一次调用快速排序方法才能显示 O(N log(N)) 行为,所有剩余的调用都会运行在已经排序的数组上并显示 O(N^2).

的最坏情况行为

使用 @Setup(Level.Iteration) 情况仍然好不了多少 - 现在是每次迭代中基准方法的第一次调用具有 O(N log(N)) 行为,每次迭代剩余约 20'000 次调用仍然显示 O(N^2).

使用 @Setup(Level.Invocation) 最终,基准方法的每次调用(以及快速排序的每次调用)都会获得自己的未排序数组作为输入,这清楚地显示在结果中:

@Setup(Level.Trial)

1000: 780 us
2000: 3300 us


@Setup(Level.Iteration)

1000: 780 us
2000: 3280 us
4000: 11700 us


@Setup(Level.Invocation)

1000: 58 us
2000: 124 us
4000: 280 us

根据我提议的更改(在基准方法中复制输入数组),我得到了稍微好一些的结果,但这可能是由于缓存效应:

1000: 25 us
2000: 108 us
4000: 260 us