这里有几个问题同时存在。
首先,以并行方式解决问题始终涉及执行更多的实际工作而不是顺序执行。在将工作分配给多个线程并合并结果时会涉及到开销。像将短字符串转换为小写之类的问题非常小,容易被并行拆分的开销淹没。
第二个问题是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
选项指定了五个热身迭代、五个基准测试迭代和一个分叉的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
请注意结果以每秒操作数为单位,因此并行运行似乎比顺序运行快了约三倍。但我的机器只有两个核心。嗯。每次运行的平均误差实际上比平均运行时间还要大!什么?这里有些可疑。
这带我们来到第三个问题。更仔细地查看工作负载,我们可以看到它为每个输入分配一个新的字符串对象,并将结果收集到列表中,这涉及大量的重新分配和复制。我猜这会导致相当数量的垃圾回收。我们可以通过启用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]
[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]
[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。
package com.stackoverflow.questions;
,public class SO23170832
。 - drac_o