Why is StringBuilder#append(int) faster in Java 7 than in Java 8?
While investigating for a little debate w.r.t. using "" + n and Integer.toString(int) to convert an integer primitive to a string I wrote this JMH microbenchmark:
@Fork(1)
@OutputTimeUnit(TimeUnit.MILLISECONDS)
@State(Scope.Benchmark)
public class IntStr {
protected int counter;
@GenerateMicroBenchmark
public String integerToString() {
return Integer.toString(this.counter++);
}
@GenerateMicroBenchmark
public String stringBuilder0() {
return new StringBuilder().append(this.counter++).toString();
}
@GenerateMicroBenchmark
public String stringBuilder1() {
return new StringBuilder().append("").append(this.counter++).toString();
}
@GenerateMicroBenchmark
public String stringBuilder2() {
return new StringBuilder().append("").append(Integer.toString(this.counter++)).toString();
}
@GenerateMicroBenchmark
public String stringFormat() {
return String.format("%d", this.counter++);
}
@Setup(Level.Iteration)
public void prepareIteration() {
this.counter = 0;
}
}
I ran it with the default JMH options with both Java VMs that exist on my Linux machine (up-to-date Mageia 4 64-bit, Intel i7-3770 CPU, 32GB RAM). The first JVM was the one supplied with Oracle JDK 8u5 64-bit:
java version "1.8.0_05"
Java(TM) SE Runtime Environment (build 1.8.0_05-b13)
Java HotSpot(TM) 64-Bit Server VM (build 25.5-b02, mixed mode)
With this JVM I got pretty much what I expected:
Benchmark Mode Samples Mean Mean error Units
b.IntStr.integerToString thrpt 20 32317.048 698.703 ops/ms
b.IntStr.stringBuilder0 thrpt 20 28129.499 421.520 ops/ms
b.IntStr.stringBuilder1 thrpt 20 28106.692 1117.958 ops/ms
b.IntStr.stringBuilder2 thrpt 20 20066.939 1052.937 ops/ms
b.IntStr.stringFormat thrpt 20 2346.452 37.422 ops/ms
I.e. using the StringBuilder class is slower due to the additional overhead of creating the StringBuilder object and appending an empty string. Using String.format(String, ...) is even slower, by an order of magnitude or so.
The distribution-provided compiler, on the other hand, is based on OpenJDK 1.7:
java version "1.7.0_55"
OpenJDK Runtime Environment (mageia-2.4.7.1.mga4-x86_64 u55-b13)
OpenJDK 64-Bit Server VM (build 24.51-b03, mixed mode)
The results here were interesting:
Benchmark Mode Samples Mean Mean error Units
b.IntStr.integerToString thrpt 20 31249.306 881.125 ops/ms
b.IntStr.stringBuilder0 thrpt 20 39486.857 663.766 ops/ms
b.IntStr.stringBuilder1 thrpt 20 41072.058 484.353 ops/ms
b.IntStr.stringBuilder2 thrpt 20 20513.913 466.130 ops/ms
b.IntStr.stringFormat thrpt 20 2068.471 44.964 ops/ms
Why does StringBuilder.append(int) appear so much faster with this JVM? Looking at the StringBuilder class source code revealed nothing particularly interesting - the method in question is almost identical to Integer#toString(int). Interestingly enough, appending the result of Integer.toString(int) (the stringBuilder2 microbenchmark) does not appear to be faster.
Is this performance discrepancy an issue with the testing harness? Or does my OpenJDK JVM contain optimizations that would affect this particular code (anti)-pattern?
EDIT:
For a more straight-forward comparison, I installed Oracle JDK 1.7u55:
java version "1.7.0_55"
Java(TM) SE Runtime Environment (build 1.7.0_55-b13)
Java HotSpot(TM) 64-Bit Server VM (build 24.55-b03, mixed mode)
The results are similar to those of OpenJDK:
Benchmark Mode Samples Mean Mean error Units
b.IntStr.integerToString thrpt 20 32502.493 501.928 ops/ms
b.IntStr.stringBuilder0 thrpt 20 39592.174 428.967 ops/ms
b.IntStr.stringBuilder1 thrpt 20 40978.633 544.236 ops/ms
It seems that this is a more general Java 7 vs Java 8 issue. Perhaps Java 7 had more aggressive string optimizations?
EDIT 2:
For completeness, here are the string-related VM options for both of these JVMs:
For Oracle JDK 8u5:
$ /usr/java/default/bin/java -XX:+PrintFlagsFinal 2>/dev/null | grep String
bool OptimizeStringConcat = true {C2 product}
intx PerfMaxStringConstLength = 1024 {product}
bool PrintStringTableStatistics = false {product}
uintx StringTableSize = 60013 {product}
For OpenJDK 1.7:
$ java -XX:+PrintFlagsFinal 2>/dev/null | grep String
bool OptimizeStringConcat = true {C2 product}
intx PerfMaxStringConstLength = 1024 {product}
bool PrintStringTableStatistics = false {product}
uintx StringTableSize = 60013 {product}
bool UseStringCache = false {product}
The UseStringCache option was removed in Java 8 with no replacement, so I doubt that makes any difference. The rest of the options appear to have the same settings.
EDIT 3:
A side-by-side comparison of the source code of the AbstractStringBuilder, StringBuilder and Integer classes from the src.zip file of reveals nothing noteworty. Apart from a whole lot of cosmetic and documentation changes, Integer now has some support for unsigned integers and StringBuilder has been slightly refactored to share more code with StringBuffer. None of these changes seem to affect the code paths used by StringBuilder#append(int), although I may have missed something.
A comparison of the assembly code generated for IntStr#integerToString() and IntStr#stringBuilder0() is far more interesting. The basic layout of the code generated for IntStr#integerToString() was similar for both JVMs, although Oracle JDK 8u5 seemed to be more aggressive w.r.t. inlining some calls within the Integer#toString(int) code. There was a clear correspondence with the Java source code, even for someone with minimal assembly experience.
The assembly code for IntStr#stringBuilder0(), however, was radically different. The code generated by Oracle JDK 8u5 was once again directly related to the Java source code - I could easily recognise the same layout. On the contrary, the code generated by OpenJDK 7 was almost unrecognisable to the untrained eye (like mine). The new StringBuilder() call was seemingly removed, as was the creation of the array in the StringBuilder constructor. Additionaly, the disassembler plugin was not able to provide as many references to the source code as it did in JDK 8.
I assume that this is either the result of a much more aggressive optimization pass in OpenJDK 7, or more probably the result of inserting hand-written low-level code for certain StringBuilder operations. I am unsure why this optimization does not happen in my JVM 8 implementation or why the same optimizations were not implemented for Integer#toString(int) in JVM 7. I guess someone familiar with the related parts of the JRE source code would have to answer these questions...
Answer
TL;DR: Side effects in append apparently break StringConcat optimizations.
Very good analysis in the original question and updates!
For completeness, below are a few missing steps:
See through the
-XX:+PrintInliningfor both 7u55 and 8u5. In 7u55, you will see something like this:@ 16 org.sample.IntStr::inlineSideEffect (25 bytes) force inline by CompilerOracle @ 4 java.lang.StringBuilder::<init> (7 bytes) inline (hot) @ 18 java.lang.StringBuilder::append (8 bytes) already compiled into a big method @ 21 java.lang.StringBuilder::toString (17 bytes) inline (hot)...and in 8u5:
@ 16 org.sample.IntStr::inlineSideEffect (25 bytes) force inline by CompilerOracle @ 4 java.lang.StringBuilder::<init> (7 bytes) inline (hot) @ 3 java.lang.AbstractStringBuilder::<init> (12 bytes) inline (hot) @ 1 java.lang.Object::<init> (1 bytes) inline (hot) @ 18 java.lang.StringBuilder::append (8 bytes) inline (hot) @ 2 java.lang.AbstractStringBuilder::append (62 bytes) already compiled into a big method @ 21 java.lang.StringBuilder::toString (17 bytes) inline (hot) @ 13 java.lang.String::<init> (62 bytes) inline (hot) @ 1 java.lang.Object::<init> (1 bytes) inline (hot) @ 55 java.util.Arrays::copyOfRange (63 bytes) inline (hot) @ 54 java.lang.Math::min (11 bytes) (intrinsic) @ 57 java.lang.System::arraycopy (0 bytes) (intrinsic)You might notice that 7u55 version is shallower, and it looks like nothing is called after
StringBuildermethods -- this is a good indication the string optimizations are in effect. Indeed, if you run 7u55 with-XX:-OptimizeStringConcat, the subcalls will reappear, and performance drops to 8u5 levels.OK, so we need to figure out why 8u5 does not do the same optimization. Grep http://hg.openjdk.java.net/jdk9/jdk9/hotspot for "StringBuilder" to figure out where VM handles the StringConcat optimization; this will get you into
src/share/vm/opto/stringopts.cpphg log src/share/vm/opto/stringopts.cppto figure out the latest changes there. One of the candidates would be:changeset: 5493:90abdd727e64 user: iveresov date: Wed Oct 16 11:13:15 2013 -0700 summary: 8009303: Tiered: incorrect results in VM tests stringconcat...Look for the review threads on OpenJDK mailing lists (easy enough to google for changeset summary): http://mail.openjdk.java.net/pipermail/hotspot-compiler-dev/2013-October/012084.html
Spot "String concat optimization optimization collapses the pattern [...] into a single allocation of a string and forming the result directly. All possible deopts that may happen in the optimized code restart this pattern from the beginning (starting from the StringBuffer allocation). That means that the whole pattern must me side-effect free." Eureka?
Write out the contrasting benchmark:
@Fork(5) @Warmup(iterations = 5) @Measurement(iterations = 5) @BenchmarkMode(Mode.AverageTime) @OutputTimeUnit(TimeUnit.NANOSECONDS) @State(Scope.Benchmark) public class IntStr { private int counter; @GenerateMicroBenchmark public String inlineSideEffect() { return new StringBuilder().append(counter++).toString(); } @GenerateMicroBenchmark public String spliceSideEffect() { int cnt = counter++; return new StringBuilder().append(cnt).toString(); } }Measure it on JDK 7u55, seeing the same performance for inlined/spliced side effects:
Benchmark Mode Samples Mean Mean error Units o.s.IntStr.inlineSideEffect avgt 25 65.460 1.747 ns/op o.s.IntStr.spliceSideEffect avgt 25 64.414 1.323 ns/opMeasure it on JDK 8u5, seeing the performance degradation with the inlined effect:
Benchmark Mode Samples Mean Mean error Units o.s.IntStr.inlineSideEffect avgt 25 84.953 2.274 ns/op o.s.IntStr.spliceSideEffect avgt 25 65.386 1.194 ns/opSubmit the bug report (https://bugs.openjdk.java.net/browse/JDK-8043677) to discuss this behavior with VM guys. The rationale for original fix is rock solid, it is interesting however if we can/should get back this optimization in some trivial cases like these.
???
PROFIT.
And yeah, I should post the results for the benchmark which moves the increment from the StringBuilder chain, doing it before the entire chain. Also, switched to average time, and ns/op. This is JDK 7u55:
Benchmark Mode Samples Mean Mean error Units o.s.IntStr.integerToString avgt 25 153.805 1.093 ns/op o.s.IntStr.stringBuilder0 avgt 25 128.284 6.797 ns/op o.s.IntStr.stringBuilder1 avgt 25 131.524 3.116 ns/op o.s.IntStr.stringBuilder2 avgt 25 254.384 9.204 ns/op o.s.IntStr.stringFormat avgt 25 2302.501 103.032 ns/op
And this is 8u5:
Benchmark Mode Samples Mean Mean error Units o.s.IntStr.integerToString avgt 25 153.032 3.295 ns/op o.s.IntStr.stringBuilder0 avgt 25 127.796 1.158 ns/op o.s.IntStr.stringBuilder1 avgt 25 131.585 1.137 ns/op o.s.IntStr.stringBuilder2 avgt 25 250.980 2.773 ns/op o.s.IntStr.stringFormat avgt 25 2123.706 25.105 ns/op
stringFormat is actually a bit faster in 8u5, and all other tests are the same. This solidifies the hypothesis the side-effect breakage in SB chains in the major culprit in the original question.