<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
<head>
<meta content="text/html; charset=ISO-8859-1"
http-equiv="Content-Type">
</head>
<body bgcolor="#ffffff" text="#000000">
<br>
Hi John,<br>
<br>
Thanks for taking such a close look at these changes!<br>
<br>
Here is a full webrev based on your comments:<br>
<a class="moz-txt-link-freetext" href="http://cr.openjdk.java.net/~brutisso/7178361/webrev.03">http://cr.openjdk.java.net/~brutisso/7178361/webrev.03</a><br>
<br>
Here is just a diff of the changes I made based on your comments:<br>
<a class="moz-txt-link-freetext" href="http://cr.openjdk.java.net/~brutisso/7178361/webrev.02-03-diff/">http://cr.openjdk.java.net/~brutisso/7178361/webrev.02-03-diff/</a><br>
<br>
Thanks again for looking at this! Your comments were really good.<br>
<br>
There are some responses inlined below.<br>
<br>
Bengt<br>
<br>
<br>
On 2012-06-29 02:25, John Cuthbertson wrote:
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<meta content="text/html; charset=ISO-8859-1"
http-equiv="Content-Type">
Hi Bengt,<br>
<br>
Apologies for the delay in reviewing your changes. Note these
comments
from your first webrev and the line numbers are from applying your
first patch to a clone of the hsx/hotspot-gc/hotspot repo at
revision:<br>
<br>
<tt>changeset: 3417:1c280e5b8d31<br>
tag: tip<br>
user: amurillo<br>
date: Fri Jun 15 14:17:28 2012 -0700<br>
summary: 7175515: new hotspot build - hs24-b15</tt><br>
<br>
Some of the comments are against code that you did not actually
touch -
you just touched near. But I think this a good opportunity for
some
cleanup<br>
<br>
Anyway onto the comments....<br>
<br>
<br>
g1GCPhaseTimes.hpp<br>
------------------<br>
Would "max_gc_threads" be a better name for the parameter of the
constructor?<br>
</blockquote>
<br>
Done.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Also we might want to cache this so that we can re-initialize all
per-worker thread slots in the time arrays at the start of each
pause.<br>
</blockquote>
<br>
Done.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
See futher comments in g1CollectorPolicy.{ch}pp about possible
other
candidates for inclusion into this file.<br>
<br>
Line 102:<br>
Rename "start" to something like - note_gc_start(). "start" is too
closely associated with threads IMO. Also should it also take the
start
time? That way the "end" routine<br>
could take an end time and do any necessary calculations.<br>
</blockquote>
<br>
Done.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 103:<br>
Make "print" a private method and add a "note_gc_end" routine that
calls print.<br>
</blockquote>
<br>
Done.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
g1GCPhaseTimes.cpp<br>
------------------<br>
Line 27:<br>
Only include g1CollectedHeap.inline.hpp - that includes
g1CollectedHeap.hpp.<br>
</blockquote>
<br>
Done.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 97:<br>
The initialization of these values should be done in the
"note_gc_start" routine. We want to detect if we don't record a
value
for one during the pause. So only<br>
initializing them once defeats that purpose.<br>
</blockquote>
<br>
Done.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 119:<br>
Should sum_of be made static or even a [private] [static] member
of the
G1GCPhaseTime class?<br>
</blockquote>
<br>
sum_of() was actually not being used. I removed it instead.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 166,167,...<br>
Argument formatting.<br>
</blockquote>
<br>
Done.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 236:<br>
"accumulate_par_times" is a bit misnamed. "collapse_par_times",
"average_par_times" might be better. Also I don't think you should
be
calling this directly from with<br>
G1CollectedHeap. It would be better to call this from a
G1GCPhaseTimes::note_gc_end() type of routine, which is called by
G1CollectorPolicy::record_collection_pause_end().<br>
</blockquote>
<br>
I renamed it to collapse_par_times(), but I still would like to call
it directly from G1CollectedHeap. The reason is that
record_collection_pause_end() need this to be called, but also the
note_gc_end() method. I don't like the note_gc_end() method to
depend on a call to record_collection_pause_end().<br>
<br>
The clean solution would be to merge these two methods, but that's
not possible without changing the timing for the ergonomics, which
is exactly what I am trying to avoid.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 246:<br>
Perhaps find a better place for this. Or even add a new routine:
calculate_known_time()?<br>
</blockquote>
<br>
It turns out that we always set _cur_collection_par_time_ms even for
ParallelGCThreads=0. And where we use accounted_time_ms() we are
really just interested in deducting the parallel time of the pause
from the total time of the pause. It should be fine to use
_cur_collection_par_time_ms for this.<br>
<br>
The only place where we actually care about the _known_time is in
TraceGen0TimeData::record_end_collection() where we try to figure
out the difference between _cur_collection_par_time_ms and the known
parallel time. So, I inlined the _known_time calculation in
TraceGen0TimeData::record_end_collection().<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 315:<br>
We should probably move this out of the "print" routine - perhaps
into
the "note_gc_end" type of routine. Then "print" just prints.<br>
</blockquote>
<br>
Done.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
g1CollectorPolicy.hpp<br>
---------------------<br>
Line 65-66:<br>
Why did you remove the indentation levels? IMO they are easier to
work
with than explicitly listing spaces.<br>
</blockquote>
<br>
Two reasons. One technical. I moved LineBuffer (that handled the
indentation) into g1GCPhaseTime.cpp and I didn't really want to
expose it outside of that module. The other, more design related
question, is whether the TraceGen0Time output should really use the
same formatting as the PrintGCDetails formatting. As it was it was
not doing a good job with the indentations. It was also pretty
difficult to read the code and guess how many white spaces would end
up where. With the white spaces explicitly in the print statements
it got clearer what really happened and I could fix the indentation
issues.<br>
<br>
I'm sure we can introduce some indentation abstraction for
TraceGen0Time too, but since I didn't really like the way it was and
I had to move the LineBuffer I thought it was easiest to revert back
to using explicit space characters in the print statements.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 178:<br>
Why didn't you include _cur_collection_pause_used_at_start_bytes
or why
did you include _curr_collection_pause_used_regions_at_start?
Should<br>
either be included? Including non-time based fields makes
G1GCPhaseTimes a bit of a misnomer. <br>
</blockquote>
<br>
My bad. At one point I was trying out G1GCPhaseTimes as
G1GCPhaseData and moved a lot more stuff in there. Then I decided
against that idea and moved everything out again. But I must have
missed _curr_collection_pause_used_regions_at_start. Thanks for
finding it! I moved it out now.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Can we rename _cur_collection_pause_used_regions_at_start to
_cur_collection_pause_used_at_start_regions? That way the "units"
of
the variable are at the end?<br>
</blockquote>
<br>
Personally I find the name
_cur_collection_pause_used_at_start_regions strange. I prefer
_cur_collection_pause_used_regions_at_start. Since it is not really
related to my change (anymore) I will leave it untouched now.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 660:<br>
The accessor name is ugly - perhaps just use "phase_times"?<br>
</blockquote>
<br>
Done.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 675-680:<br>
Should:<br>
<br>
<tt> double _cur_mark_stop_world_time_ms;<br>
double _mark_remark_start_sec;<br>
double _mark_cleanup_start_sec;</tt><br>
<br>
also be included in the phase times class?<br>
</blockquote>
<br>
I think not. The way I look at it G1GCPhaseTimes should only include
timing data for a normal G1 GC. We could definitely wrap the other
timing data in other classes, but I think it is good if we keep the
focus of this class simple.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 787:<br>
I would not remove record_concurrent_pause_end(). I would leave
it in
case we ever want to record anything at the end of a concurrent
pause.
Perhaps these routines should also be moved to the GC phase times
class.<br>
</blockquote>
<br>
I disagree. I think we can easily add it back in if we need it. No
point in keeping empty methods around.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 789:<br>
Does it make more sense to have record_collection_pause_start()
take
the starting time and number of GC threads and have it record the
start
time in the G1 phase times object. Then
record_collection_pause_end()
can take the "end" time - also pass it to the phase times object
and
have the phase times object do the calculations (see earlier<br>
comments about g1GCPhaseTimes.hpp).<br>
</blockquote>
<br>
I already did that based on your earlier comments ;-)<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
g1CollectorPolicy.cpp<br>
---------------------<br>
Line 199-204:<br>
Should the calculation of index use _parallel_gc_threads?<br>
</blockquote>
<br>
Good idea! That simplified the code to a one-liner.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 748:<br>
Perhaps G1GCPhaseTimes should have note_full_gc_start(),
note_inc_gc_start(), and corresponding end routines. The
"note_[full_]gc_start() routines would then be used<br>
to set the _cur_collection_start_sec.<br>
</blockquote>
<br>
Again, I would like to keep G1GCPhaseTimes to only handle normal
GCs. Otherwise I'm afraid the class will grow too big. I had not
realized that full GCs used the same _cur_collection_start_sec field
to keep track of its time.<br>
<br>
I separated the full GC timing out to a
G1CollectorPolicy::_full_collection_start_sec variable. That way we
won't risk mixing full GC and normal GC timing data.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 905:<br>
See earlier comments about re-initializing/clearing the
_par_last_gc
arrays.<br>
<br>
Line 1145:<br>
See earlier comments about record_collection_pause_end().<br>
</blockquote>
<br>
I was not really able to figure out what the two line numbers above
referred to, but since both comments refer to earlier comments I
hope that I have fixed it. :-)<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Line 2155:<br>
Old code with the levels looks much nicer - IMO.<br>
</blockquote>
<br>
See my earlier comment on this.<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
g1RemSet.cpp<br>
------------<br>
To make this consistent - perhaps change this code to call
os::elapsedTime() again (rather than in
G1GCPhaseTimes::record_cc_clear_time()) and pass the elapsed time
delta.<br>
</blockquote>
<br>
I don't really understand this comment. Can you explain a bit more
what you mean?<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Other than these, it looks OK.<br>
</blockquote>
<br>
Great!<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
Again - sorry for the delay in getting back to you.<br>
</blockquote>
<br>
No problem. Thanks for looking at this!<br>
<br>
<br>
<br>
<br>
<blockquote cite="mid:4FECF617.3070707@oracle.com" type="cite">
<br>
JohnC<br>
<br>
<br>
On 06/28/12 02:35, Bengt Rutisson wrote:
<blockquote cite="mid:4FEC256E.2030708@oracle.com" type="cite">
<meta content="text/html; charset=ISO-8859-1"
http-equiv="Content-Type">
<br>
Hi again,<br>
<br>
Here is an updated webrev:<br>
<a moz-do-not-send="true" class="moz-txt-link-freetext"
href="http://cr.openjdk.java.net/%7Ebrutisso/7178361/webrev.02/">http://cr.openjdk.java.net/~brutisso/7178361/webrev.02/</a><br>
<br>
It includes the assert to check that we are set up
active_workers to be
less than ParallelGCThreads that Vitaly suggested. <br>
<br>
Also, I will have to change my earlier statement about using
signed
values to index C++ arrays. It is fine with unsigned values too
(thanks
Mikael Vidstedt for making me reconsider this statement). So,
Vitaly, I
went ahead and implemented your first suggestion to use uint for
the
worker indexes.<br>
<br>
Thanks again for the review Vitaly. I know John Cuthbertson is
looking
at this too. <br>
<br>
Benbgt<br>
<br>
<br>
On 2012-06-25 16:23, Vitaly Davidovich wrote:
<blockquote
cite="mid:CAHjP37FS-Ht8YVnnq5Fz07ZirHOnDi7MrS8pJaMvLdGAvmD4Tg@mail.gmail.com"
type="cite">
<p>Thanks for the explanation Bengt - all good from me, FWIW
:).</p>
<p>Sent from my phone</p>
<div class="gmail_quote">On Jun 25, 2012 9:24 AM, "Bengt
Rutisson"
<<a moz-do-not-send="true"
href="mailto:bengt.rutisson@oracle.com">bengt.rutisson@oracle.com</a>>
wrote:<br type="attribution">
<blockquote class="gmail_quote" style="border-left: 1px
solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex;
padding-left: 1ex;">
<div bgcolor="#FFFFFF" text="#000000">
<div><br>
Hi Vitaly,<br>
<br>
On 2012-06-21 14:36, Vitaly Davidovich wrote:<br>
</div>
<blockquote type="cite">Hi Bengt,
<div><br>
</div>
<div>Looks good. One question: the asserts you added
check
against _active_gc_threads, but the arrays are sized
with
parallel_gc_threads. The assumption then is that
active_gc_threads
<= parallel_gc_threads? If so, maybe assert that
piece as well. </div>
</blockquote>
<br>
I see your point. Currently _active_gc_threads is set up
to be the same
as parallel_gc_threads, but I can add an assert to that
effect in the
constructor of G1GCPhaseTimes.<br>
<br>
<blockquote type="cite">
<div>Also, maybe consider moving the range asserts
into a macro
or helper function so that you don't have to repeat
the exact same 2
lines?</div>
</blockquote>
<br>
Somehow I find the inlined asserts more readable. I'll
think about it.
Thanks for the suggestion.<br>
<br>
<blockquote type="cite">
<div><br>
</div>
<div>Finally (forgot to mention this in my initial
email), a
minor point -- should the sentinel -1234.0 value
that you set the
arrays to be defined as a constant so if you, for
some reason, decide
to change it, you just update 1 place? Very minor
though :).</div>
</blockquote>
<br>
Yes, this should be fixed. However, I just moved this
code from one
place to anther and I plan on revisiting this code and
cleaning it up a
bit with my next change. That change should remove the
serial special
case in this code. Is it ok if I leave this cleanup for
that change?<br>
<br>
<blockquote type="cite">
<div><br>
</div>
<div>As for worker_i being unsigned, I was thinking
the method
would take unsigned which perhaps better expresses
the range/intent of
the value, but can cast internally to signed to do
array lookup.
Anyhow, not a big deal and what you have is fine,
obviously.</div>
</blockquote>
<br>
Yes, I tend to agree, but I think I'll leave them as int
for now. Maybe
I'll change this too as part of my next cleanup.<br>
<br>
<blockquote type="cite">
<div>The output looks nice with your changes -- I
wonder though
if even whitespace changes are deemed too risky in
terms of possibly
breaking client parsers (would have to be fairly
brittle ones, but
nonetheless).</div>
</blockquote>
<br>
Right. However, it looks to me like this output has been
changing its
indentation levels over time, so if any parsers break
due to white
space changes they are probably already broken ;-)<br>
<br>
Thanks again for looking at this!<br>
Bengt<br>
<br>
<blockquote type="cite">
<div><br>
</div>
<div>Thanks,</div>
<div><br>
</div>
<div>Vitaly<br>
<br>
<div class="gmail_quote">On Thu, Jun 21, 2012 at
7:54 AM, Bengt
Rutisson <span dir="ltr"><<a
moz-do-not-send="true"
href="mailto:bengt.rutisson@oracle.com"
target="_blank">bengt.rutisson@oracle.com</a>></span>
wrote:<br>
<blockquote class="gmail_quote"
style="border-left: 1px solid rgb(204, 204,
204); margin: 0pt 0pt 0pt 0.8ex; padding-left:
1ex;"><br>
Hi again,<br>
<br>
Updated webrev:<br>
<a moz-do-not-send="true"
href="http://cr.openjdk.java.net/%7Ebrutisso/7178361/webrev.01/"
target="_blank">http://cr.openjdk.java.net/~brutisso/7178361/webrev.01/</a><br>
<br>
I added some asserts as suggested by Vitaly and
I did some white space
changes to the TraceGen0Time logging. I hope
this will not break any
parsers. It is just intended to align the output
up a bit better to be
more readable.<br>
<br>
Here is a webrev with just the change I made
compared to my previous
webrev:<br>
<a moz-do-not-send="true"
href="http://cr.openjdk.java.net/%7Ebrutisso/7178361/webrev.00-01-diff/"
target="_blank">http://cr.openjdk.java.net/~brutisso/7178361/webrev.00-01-diff/</a><br>
<br>
Here is an example of what the TraceGen0Time
output looks like after my
change:<br>
<br>
ALL PAUSES<br>
Total = 0.95 s (avg =
63.44 ms)<br>
(num =
15, std dev =
47.84 ms, max = 150.30 ms)<br>
<br>
<br>
Young GC Pauses: 14<br>
Mixed GC Pauses: 1<br>
<br>
EVACUATION PAUSES<br>
Evacuation Pauses = 0.95 s (avg =
63.44 ms)<br>
(num =
15, std dev =
47.84 ms, max = 150.30 ms)<br>
Root Region Scan Wait = 0.00 s (avg =
0.00 ms)<br>
Parallel Time = 0.94 s (avg =
62.39 ms)<br>
Ext Root Scanning = 0.11 s (avg =
7.22 ms)<br>
SATB Filtering = 0.00 s (avg =
0.00 ms)<br>
Update RS = 0.04 s (avg =
2.81 ms)<br>
Scan RS = 0.03 s (avg =
2.07 ms)<br>
Object Copy = 0.75 s (avg =
49.75 ms)<br>
Termination = 0.00 s (avg =
0.02 ms)<br>
Parallel Other = 0.01 s (avg =
0.51 ms)<br>
Clear CT = 0.00 s (avg =
0.09 ms)<br>
Other = 0.01 s (avg =
0.90 ms)<br>
<br>
MISC<br>
Stop World = 0.01 s (avg =
0.48 ms)<br>
(num =
15, std dev =
0.19 ms, max = 0.79 ms)<br>
Yields = 0.00 s (avg =
0.27 ms)<br>
(num =
2, std dev =
0.05 ms, max = 0.32 ms)<br>
<br>
Thanks,<br>
Bengt
<div>
<div><br>
<br>
<br>
On 2012-06-20 15:15, Bengt Rutisson wrote:<br>
<blockquote class="gmail_quote"
style="border-left: 1px solid rgb(204,
204, 204); margin: 0pt 0pt 0pt 0.8ex;
padding-left: 1ex;"> <br>
Hi everyone,<br>
<br>
Could I please have some reviews for this
change:<br>
<a moz-do-not-send="true"
href="http://cr.openjdk.java.net/%7Ebrutisso/7178361/webrev.00/"
target="_blank">http://cr.openjdk.java.net/~brutisso/7178361/webrev.00/</a><br>
<br>
Background<br>
As part of the PrintGC and PrintGCDetails
logging there is information
about how long the GC pause was. The
timing of the pause was done
differently in G1 depending on whether
PrintGC or PrintGCDetails were
enabled. It turns out that PrintGCDetails
was just timing part of the
pause.<br>
<br>
This change will make both PrintGC and
PrintGCDetails use the same
timing. To achieve this I had to refactor
the code a bit. I moved all
the timing data out of G1CollectorPolicy
into a new class called
G1GCPhaseTimes.<br>
<br>
My intention is that this change should
not alter the format of the
output of PrintGC or PrintGCDetails. It
should just correct the timing
data.<br>
<br>
However, I did find that we are collecting
timing information about
card counts, under an #ifdef. I moved this
to the finest log level
instead. This does not change the existing
format for normal usage of
PrintGC or PrintGCDetails.<br>
<br>
Also, I had to update how the
TraceGen0Time data is logged. I will have
another look at this, but my idea was to
leave the format exactly as it
was. However, I think the format has
decayed over time so maybe I'll
try to clean it up.<br>
<br>
I intend to follow this change up with a
change to remove the special
treatment of the single threaded case for
PrintGCDetails (tracked in CR
7178363).<br>
<br>
Finally, this work revealed an issue with
how the ergonomics in G1
measure the collection pauses. I did not
want to change this behavior
now so I filed a separate RFE for that
(7178365: G1: Ergonomics only
count part of the collection pause).<br>
<br>
Bengt<br>
</blockquote>
<br>
</div>
</div>
</blockquote>
</div>
<br>
</div>
</blockquote>
<br>
<br>
</div>
</blockquote>
</div>
</blockquote>
<br>
</blockquote>
<br>
</blockquote>
<br>
</body>
</html>