|
Description
|
FULL PRODUCT VERSION :
java version "1.4.1_01"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.1_01-b01)
Java HotSpot(TM) Client VM (build 1.4.1_01-b01, mixed mode)
FULL OPERATING SYSTEM VERSION :
SunOS nexus 5.9 Generic_112233- customer sun4u sparc SUNW,Sun-Fire-880
A DESCRIPTION OF THE PROBLEM :
It is difficult to report this bug in a replicable way, at
least without providing a lot of code and data.
I am including at the profiling results of a run of an HTML
parser on a series of pages, in which the method responsible
for most of the activity (parse()) has not been compiled.
The resulting performance is completely unacceptable, as you
can easily imagine.
On other, seemingly identical runs (same command and arguments),
the VM compiles the method, leading to a 10x speed improvement.
There is no short code that we can provide that replicates
the problem. It is clear that HotSpot is somehow "fooled" by
the complexity of the code, and takes the (completely wrong)
decision not to compile the method that's responsible for
most of the computing time. This happen most of the times
(I'd say 3/4), but not always.
We can either provide you with enough classes and data to
reproduce the bug, or run tests for you trying to understand
what's happening.
Since the problem is not localised in a instruction or in a
method, but is inherently linked to the fact that the code
is complex, it must be debugged from the inside of the JVM.
ERROR MESSAGES/STACK TRACES THAT OCCUR :
Flat profile of 0.01 secs (1 total ticks): SIGTERM handler
Thread-local ticks:
100.0% 1 Blocked (of total)
Flat profile of 17338.35 secs (733235 total ticks): main
Interpreted + native Method
73.1% 533594 + 1503 ubi.util.PageParser2.parse
0.6% 12 + 4352 java.util.zip.Inflater.inflateBytes
0.0% 164 + 198 it.unimi.dsi.fastUtil.Object2ObjectOpenHashMap.<init>
0.0% 0 + 231 java.io.FileInputStream.readBytes
0.0% 23 + 128 java.lang.System.arraycopy
0.0% 3 + 109 java.io.FileOutputStream.writeBytes
0.0% 56 + 33 java.lang.StringBuffer.expandCapacity
0.0% 75 + 0 java.util.zip.Inflater.inflate
0.0% 75 + 0 java.util.zip.Inflater.setInput
0.0% 63 + 0 sun.nio.cs.UTF_8$Decoder.decodeArrayLoop
0.0% 0 + 55 it.unimi.dsi.fastUtil.Long2IntOpenHashMap.<init>
0.0% 3 + 43 ubi.util.Page.read
0.0% 13 + 29 java.util.zip.Inflater.reset
0.0% 39 + 0 sun.nio.cs.StreamEncoder$CharsetSE.writeBytes
0.0% 39 + 0 it.unimi.dsi.mg4j.io.FastBufferedInputStream.read
0.0% 0 + 35 java.io.BufferedWriter.<init>
0.0% 30 + 0 java.nio.Buffer.position
0.0% 27 + 0 ubi.util.OutputAnchorParserCallback.ensureEnd
0.0% 27 + 0 it.unimi.dsi.fastUtil.Object2ObjectOpenHashMap.<init>
0.0% 0 + 26 java.io.BufferedOutputStream.<init>
0.0% 23 + 0 ubi.util.TitleParserCallback.reset
0.0% 21 + 0 it.unimi.dsi.mg4j.util.MutableString.append
0.0% 19 + 0 it.unimi.dsi.mg4j.util.MutableString.length
0.0% 18 + 0 ubi.util.Tokenizer.flush
0.0% 18 + 0 ubi.util.PrintTitleParserCallback.flush
74.0% 534859 + 6800 Total interpreted (including elided)
Compiled + native Method
5.8% 42445 + 0 adapters
2.2% 15835 + 0 sun.nio.cs.UTF_8$Decoder.decodeArrayLoop
1.3% 9536 + 0 it.unimi.dsi.mg4j.util.MutableString.append
1.2% 5745 + 3358 ubi.util.Page.read
1.1% 7844 + 0 ubi.util.PrintOccurrencesParserCallback.handleWord
1.0% 7205 + 0 it.unimi.dsi.fastUtil.Object2ObjectOpenHashMap.findKey
1.0% 7091 + 0 java.lang.Character.isLetterOrDigit
0.8% 6183 + 1 ubi.util.Tokenizer.enqueue
0.8% 5739 + 1 ubi.util.PageParser2.fixEntities
0.7% 4943 + 48 ubi.util.Base64.decode
0.7% 4843 + 0 java.io.BufferedWriter.write
0.6% 4445 + 0 java.lang.Character.isLetter
0.6% 4299 + 0 it.unimi.dsi.fastUtil.Object2ObjectOpenHashMap.clear
0.5% 3780 + 0 ubi.util.Fast.toLowerCase
0.4% 3247 + 0 ubi.util.Tokenizer.flush
0.4% 2963 + 0 it.unimi.dsi.mg4j.util.MutableString.hashCode
0.4% 2711 + 0 sun.nio.cs.UTF_8$Encoder.encodeArrayLoop
0.4% 2663 + 0 it.unimi.dsi.mg4j.util.MutableString.length
0.3% 2516 + 0 ubi.util.Base64.decode4to3
0.3% 2273 + 25 it.unimi.dsi.mg4j.util.MutableString.toString
0.3% 2137 + 0 ubi.util.URL2.<init>
0.2% 1654 + 16 java.nio.charset.CharsetEncoder.isLegalReplacement
0.2% 1488 + 0 vtable chunks
0.2% 1453 + 0
it.unimi.dsi.fastUtil.Object2ObjectOpenHashMap.findInsertionPoint
0.2% 1418 + 0 it.unimi.dsi.mg4j.util.MutableString.length
24.6% 176414 + 3465 Total compiled (including elided)
Stub + native Method
0.6% 9 + 4548 java.util.zip.Inflater.inflateBytes
0.6% 9 + 4548 Total stub
Runtime stub + native Method
0.0% 6 + 0 _new_typeArray_Java
0.0% 1 + 0 _new_Java
0.0% 7 + 0 Total runtime stubs
Thread-local ticks:
0.2% 1718 Blocked (of total)
0.0% 4 Class loader
0.0% 27 Interpreter
0.0% 3 Compilation
0.7% 5279 Unknown: running frame
0.0% 24 Unknown: calling frame
0.0% 78 Unknown: thread_state
Global summary of 17338.35 seconds:
100.0% 856557 Received ticks
13.8% 118070 Received GC ticks
0.1% 1284 Compilation
0.0% 2 Other VM operations
0.0% 4 Class loader
0.0% 27 Interpreter
0.6% 5381 Unknown code
REPRODUCIBILITY :
This bug can be reproduced often.
CUSTOMER WORKAROUND :
There is no possible workaround. The problem is deeply
inside the JVM.
(Review ID: 181803)
======================================================================
|
|
Evaluation
|
Feedback from original submitter revealed this to be a duplicate of another bug.
> No, it is not new, it is bug 4755752. I discussed this issue with Sun
Italy, as we have a V880. The bug is fixed in 1.4.1_02 (at least for
what we can test).
>
> Ciao
xxxxx@xxxxx 2003-04-04
|
