同样的代码,同样的输入,有时运行得很快,有时运行得很慢,为什么?

5
我写了一些Java类来评估/演示不同的排序算法。但是当我运行我的演示类时,我感到困惑。希望你们能给我一个解释。(这个问题不是作业。)
首先,我将列出与此问题相关的一些代码。
AbstractDemo
public abstract class AbstractDemo {
    protected final int BIG_ARRAY_SIZE = 20000;
    protected final int SMALL_ARRAY_SIZE = 14;
    protected Stopwatch stopwatch = new Stopwatch();

    public final void doDemo() {
        prepareDemo();
        specificDemo();
    }

    protected abstract void prepareDemo();

    protected abstract void specificDemo();

    protected final void printInfo(final String text) {
        System.out.println(text);
    }
}

排序演示

public class SortingDemo extends AbstractDemo {
    private static final String FMT = "%-10s| %-21s| %7s ms.";
    private static final String SPL = AlgUtil.lineSeparator('-', 45);
    private static final String SPLT = AlgUtil.lineSeparator('=', 45);

    private int[] data;

    private final List<Sorting> demoList = new LinkedList<Sorting>();

    @Override
    protected void specificDemo() {
        int[] testData;
        //*** this comment is interesting!!! for (int x = 1; x < 6; x++) {  

            printInfo(String.format("Sorting %7s elements", data.length));
            printInfo(SPLT);
            for (final Sorting sort : demoList) {

                // here I made a copy of the original Array, avoid to sort an already sorted array.
                testData = new int[data.length];
                System.arraycopy(data, 0, testData, 0, data.length);
                stopwatch.start();
                // sort
                sort.sort(testData);
                stopwatch.stop();
                printInfo(String.format(FMT, sort.getBigO(), sort.getClass().getSimpleName(), stopwatch.read()));
                printInfo(SPL);
                testData = null;
                stopwatch.reset();
            }
        //}
    }

    @Override
    protected void prepareDemo() {
        data = AlgUtil.getRandomIntArray(BIG_ARRAY_SIZE, BIG_ARRAY_SIZE * 5, false);
        demoList.add(new InsertionSort());
        demoList.add(new SelectionSort());
        demoList.add(new BubbleSort());
        demoList.add(new MergeSort());  //here is interesting too
        demoList.add(new OptimizedMergeSort());

    }

    public static void main(final String[] args) {
        final AbstractDemo sortingDemo = new SortingDemo();
        sortingDemo.doDemo();
    }
}

秒表

public class Stopwatch {
    private boolean running;
    private long startTime;
    private long elapsedMillisec;

    public void start() {
        if (!running) {
            this.startTime = System.currentTimeMillis();
            running = true;
        } else {
            throw new IllegalStateException("the stopwatch is already running");
        }
    }

    public void stop() {
        if (running) {
            elapsedMillisec = System.currentTimeMillis() - startTime;
            running = false;
        } else {
            throw new IllegalStateException("the stopwatch is not running");
        }
    }

    public void reset() {
        elapsedMillisec = 0;

    }

    public long read() {
        if (running) {
            elapsedMillisec = System.currentTimeMillis() - startTime;
        }
        return this.elapsedMillisec;
    }

}

生成随机数组的方法
public static int[] getRandomIntArray(final int len, final int max, boolean allowNegative) {
        final int[] intArray = new int[len];
        final Random rand = new Random();
        rand.setSeed(20100102);

        if (!allowNegative) {
            if (max <= 0) {
                throw new IllegalArgumentException("max must be possitive if allowNegative false");
            }
            for (int i = 0; i < intArray.length; i++) {
                intArray[i] = rand.nextInt(max);
            }
        } else {
            int n;
            int i = 0;
            while (i < len) {
                n = rand.nextInt();
                if (n < max) {
                    intArray[i] = n;
                    i++;
                }
            }
        }

        return intArray;
    }

您可以看到,我生成了一个由20000个元素组成的整数数组。由于在getRandomIntArray方法中我使用了一个固定的种子,每次调用它时都会获得相同的数组。类SortingDemo具有main方法,如果我运行这个类,我将得到以下输出:

Sorting   20000 elements
=============================================
O(n^2)    | InsertionSort        |     101 ms.
---------------------------------------------
O(n^2)    | SelectionSort        |     667 ms.
---------------------------------------------
O(n^2)    | BubbleSort           |    1320 ms.
---------------------------------------------
O(nlog(n))| MergeSort            |      39 ms.
---------------------------------------------
O(?)      | OptimizedMergeSort   |      11 ms.
---------------------------------------------

看起来不错。现在出现了一些让我困惑的东西。如果我改变SortingDemo中demoList.add()的顺序,例如:

demoList.add(new InsertionSort());
    demoList.add(new SelectionSort());
    demoList.add(new BubbleSort());
    // OptimizedMergeSort before Mergesort
    demoList.add(new OptimizedMergeSort()); 
    demoList.add(new MergeSort());

我得到了:

Sorting   20000 elements
=============================================
O(n^2)    | InsertionSort        |     103 ms.
---------------------------------------------
O(n^2)    | SelectionSort        |     676 ms.
---------------------------------------------
O(n^2)    | BubbleSort           |    1313 ms.
---------------------------------------------
O(?)      | OptimizedMergeSort   |      41 ms.
---------------------------------------------
O(nlog(n))| MergeSort            |      14 ms.
---------------------------------------------

为什么第二次运行的输出结果不同?OptimizedMergeSort比普通的MergeSort更耗时...

如果我取消SortingDemo中for (int x=1; x<6; x++)这一行的注释(使用相同的数组运行测试5次),我得到了以下结果:

Sorting   20000 elements
=============================================
O(n^2)    | InsertionSort        |     101 ms.
---------------------------------------------
O(n^2)    | SelectionSort        |     668 ms.
---------------------------------------------
O(n^2)    | BubbleSort           |    1311 ms.
---------------------------------------------
O(?)      | OptimizedMergeSort   |      37 ms.
---------------------------------------------
O(nlog(n))| MergeSort            |      10 ms.
---------------------------------------------

Sorting   20000 elements
=============================================
O(n^2)    | InsertionSort        |      94 ms.
---------------------------------------------
O(n^2)    | SelectionSort        |     665 ms.
---------------------------------------------
O(n^2)    | BubbleSort           |    1308 ms.
---------------------------------------------
O(?)      | OptimizedMergeSort   |       5 ms.
---------------------------------------------
O(nlog(n))| MergeSort            |       7 ms.
---------------------------------------------

Sorting   20000 elements
=============================================
O(n^2)    | InsertionSort        |     116 ms.
---------------------------------------------
O(n^2)    | SelectionSort        |     318 ms.
---------------------------------------------
O(n^2)    | BubbleSort           |     969 ms.
---------------------------------------------
O(?)      | OptimizedMergeSort   |       5 ms.
---------------------------------------------
O(nlog(n))| MergeSort            |      10 ms.
---------------------------------------------

Sorting   20000 elements
=============================================
O(n^2)    | InsertionSort        |     116 ms.
---------------------------------------------
O(n^2)    | SelectionSort        |     319 ms.
---------------------------------------------
O(n^2)    | BubbleSort           |     964 ms.
---------------------------------------------
O(?)      | OptimizedMergeSort   |       5 ms.
---------------------------------------------
O(nlog(n))| MergeSort            |       5 ms.
---------------------------------------------

Sorting   20000 elements
=============================================
O(n^2)    | InsertionSort        |     116 ms.
---------------------------------------------
O(n^2)    | SelectionSort        |     320 ms.
---------------------------------------------
O(n^2)    | BubbleSort           |     963 ms.
---------------------------------------------
O(?)      | OptimizedMergeSort   |       4 ms.
---------------------------------------------
O(nlog(n))| MergeSort            |       6 ms.
---------------------------------------------

对于其他的排序方法,结果看起来很合理。但对于MergeSort,为什么第一次运行比后面的时间长得多? OptimizedMergeSort的时间是37ms:4ms。
我认为即使Optimized / MergeSort的实现有误,输出也应该保持不变,为什么有时相同方法调用需要更长的时间,有时则需要更短的时间?
所有这些*Sort类都继承一个超级抽象类Sorting。它具有一个抽象方法void sort(int[] data)
MergeSort有mergeSorting方法和合并() 方法。 OptimizedMergeSort扩展了MergeSort,并重写了mergeSorting() 方法(因为当数组大小<=7时,它将进行insertionSort),并从MergeSort类中重用了merge() 方法。
感谢您阅读这篇长文和代码。如果您能给我一些解释,我会非常感激。
所有测试都在Linux下的Eclipse中完成。

MergeSort和OptimizedMergeSort是否共享代码?如果是这样,那么您很可能会看到jit编译的影响。在Java中编写准确的微基准测试非常困难(由于jit),有许多文章专门研究此主题。 - jtahlborn
@minitech 感谢您的评论。我认为随机数不会影响结果,因为 prepareDemo 只被调用了一次。无论它得到什么样的随机数,对于所有排序来说都是同一个数组。 - Kent
@jtahlborn 是的,正如我在问题中所写的那样,OptimizedMS是MS的子类,它们共享合并方法(在MS类中受保护)。感谢jit提示,我会搜索并阅读相关内容。 - Kent
可能是您的程序在那个点进行了垃圾回收或其他外部因素造成的影响。请注意,您在每次运行后都会丢弃“testData”,这将不得不在某个时候进行垃圾回收。 - Paul Tomblin
@Kent - 只需循环几次所有测试并打印最后一组时间即可。 - jtahlborn
3个回答

4
微基准测试Java代码非常棘手。
很可能即时编译器在某个时刻将您的Java字节码编译成本机机器代码。每次编译都需要时间,但是生成的代码很可能运行得更快。
还有其他陷阱,但我认为上述情况最有可能发生在您的情况中。
以下SO答案是非常好的阅读:https://dev59.com/hHRB5IYBdhLWcg3wz6UK#513259

这是我第一次遇到JIT问题。我会先阅读一些资料。你提供的链接会很有帮助。感谢你指引我方向。 - Kent

1

基本上,有两个可能的原因,都与环境有关,而不是您的程序:其他东西占用了大量空间,或者其他东西占用了大量CPU时间。

在第一种情况下,您有一些其他程序消耗物理内存,导致您的程序更频繁地进行页面和/或垃圾回收。

在第二种情况下,如果您正在运行Mac,则会有一些其他程序(我敢打赌是Time Machine)间歇性地运行并消耗CPU。

无论如何,您可以开始使用Java附带的工具来找出问题所在。 jconsole和VirtualVM是很好的选择。

通常,在出现性能问题时,需要采取三个关键步骤:测量,测量和测量。

更新

我同意JIT可能会产生差异,但我得到的印象是这些是单独的运行;每次都会调用新的JVM。 这最小化了JIT的影响。


我同意Charlie Martin的观点。此外,两次运行之间的时间差非常小,这一点并不奇怪。 - Boundless
每个运行组都在同一个JVM中。很明显是JIT。 - jtahlborn
不,@jtahlborn,并不是“明显”的JIT - 这是可能的或者合理的JIT。没有实验基础来隔离出JIT以及其他影响。即使它在一个JVM实例中运行,JIT也不是JVM中唯一潜在的影响因素。正如我所说,“测量!”业余人士只会断言性能问题所在;专业人士才会测量。 - Charlie Martin
这个结果我可以随时重现。所以我猜这不可能是空间/CPU时间问题?顺便说一下,所有的测试都是在Linux(Archlinux i686)操作系统下的Eclipse中进行的。 - Kent
你有测量过吗?他说,揉了揉眼睛。但是,更可能是JVM的行为。你甚至可以尝试关闭JIT编译器,看看会发生什么。 - Charlie Martin
请查看此页面:http://www.oracle.com/technetwork/java/javase/tech/vmoptions-jsp-140102.html 考虑尝试-XX:-CITime。或者查看此页面http://docs.oracle.com/javase/1.5.0/docs/tooldocs/solaris/java.html并考虑尝试-Xprof。或阅读此文http://java.sun.com/developer/onlineTraining/Programming/JDCBook/perf2.html并尝试-Djava.compiler = none。 - Charlie Martin

0
为了减少JIT的影响,您可以对每个测试丢弃最初的几次运行。此外,为了获得更准确的结果,请在100或1000次运行中取平均值。
在开始测量之前,您还可以执行System.gc()和Thread.yeild()。如果您只打算测试几次迭代,请使用system.nanoTime()而不是system.currentTimeMillis(后者不够准确)。

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接