-
Bug
-
Resolution: Fixed
-
P2
-
5.0
-
tiger
-
x86
-
linux, solaris_8
There is a 4% regression in JetStream benchmark across all platforms in Tiger b05. When comparing Xprof output between b04 and b05 we see 11% more time spent in StringBuffer append and 7% more time spent in StringBuffer toString methods. Looking at the IO workspace archives, the regression was introduced at
/net/teal/a/builds/tiger/linux-i586/2003/063a
We know this since the regression is not present in the previous 063 archive build.
xprof of 063
Compiled + native Method
9.5% 54 + 0 java.io.BufferedReader.read
8.6% 49 + 0 java.io.BufferedOutputStream.write
8.2% 11 + 36 java.lang.String.getChars
6.7% 38 + 0 java.io.BufferedInputStream.read
6.7% 21 + 17 java.lang.String.<init>
6.0% 32 + 2 java.lang.StringBuffer.append
4.0% 9 + 14 java.lang.StringBuffer.append
4.0% 23 + 0 sun.nio.cs.ISO_8859_1$Encoder.encodeArrayLoop
3.7% 21 + 0 sun.nio.cs.ISO_8859_1$Decoder.decodeArrayLoop
3.5% 19 + 1 WriteTextTest.writeFile3
3.2% 18 + 0 java.io.StreamTokenizer.nextToken
2.8% 16 + 0 java.lang.Integer.toString
2.6% 15 + 0 java.io.BufferedReader.readLine
2.1% 12 + 0 java.lang.String.<init>
2.1% 12 + 0 sun.nio.cs.StreamEncoder.write
1.9% 11 + 0 java.io.StreamTokenizer.read
1.8% 10 + 0 java.lang.Integer.getChars
1.8% 9 + 1 java.lang.Integer.appendTo
1.4% 8 + 0 java.lang.StringBuffer.length
1.2% 7 + 0 java.nio.CharBuffer.wrap
1.1% 6 + 0 java.io.PrintWriter.write
1.1% 6 + 0 java.nio.charset.CharsetEncoder.encode
0.9% 5 + 0 java.io.OutputStreamWriter.write
0.9% 5 + 0 java.nio.Buffer.position
0.7% 4 + 0 java.lang.ThreadLocal$ThreadLocalMap.get
91.9% 454 + 71 Total compiled (including elided)
xprof of 063a
9.4% 33 + 25 java.lang.StringBuffer.append
8.4% 52 + 0 java.io.BufferedInputStream.read
7.8% 48 + 0 java.io.BufferedOutputStream.write
7.3% 45 + 0 java.io.BufferedReader.read
6.2% 26 + 12 java.lang.StringBuffer.toString
5.5% 34 + 0 sun.nio.cs.ISO_8859_1$Decoder.decodeArrayLoop
5.0% 31 + 0 sun.nio.cs.ISO_8859_1$Encoder.encodeArrayLoop
4.9% 30 + 0 java.io.StreamTokenizer.nextToken
4.7% 15 + 14 java.lang.String.<init>
4.2% 14 + 12 java.lang.StringBuffer.append
3.9% 10 + 14 java.lang.String.getChars
2.8% 14 + 3 java.lang.Integer.toString
2.6% 14 + 2 WriteTextTest.writeFile3
2.3% 14 + 0 sun.nio.cs.StreamEncoder.write
2.3% 14 + 0 java.io.BufferedReader.readLine
1.8% 4 + 7 java.lang.Integer.appendTo
1.6% 10 + 0 java.io.StreamTokenizer.read
1.5% 9 + 0 java.nio.CharBuffer.wrap
1.3% 2 + 6 java.lang.Integer.toString
1.3% 8 + 0 java.lang.Integer.getChars
1.1% 7 + 0 java.io.OutputStreamWriter.write
1.1% 5 + 2 java.io.BufferedWriter.write
1.0% 6 + 0 CopyFileTest.copyFilesInDir
0.8% 5 + 0 java.io.PrintWriter.write
0.8% 5 + 0 java.nio.Buffer.limit
92.9% 476 + 97 Total compiled (including elided)
We believe the 2% regression in Specjbb on Solaris is also caused by changes to StringBuffer toString (although not necessarily caused by build 063). Getting Xrunhprof:cpu=samples output and running a diff on the output, we have three different places where StringBuffer toString time increases.
Before: 243/34506 (0.704225%)
After: 452/34383 (1.3146%)
java.lang.StringBuffer.toString(StringBuffer.java)
spec.jbb.Company.getCustomerByLastName(Company.java)
spec.jbb.PaymentTransaction.process(PaymentTransaction.java)
spec.jbb.TransactionManager.go(TransactionManager.java)
---
Before: 211/34506 (0.611488%)
After: 419/34383 (1.21863%)
java.lang.StringBuffer.toString(StringBuffer.java)
spec.jbb.JBButil.create_random_last_name(JBButil.java)
spec.jbb.JBButil.choose_random_last_name(JBButil.java)
spec.jbb.PaymentTransaction.init(PaymentTransaction.java)
---
Before: 188/34506 (0.544833%)
After: 354/34383 (1.02958%)
java.lang.StringBuffer.toString(StringBuffer.java)
spec.jbb.History.buildData(History.java)
spec.jbb.PaymentTransaction.process(PaymentTransaction.java)
spec.jbb.TransactionManager.go(TransactionManager.java)
###@###.### 2003-05-07
Volano too {(d32, d64) sparc, win32, linux, solx86} is impacted by these changes.
###@###.### 2003-05-08
/net/teal/a/builds/tiger/linux-i586/2003/063a
We know this since the regression is not present in the previous 063 archive build.
xprof of 063
Compiled + native Method
9.5% 54 + 0 java.io.BufferedReader.read
8.6% 49 + 0 java.io.BufferedOutputStream.write
8.2% 11 + 36 java.lang.String.getChars
6.7% 38 + 0 java.io.BufferedInputStream.read
6.7% 21 + 17 java.lang.String.<init>
6.0% 32 + 2 java.lang.StringBuffer.append
4.0% 9 + 14 java.lang.StringBuffer.append
4.0% 23 + 0 sun.nio.cs.ISO_8859_1$Encoder.encodeArrayLoop
3.7% 21 + 0 sun.nio.cs.ISO_8859_1$Decoder.decodeArrayLoop
3.5% 19 + 1 WriteTextTest.writeFile3
3.2% 18 + 0 java.io.StreamTokenizer.nextToken
2.8% 16 + 0 java.lang.Integer.toString
2.6% 15 + 0 java.io.BufferedReader.readLine
2.1% 12 + 0 java.lang.String.<init>
2.1% 12 + 0 sun.nio.cs.StreamEncoder.write
1.9% 11 + 0 java.io.StreamTokenizer.read
1.8% 10 + 0 java.lang.Integer.getChars
1.8% 9 + 1 java.lang.Integer.appendTo
1.4% 8 + 0 java.lang.StringBuffer.length
1.2% 7 + 0 java.nio.CharBuffer.wrap
1.1% 6 + 0 java.io.PrintWriter.write
1.1% 6 + 0 java.nio.charset.CharsetEncoder.encode
0.9% 5 + 0 java.io.OutputStreamWriter.write
0.9% 5 + 0 java.nio.Buffer.position
0.7% 4 + 0 java.lang.ThreadLocal$ThreadLocalMap.get
91.9% 454 + 71 Total compiled (including elided)
xprof of 063a
9.4% 33 + 25 java.lang.StringBuffer.append
8.4% 52 + 0 java.io.BufferedInputStream.read
7.8% 48 + 0 java.io.BufferedOutputStream.write
7.3% 45 + 0 java.io.BufferedReader.read
6.2% 26 + 12 java.lang.StringBuffer.toString
5.5% 34 + 0 sun.nio.cs.ISO_8859_1$Decoder.decodeArrayLoop
5.0% 31 + 0 sun.nio.cs.ISO_8859_1$Encoder.encodeArrayLoop
4.9% 30 + 0 java.io.StreamTokenizer.nextToken
4.7% 15 + 14 java.lang.String.<init>
4.2% 14 + 12 java.lang.StringBuffer.append
3.9% 10 + 14 java.lang.String.getChars
2.8% 14 + 3 java.lang.Integer.toString
2.6% 14 + 2 WriteTextTest.writeFile3
2.3% 14 + 0 sun.nio.cs.StreamEncoder.write
2.3% 14 + 0 java.io.BufferedReader.readLine
1.8% 4 + 7 java.lang.Integer.appendTo
1.6% 10 + 0 java.io.StreamTokenizer.read
1.5% 9 + 0 java.nio.CharBuffer.wrap
1.3% 2 + 6 java.lang.Integer.toString
1.3% 8 + 0 java.lang.Integer.getChars
1.1% 7 + 0 java.io.OutputStreamWriter.write
1.1% 5 + 2 java.io.BufferedWriter.write
1.0% 6 + 0 CopyFileTest.copyFilesInDir
0.8% 5 + 0 java.io.PrintWriter.write
0.8% 5 + 0 java.nio.Buffer.limit
92.9% 476 + 97 Total compiled (including elided)
We believe the 2% regression in Specjbb on Solaris is also caused by changes to StringBuffer toString (although not necessarily caused by build 063). Getting Xrunhprof:cpu=samples output and running a diff on the output, we have three different places where StringBuffer toString time increases.
Before: 243/34506 (0.704225%)
After: 452/34383 (1.3146%)
java.lang.StringBuffer.toString(StringBuffer.java)
spec.jbb.Company.getCustomerByLastName(Company.java)
spec.jbb.PaymentTransaction.process(PaymentTransaction.java)
spec.jbb.TransactionManager.go(TransactionManager.java)
---
Before: 211/34506 (0.611488%)
After: 419/34383 (1.21863%)
java.lang.StringBuffer.toString(StringBuffer.java)
spec.jbb.JBButil.create_random_last_name(JBButil.java)
spec.jbb.JBButil.choose_random_last_name(JBButil.java)
spec.jbb.PaymentTransaction.init(PaymentTransaction.java)
---
Before: 188/34506 (0.544833%)
After: 354/34383 (1.02958%)
java.lang.StringBuffer.toString(StringBuffer.java)
spec.jbb.History.buildData(History.java)
spec.jbb.PaymentTransaction.process(PaymentTransaction.java)
spec.jbb.TransactionManager.go(TransactionManager.java)
###@###.### 2003-05-07
Volano too {(d32, d64) sparc, win32, linux, solx86} is impacted by these changes.
###@###.### 2003-05-08
- duplicates
-
JDK-4872786 Various regressions in Jetstream benchmark
-
- Closed
-
- relates to
-
JDK-4261803 Need an unsynchronized StringBuffer
-
- Resolved
-
-
JDK-4822325 Remove String/StringBuffer sharing
-
- Resolved
-