Benchmarks are run under intel core i5, Ubuntu
java version "1.8.0_144"
Java(TM) SE Runtime Environment (build 1.8.0_144-b01)
Java HotSpot(TM) 64-Bit Server VM (build 25.144-b01, mixed mode)
I'm comparing performance of Collectors.counting
and Collectors.summingLong(x -> 1L)
. Here is the benchmark:
public List<Integer> ints = new ArrayList<>();
Collector<Integer, ?, Long> counting = Collectors.counting();
Collector<Integer, ?, Long> summingLong = Collectors.summingLong(x -> 1L);
@Setup
public void setup() throws Exception{
ints.add(new Random().nextInt(1000));
ints.add(new Random().nextInt(1000));
ints.add(new Random().nextInt(1000));
ints.add(new Random().nextInt(1000));
ints.add(new Random().nextInt(1000));
ints.add(new Random().nextInt(1000));
ints.add(new Random().nextInt(1000));
ints.add(new Random().nextInt(1000));
ints.add(new Random().nextInt(1000));
ints.add(new Random().nextInt(1000));
}
@Benchmark
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@BenchmarkMode(Mode.AverageTime)
public Long counting() {
return ints.stream().collect(counting);
}
@Benchmark
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@BenchmarkMode(Mode.AverageTime)
public Long summingLong() {
return ints.stream().collect(summingLong);
}
I got the result that Collectors.counting
3 times slower Collectors.summingLong
.
So I ran it with -prof perfnorm
with 25 forks. Here is the result:
Benchmark Mode Cnt Score Error Units
MyBenchmark.counting avgt 125 87.115 ± 3.787 ns/op
MyBenchmark.counting:CPI avgt 25 0.310 ± 0.011 #/op
MyBenchmark.counting:L1-dcache-load-misses avgt 25 1.963 ± 0.171 #/op
MyBenchmark.counting:L1-dcache-loads avgt 25 258.716 ± 41.458 #/op
MyBenchmark.counting:L1-dcache-store-misses avgt 25 1.890 ± 0.168 #/op
MyBenchmark.counting:L1-dcache-stores avgt 25 131.344 ± 16.433 #/op
MyBenchmark.counting:L1-icache-load-misses avgt 25 0.035 ± 0.007 #/op
MyBenchmark.counting:LLC-loads avgt 25 0.411 ± 0.143 #/op
MyBenchmark.counting:LLC-stores avgt 25 0.007 ± 0.001 #/op
MyBenchmark.counting:branch-misses avgt 25 0.029 ± 0.017 #/op
MyBenchmark.counting:branches avgt 25 139.669 ± 21.901 #/op
MyBenchmark.counting:cycles avgt 25 261.967 ± 29.392 #/op
MyBenchmark.counting:dTLB-load-misses avgt 25 0.036 ± 0.003 #/op
MyBenchmark.counting:dTLB-loads avgt 25 258.111 ± 41.008 #/op
MyBenchmark.counting:dTLB-store-misses avgt 25 0.001 ± 0.001 #/op
MyBenchmark.counting:dTLB-stores avgt 25 131.394 ± 16.166 #/op
MyBenchmark.counting:iTLB-load-misses avgt 25 0.001 ± 0.001 #/op
MyBenchmark.counting:iTLB-loads avgt 25 0.001 ± 0.001 #/op
MyBenchmark.counting:instructions avgt 25 850.262 ± 113.228 #/op
MyBenchmark.counting:stalled-cycles-frontend avgt 25 48.493 ± 8.968 #/op
MyBenchmark.summingLong avgt 125 37.238 ± 0.194 ns/op
MyBenchmark.summingLong:CPI avgt 25 0.311 ± 0.002 #/op
MyBenchmark.summingLong:L1-dcache-load-misses avgt 25 1.793 ± 0.013 #/op
MyBenchmark.summingLong:L1-dcache-loads avgt 25 93.785 ± 0.640 #/op
MyBenchmark.summingLong:L1-dcache-store-misses avgt 25 1.727 ± 0.013 #/op
MyBenchmark.summingLong:L1-dcache-stores avgt 25 56.249 ± 0.408 #/op
MyBenchmark.summingLong:L1-icache-load-misses avgt 25 0.020 ± 0.003 #/op
MyBenchmark.summingLong:LLC-loads avgt 25 0.843 ± 0.117 #/op
MyBenchmark.summingLong:LLC-stores avgt 25 0.004 ± 0.001 #/op
MyBenchmark.summingLong:branch-misses avgt 25 0.008 ± 0.002 #/op
MyBenchmark.summingLong:branches avgt 25 61.472 ± 0.260 #/op
MyBenchmark.summingLong:cycles avgt 25 110.949 ± 0.784 #/op
MyBenchmark.summingLong:dTLB-load-misses avgt 25 0.031 ± 0.001 #/op
MyBenchmark.summingLong:dTLB-loads avgt 25 93.662 ± 0.616 #/op
MyBenchmark.summingLong:dTLB-store-misses avgt 25 ≈ 10⁻³ #/op
MyBenchmark.summingLong:dTLB-stores avgt 25 56.302 ± 0.351 #/op
MyBenchmark.summingLong:iTLB-load-misses avgt 25 0.001 ± 0.001 #/op
MyBenchmark.summingLong:iTLB-loads avgt 25 ≈ 10⁻³ #/op
MyBenchmark.summingLong:instructions avgt 25 357.029 ± 1.712 #/op
MyBenchmark.summingLong:stalled-cycles-frontend avgt 25 10.074 ± 1.096 #/op
What I noticed is this:
branches
, instructions
, cycles
differs almost 3 times. Also cache operations. Branches seems well predicted, also not too much cache misses (only my opinion).
So the issue might be with the compiled code. Ran it with -prof perfasm
(too long to put it here).
In compiled code I noticed the following:
I. Collectors.summingLong
assembly
We have 3 loops iterating through the array and counting. First counts just one element
0x00007f9abd226dfd: mov %edi,%ebp ;contains the iteration index
incl %ebp
;...
0x00007f9abd226e27: incl %edi
0x00007f9abd226e29: cmp %ebp,%edi
0x00007f9abd226e2b: jnl 0x7f9abd226e34 ;exit after the first iteration
Second counts 4 elements for 1 iteration (Is that loop unrolling?) and also exit after the first one.
0x00007f9abd226ea6: add $0x1,%rsi
;...
0x00007f9abd226ed0: add $0x2,%rsi
;...
0x00007f9abd226efa: add $0x3,%rsi
;...
0x00007f9abd226f1c: add $0x4,%rbx
;...
0x00007f9abd226f20: mov %rbx,0x10(%r14)
And the third counts the rest of elements.
II. Collectors.counting
assembly
We have only one loop counting all elements one-by-one (not unrolled). Also we have inlined boxing conversion inside the loop of the result of counting. Also we seem to have not inlined boxing conversion inside the loop
0x00007f80dd22dfb5: mov $0x1,%esi
0x00007f80dd22dfba: nop
0x00007f80dd22dfbb: callq 0x7f80dd046420
which seems performs boxing of the 1L
provided in lambda e -> 1L
. But this is not clear why. When performing the actual addition we have this code:
0x00007f80dd22dfec: mov $0x1,%r10d
0x00007f80dd22dff2: add 0x10(%r11),%r10
Also, we store the result of counting inside the stack mov %r10d,0x10(%rsp)
instead of the heap like in the first case.
If my undersatnding of what's going on is correct I have
QUESTION: Is that loop unrolling with boxing conversions caused 3 times slowdown? If so, why didn't runtime unroll the loop in the counting
case?
Notice that Collectors.summingLong
has 2.5 more GC pressure than Collectors.counting
. This is not quite clear (I could only guess that we store intermidiate values in the stack in Collectors.counting
).
MyBenchmark.counting avgt 5 96.956 ± 4.412 ns/op
MyBenchmark.counting:·gc.alloc.rate avgt 5 734.538 ± 33.083 MB/sec
MyBenchmark.counting:·gc.alloc.rate.norm avgt 5 112.000 ± 0.001 B/op
MyBenchmark.counting:·gc.churn.PS_Eden_Space avgt 5 731.423 ± 340.767 MB/sec
MyBenchmark.counting:·gc.churn.PS_Eden_Space.norm avgt 5 111.451 ± 48.411 B/op
MyBenchmark.counting:·gc.churn.PS_Survivor_Space avgt 5 0.017 ± 0.067 MB/sec
MyBenchmark.counting:·gc.churn.PS_Survivor_Space.norm avgt 5 0.003 ± 0.010 B/op
MyBenchmark.counting:·gc.count avgt 5 16.000 counts
MyBenchmark.counting:·gc.time avgt 5 12.000 ms
MyBenchmark.summingLong avgt 5 38.371 ± 1.733 ns/op
MyBenchmark.summingLong:·gc.alloc.rate avgt 5 1856.581 ± 81.706 MB/sec
MyBenchmark.summingLong:·gc.alloc.rate.norm avgt 5 112.000 ± 0.001 B/op
MyBenchmark.summingLong:·gc.churn.PS_Eden_Space avgt 5 1876.736 ± 192.503 MB/sec
MyBenchmark.summingLong:·gc.churn.PS_Eden_Space.norm avgt 5 113.213 ± 9.916 B/op
MyBenchmark.summingLong:·gc.churn.PS_Survivor_Space avgt 5 0.033 ± 0.072 MB/sec
MyBenchmark.summingLong:·gc.churn.PS_Survivor_Space.norm avgt 5 0.002 ± 0.004 B/op
MyBenchmark.summingLong:·gc.count avgt 5 62.000 counts
MyBenchmark.summingLong:·gc.time avgt 5 48.000 ms
I didn't look at the assembly or analyze it but a look at the sources already provides some information.
summingLong()
results in this collector:
new CollectorImpl<>(
() -> new long[1],
(a, t) -> { a[0] += mapper.applyAsLong(t); },
(a, b) -> { a[0] += b[0]; return a; },
a -> a[0], CH_NOID);
counting()
results in this:
new CollectorImpl<>(
boxSupplier(identity),
(a, t) -> { a[0] = op.apply(a[0], mapper.apply(t)); },
(a, b) -> { a[0] = op.apply(a[0], b[0]); return a; },
a -> a[0], CH_NOID);
As you can see, the counting()
version is doing some more things:
op.apply(...)
Since op
is Long::sum
which operates on primitives there's a lot of boxing and unboxing invoved.
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With