Java 8 的流 : why parallel stream is slower?

Question

我正在使用 Java 8 的流，无法理解我得到的性能结果。我有 2 核 CPU (Intel i73520M)、Windows 8 x64 和 64 位 Java 8 update 5。我正在对字符串流/并行流进行简单映射，发现并行版本有点慢。

Function<Stream<String>, Long> timeOperation = (Stream<String> stream) -> {
  long time1 = System.nanoTime();
  final List<String> list = 
     stream
       .map(String::toLowerCase)
       .collect(Collectors.toList());
  long time2 = System.nanoTime();
  return time2 - time1;
};

Consumer<Stream<String>> printTime = stream ->
  System.out.println(timeOperation.apply(stream) / 1000000f);

String[] array = new String[1000000];
Arrays.fill(array, "AbabagalamagA");

printTime.accept(Arrays.stream(array));            // prints around 600
printTime.accept(Arrays.stream(array).parallel()); // prints around 900

考虑到我有 2 个 CPU 核心，并行版本不是应该更快吗？有人可以告诉我为什么并行版本速度较慢吗？

Answer 1

可以说，这里同时发生了几个问题。

首先，并行解决问题总是需要执行比顺序执行更多的实际工作。开销涉及将工作分配给多个线程以及连接或合并结果。像将短字符串转换为小写这样的问题足够小，以至于它们有被并行拆分开销淹没的危险。

第二个问题是Java程序的基准测试非常微妙，很容易得到令人困惑的结果。两个常见问题是 JIT 编译和死代码消除。短基准测试通常在 JIT 编译之前或期间完成，因此它们不会测量峰值吞吐量，实际上它们可能会测量 JIT 本身。编译何时发生在某种程度上是不确定的，因此它也可能导致结果差异很大。

对于小型综合基准测试，工作负载通常会计算出被丢弃的结果。 JIT 编译器非常擅长检测这一点并消除不会产生可在任何地方使用的结果的代码。在这种情况下，这种情况可能不会发生，但如果您修改其他合成工作负载，这种情况肯定会发生。当然，如果 JIT 消除了基准测试工作负载，那么基准测试就变得毫无用处。

我强烈建议使用成熟的基准测试框架，例如 JMH，而不是手动构建自己的基准测试框架。 JMH 拥有有助于避免常见基准测试陷阱(包括这些陷阱)的设施，并且设置和运行非常容易。以下是转换为使用 JMH 的基准测试:

package com.stackoverflow.questions;

import java.util.Arrays;
import java.util.List;
import java.util.stream.Collectors;
import java.util.concurrent.TimeUnit;

import org.openjdk.jmh.annotations.*;

public class SO23170832 {
    @State(Scope.Benchmark)
    public static class BenchmarkState {
        static String[] array;
        static {
            array = new String[1000000];
            Arrays.fill(array, "AbabagalamagA");
        }
    }

    @GenerateMicroBenchmark
    @OutputTimeUnit(TimeUnit.SECONDS)
    public List<String> sequential(BenchmarkState state) {
        return
            Arrays.stream(state.array)
                  .map(x -> x.toLowerCase())
                  .collect(Collectors.toList());
    }

    @GenerateMicroBenchmark
    @OutputTimeUnit(TimeUnit.SECONDS)
    public List<String> parallel(BenchmarkState state) {
        return
            Arrays.stream(state.array)
                  .parallel()
                  .map(x -> x.toLowerCase())
                  .collect(Collectors.toList());
    }
}

我使用以下命令运行此命令:

java -jar dist/microbenchmarks.jar ".*SO23170832.*" -wi 5 -i 5 -f 1

(这些选项表示五次预热迭代、五次基准测试迭代和一次 fork JVM。)在运行期间，JMH 会发出大量详细消息，我已将其省略。总结结果如下。

Benchmark                       Mode   Samples         Mean   Mean error    Units
c.s.q.SO23170832.parallel      thrpt         5        4.600        5.995    ops/s
c.s.q.SO23170832.sequential    thrpt         5        1.500        1.727    ops/s

请注意，结果以每秒操作数为单位，因此看起来并行运行比顺序运行快大约三倍。但我的机器只有两个核心。嗯。每次运行的平均错误实际上比平均运行时间更大!瓦特？这里发生了一些可疑的事情。

这给我们带来了第三个问题。更仔细地观察工作负载，我们可以看到它为每个输入分配一个新的 String 对象，并且还将结果收集到一个列表中，这涉及大量的重新分配和复制。我猜这会导致大量的垃圾收集。我们可以通过启用 GC 消息重新运行基准测试来看到这一点:

java -verbose:gc -jar dist/microbenchmarks.jar ".*SO23170832.*" -wi 5 -i 5 -f 1

这会产生如下结果:

[GC (Allocation Failure)  512K->432K(130560K), 0.0024130 secs]
[GC (Allocation Failure)  944K->520K(131072K), 0.0015740 secs]
[GC (Allocation Failure)  1544K->777K(131072K), 0.0032490 secs]
[GC (Allocation Failure)  1801K->1027K(132096K), 0.0023940 secs]
# Run progress: 0.00% complete, ETA 00:00:20
# VM invoker: /Users/src/jdk/jdk8-b132.jdk/Contents/Home/jre/bin/java
# VM options: -verbose:gc
# Fork: 1 of 1
[GC (Allocation Failure)  512K->424K(130560K), 0.0015460 secs]
[GC (Allocation Failure)  933K->552K(131072K), 0.0014050 secs]
[GC (Allocation Failure)  1576K->850K(131072K), 0.0023050 secs]
[GC (Allocation Failure)  3075K->1561K(132096K), 0.0045140 secs]
[GC (Allocation Failure)  1874K->1059K(132096K), 0.0062330 secs]
# Warmup: 5 iterations, 1 s each
# Measurement: 5 iterations, 1 s each
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Throughput, ops/time
# Benchmark: com.stackoverflow.questions.SO23170832.parallel
# Warmup Iteration   1: [GC (Allocation Failure)  7014K->5445K(132096K), 0.0184680 secs]
[GC (Allocation Failure)  7493K->6346K(135168K), 0.0068380 secs]
[GC (Allocation Failure)  10442K->8663K(135168K), 0.0155600 secs]
[GC (Allocation Failure)  12759K->11051K(139776K), 0.0148190 secs]
[GC (Allocation Failure)  18219K->15067K(140800K), 0.0241780 secs]
[GC (Allocation Failure)  22167K->19214K(145920K), 0.0208510 secs]
[GC (Allocation Failure)  29454K->25065K(147456K), 0.0333080 secs]
[GC (Allocation Failure)  35305K->30729K(153600K), 0.0376610 secs]
[GC (Allocation Failure)  46089K->39406K(154624K), 0.0406060 secs]
[GC (Allocation Failure)  54766K->48299K(164352K), 0.0550140 secs]
[GC (Allocation Failure)  71851K->62725K(165376K), 0.0612780 secs]
[GC (Allocation Failure)  86277K->74864K(184320K), 0.0649210 secs]
[GC (Allocation Failure)  111216K->94203K(185856K), 0.0875710 secs]
[GC (Allocation Failure)  130555K->114932K(199680K), 0.1030540 secs]
[GC (Allocation Failure)  162548K->141952K(203264K), 0.1315720 secs]
[Full GC (Ergonomics)  141952K->59696K(159232K), 0.5150890 secs]
[GC (Allocation Failure)  105613K->85547K(184832K), 0.0738530 secs]
1.183 ops/s

注意:以# 开头的行是正常的JMH 输出行。其余的都是GC消息。这只是五次预热迭代中的第一次，它先于五次基准迭代。在其余的迭代中，GC 消息继续以同样的方式进行。我认为可以肯定地说，所测量的性能主要由 GC 开销决定，并且报告的结果不应该被相信。

目前还不清楚该怎么做。这纯粹是一个综合工作负载。与分配和复制相比，它显然只需要很少的 CPU 时间来完成实际工作。很难说你真正想在这里衡量什么。一种方法是提出一种不同的工作负载，在某种意义上更“真实”。另一种方法是更改​​堆和 GC 参数，以避免在基准测试运行期间发生 GC。