<html>
<head>
<meta content="text/html; charset=utf-8" http-equiv="Content-Type">
</head>
<body bgcolor="#FFFFFF" text="#000000">
<font face="Times New Roman, Times, serif">Bengt,<br>
<br>
The changes look good.<br>
<br>
Is it correct that for </font><br>
<pre>PSParallelCompact::invoke_no_policy()
the VerifyBeforeGC is now done before the
heap dump? That seems like the right order
but I thought I would note that change.
Jon
</pre>
<br>
<div class="moz-cite-prefix">On 02/04/2016 07:26 AM, Bengt Rutisson
wrote:<br>
</div>
<blockquote cite="mid:56B36D8D.6020905@oracle.com" type="cite">
<br>
Hi everyone,
<br>
<br>
Could I have a couple of reviews for this change?
<br>
<br>
<a class="moz-txt-link-freetext" href="http://cr.openjdk.java.net/~brutisso/8149035/webrev.00/">http://cr.openjdk.java.net/~brutisso/8149035/webrev.00/</a>
<br>
<a class="moz-txt-link-freetext" href="https://bugs.openjdk.java.net/browse/JDK-8149035">https://bugs.openjdk.java.net/browse/JDK-8149035</a>
<br>
<br>
There are two actions that can be taken before and after a full
GC. We can do a a heap dump and we can produce a class histogram.
<br>
<br>
Both these actions now use their own GC ID and are logged and
recorded as separate GCs. It is more natural that they are
considered part of the full GC. Especially since they make up a
significant part of the pause that the application experience.
<br>
<br>
We should move these two actions inside of the GC pause reporting.
<br>
<br>
The log now looks like this (truncated the class histogram for
readability):
<br>
<br>
[1,930s][info ][gc,start ] GC(1) Pause Full (System.gc())
(1,930s)
<br>
[1,930s][info ][gc,start ] GC(1) Heap Dump (before full gc)
(1,930s)
<br>
[1,985s][info ][gc ] GC(1) Heap Dump (before full gc)
(1,930s, 1,985s) 54,830ms
<br>
[1,994s][trace ][gc,classhisto] GC(1) num #instances
#bytes class name
<br>
[1,994s][trace ][gc,classhisto] GC(1)
----------------------------------------------
<br>
[1,994s][trace ][gc,classhisto] GC(1) 1: 9059 601136
[B
<br>
[1,994s][trace ][gc,classhisto] GC(1) 2: 466 480144
[I
<br>
[1,994s][trace ][gc,classhisto] GC(1) 3: 1788 205608
java.lang.Class
<br>
...
<br>
[1,999s][trace ][gc,classhisto] GC(1) 584: 1 16
sun.util.resources.cldr.provider.CLDRLocaleDataMetaInfo_jdk_localedata
<br>
[1,999s][trace ][gc,classhisto] GC(1) Total 40164 2413832
<br>
[1,999s][trace ][gc,classhisto] GC(1) Class Histogram (before
full gc) (1,985s, 1,999s) 13,485ms
<br>
[2,051s][info ][gc,heap ] GC(1) PSYoungGen:
2349K->0K(57344K)
<br>
[2,051s][info ][gc,heap ] GC(1) ParOldGen:
8K->1902K(65536K)
<br>
[2,051s][info ][gc,metaspace ] GC(1) Metaspace:
10738K->10738K(1058816K)
<br>
[2,062s][trace ][gc,classhisto] GC(1) num #instances
#bytes class name
<br>
[2,062s][trace ][gc,classhisto] GC(1)
----------------------------------------------
<br>
[2,062s][trace ][gc,classhisto] GC(1) 1: 9059 601136
[B
<br>
[2,062s][trace ][gc,classhisto] GC(1) 2: 1788 205608
java.lang.Class
<br>
[2,062s][trace ][gc,classhisto] GC(1) 3: 8551 205224
java.lang.String
<br>
...
<br>
[2,067s][trace ][gc,classhisto] GC(1) 584: 1 16
sun.util.resources.cldr.provider.CLDRLocaleDataMetaInfo_jdk_localedata
<br>
[2,067s][trace ][gc,classhisto] GC(1) Total 40093 1948480
<br>
[2,067s][trace ][gc,classhisto] GC(1) Class Histogram (after full
gc) (2,051s, 2,067s) 16,486ms
<br>
[2,067s][info ][gc ] GC(1) Pause Full (System.gc())
2M->1M(120M) (1,930s, 2,067s) 137,013ms
<br>
[2,067s][info ][gc,cpu ] GC(1) User=0,87s Sys=0,03s
Real=0,14s
<br>
<br>
Several things had to be fixed for this to work properly:
<br>
<br>
- The calls to pre/post_full_gc_dump() in genCollectedHeap.cpp
were moved to concurrentMarkSweepGeneration.cpp and
tenuredGeneration.cpp
<br>
- In psMarkSweep and parallelCompact the calls to
pre/post_full_gc_dump() were moved to inside the GC start/end.
<br>
- In CollectedHeap::full_gc_dump() the setup of a new GC id was
removed.
<br>
- In CollectedHeap::full_gc_dump() the use of FormatBuffer was
removed. This is necessary since the "title" passed to GCTraceTime
is stored and used later to send a trace event.
<br>
- In heapInspection.cpp the logging for the title was moved to be
able to use two print_cr calls to make it log the title with
decorations properly.
<br>
- A log prefix was added for [gc, classhisto]
<br>
<br>
Thanks,
<br>
Bengt
<br>
</blockquote>
<br>
</body>
</html>