JDK-6507118 : REGRESSION: Testcase from CR 6348045 runs much slower on Java SE 6 than on J2SE 5
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.util.jar
  • Affected Version: 6
  • Priority: P2
  • Status: Closed
  • Resolution: Won't Fix
  • OS: generic
  • CPU: generic
  • Submitted: 2006-12-21
  • Updated: 2010-07-29
  • Resolved: 2006-12-23
Related Reports
Relates :  
JDK-6280693 - Mmap the whole jar files takes too much perceived footprint
Relates :  
JDK-6348045 - REGRESSION: serious performance degradation as GZIPInputStream is slower
Description
The testcase which is attached at CR 6348045 runs much slower on Java SE 6 than on J2SE 5.

$ java -showversion PerformanceTest
java version "1.5.0_10"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_10-b03)
Java HotSpot(TM) Server VM (build 1.5.0_10-b03, mixed mode)

Time needed for copy the archive :154626 ms

$ java -showversion PerformanceTest
java version "1.6.0"
Java(TM) SE Runtime Environment (build 1.6.0-b105)
Java HotSpot(TM) Server VM (build 1.6.0-b105, mixed mode)

Time needed for copy the archive :532257 ms

hprof output from JDK 5u10:
rank   self  accum   count trace method
   1 72.13% 72.13%    6261 300060 java.util.zip.Deflater.deflateBytes
   2 15.39% 87.52%    1336 300067 java.util.zip.CRC32.updateBytes
   3  2.09% 89.61%     181 300069 java.util.zip.Deflater.deflateBytes
   4  1.38% 90.99%     120 300066 PerformanceTest.startTest

hprof output from JDK 6:
rank   self  accum   count trace method
   1 57.52% 57.52%   14852 300056 java.util.zip.ZipFile.read
   2 31.27% 88.79%    8074 300054 java.util.zip.Deflater.deflateBytes
   3  6.71% 95.50%    1733 300053 java.util.zip.CRC32.updateBytes
   4  0.62% 96.12%     160 300067 java.util.zip.Deflater.deflateBytes
   5  0.34% 96.46%      89 300060 java.util.zip.DeflaterOutputStream.deflate
   6  0.34% 96.80%      88 300063 PerformanceTest.startTest
Comments
WORK AROUND Wrap streams in Buffered streams, instead of reading byte-at-a-time.
23-12-2006
EVALUATION It makes a big difference whether the test file is STORED or DEFLATED: Only the former shows much regression. The reason for the regression appears to be the decision to not map the entire JAR file into memory. In Mustang, only the central directory is mmaped. The change was done to reduce perceived footprint of Java applications. There is a decent workaround for the problem: use buffering; see attached BufferedPerformanceTest.java. Sample results are below. Note that with buffering 1,6.0 is (slightly!) faster than 1.5.0_10: % jver 1.5.0_10 java -showversion PerformanceTest; jver 1.5.0_10 java PerformanceTest; jver 1.5.0_10 java PerformanceTest java version "1.5.0_10" Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_10-b03) Java HotSpot(TM) Server VM (build 1.5.0_10-b03, mixed mode) Time needed for copy the archive :10015 ms Time needed for copy the archive :9880 ms Time needed for copy the archive :9891 ms % jver 1.6.0 java -showversion PerformanceTest; jver 1.6.0 java PerformanceTest; jver 1.6.0 java PerformanceTest java version "1.6.0" Java(TM) SE Runtime Environment (build 1.6.0-b105) Java HotSpot(TM) Server VM (build 1.6.0-b105, mixed mode) Time needed for copy the archive :22006 ms Time needed for copy the archive :22594 ms Time needed for copy the archive :22531 ms % jver 1.5.0_10 java -showversion BufferedPerformanceTest; jver 1.5.0_10 java BufferedPerformanceTest; jver 1.5.0_10 java BufferedPerformanceTest java version "1.5.0_10" Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_10-b03) Java HotSpot(TM) Server VM (build 1.5.0_10-b03, mixed mode) Time needed for copy the archive :856 ms Time needed for copy the archive :859 ms Time needed for copy the archive :858 ms % jver 1.6.0 java -showversion BufferedPerformanceTest; jver 1.6.0 java BufferedPerformanceTest; jver 1.6.0 java BufferedPerformanceTest java version "1.6.0" Java(TM) SE Runtime Environment (build 1.6.0-b105) Java HotSpot(TM) Server VM (build 1.6.0-b105, mixed mode) Time needed for copy the archive :808 ms Time needed for copy the archive :804 ms Time needed for copy the archive :805 ms
23-12-2006
EVALUATION I am unable to reproduce a regression as severe as reported. Here are results from solaris-amd64: % jver 1.5.0_10 java PerformanceTest; jver 1.5.0_10 java PerformanceTest; jver 1.5.0_10 java PerformanceTest; jver 1.5.0_10 java PerformanceTest; jver 1.5.0_10 java PerformanceTest Time needed for copy the archive :17534 ms Time needed for copy the archive :17779 ms Time needed for copy the archive :17913 ms Time needed for copy the archive :17683 ms Time needed for copy the archive :17748 ms [db13166@pasilla /tmp/6348045] % jver 1.6.0 java PerformanceTest Time needed for copy the archive :18958 ms % jver 1.6.0 java PerformanceTest; jver 1.6.0 java PerformanceTest; jver 1.6.0 java PerformanceTest; jver 1.6.0 java PerformanceTest; jver 1.6.0 java PerformanceTest Time needed for copy the archive :18839 ms Time needed for copy the archive :19056 ms Time needed for copy the archive :19066 ms Time needed for copy the archive :18895 ms Time needed for copy the archive :18935 ms That is ~7% regression. On win32, I see no regression at all. I used lib/charsets.jar (687 entries, 3474942 bytes long) as the input source. Please provide more information on how to duplicate your results.
21-12-2006