Request for review (M): 7178361: G1: Make sure that PrintGC and PrintGCDetails use the same timing for the GC pause

John Cuthbertson john.cuthbertson at
Thu Jul 12 21:34:30 UTC 2012

Hi Bengt,

The latest webrev looks good to me.


On 07/11/12 13:58, Bengt Rutisson wrote:
> Hi John,
> Thanks a lot for looking at this! Good comments as always!
> I applied your latest comments. (Good catch about the initialization 
> of the card cleaning timing variables.)
> Here is an updated webrev:
> For convenience, here is a webrev with just the latest changes that I 
> applied based on your two last emails:
> I'm getting back to work next week and I'd like to start on the next 
> step (to clean up the single threaded logging) based on this change. 
> So, I'd like to get this pushed before Monday.
> If I don't get any objections before tomorrow I'll push this. I can 
> always include some changes in my next push as well if there is late 
> feedback.
> Thanks again for the review!
> Bengt
> On 2012-07-04 00:07, John Cuthbertson wrote:
>> Hi Bengt,
>> Finished looking at the rest of the webrev. Replies are inline.....
>> On 06/29/12 05:37, Bengt Rutisson wrote:
>>>> Line 102:
>>>> 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
>>>> could take an end time and do any necessary calculations.
>>> Done.
>> Thanks again - I can see you even extended the idea to include other 
>> cachable items from the start of the pause. It also looks good.
>>>> Line 236:
>>>> "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
>>>> 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().
>>> 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().
>>> 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.
>> OK. I was expecting note_gc_end() to be called by 
>> record_collection_pause_end() but I see your point  - they are kind 
>> of inter-dependent.  I'm OK with the current solution. I agree that 
>> it's good not to change the timer for the ergonomics - it covers the 
>> part of the GC we can control and make changes to.
>>>> g1CollectorPolicy.hpp
>>>> ---------------------
>>>> Line 65-66:
>>>> Why did you remove the indentation levels? IMO they are easier to 
>>>> work with than explicitly listing spaces.
>>> 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.
>>> 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.
>> I think we'll agree to disagree with this one - but I don't feel that 
>> strongly so let's go with your current solution.
>> I'm OK with your replies to the remaining comments.
>> Based upon the latest patch, however, I think you need the following 
>> initializers:
>>     _min_clear_cc_time_ms(-1.0),
>>     _max_clear_cc_time_ms(-1.0),
>>     _cur_clear_cc_time_ms(0.0),
>>     _cum_clear_cc_time_ms(0.0),
>>     _num_cc_clears(0L),
>> in the G1GCPhaseTimes constructor - otherwise the min, max, and 
>> cumulative card count times end up invalid:
>>    [Cur Clear CC: 0.0 ms]
>>    [Cum Clear CC: 
>> -7478635795308384178678626234477338765623121979189748343809653167004330313976030486954447383286129802186779679841804100646674790742262819242223986790247088643994984488195310211210345403332642667378471000230265516264857328262241129957569855488.0 
>> ms]
>>    [Min Clear CC: 0.0 ms]
>>    [Max Clear CC: 0.0 ms]
>> Also, since the previous version of the finest log-level didn't 
>> display these items, perhaps only display them if Verbose is also 
>> enabled? In most cases card cache count clearing  will exhibit itself 
>> as a higher HC Worker Other time for worker 0.
>> Everything else looks OK.
>> Thanks,
>> JohnC

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <>

More information about the hotspot-gc-dev mailing list