Request for review (M): 7178363 G1: Remove the serial code for PrintGCDetails and make it a special case of the parallel code

[Bengt Rutisson]

Hi John,

Thanks for looking at this so quickly!

On 2012-08-23 07:18, John Cuthbertson wrote:
> Hi Bengt,
>
> Looks good to me. Some really good refactoring in there. Some minor nits:
>
> g1GCPhaseTimes.cpp,  line 205: On my screen it looks like the 
> indentation is incorrect. You might want to check it. Also would it 
> read better to use a local to hold the difference between the end and 
> start times? Your choice.

Good catch. I fixed the indentation and I added locals to hold both the 
worker time and the other time. Looks better now I think. Here's what 
the for loop looks like now:

     for (uint i = 0; i < _active_gc_threads; i++) {
       double worker_time = _last_gc_worker_end_times_ms.get(i) - 
_last_gc_worker_start_times_ms.get(i);
       _last_gc_worker_times_ms.set(i, worker_time);

       double worker_known_time = _last_ext_root_scan_times_ms.get(i) +
         _last_satb_filtering_times_ms.get(i) +
         _last_update_rs_times_ms.get(i) +
         _last_scan_rs_times_ms.get(i) +
         _last_obj_copy_times_ms.get(i) +
         _last_termination_times_ms.get(i);

       double worker_other_time = worker_time - worker_known_time;
       _last_gc_worker_other_times_ms.set(i, worker_other_time);
     }

>
> Also your patch comment has an extra capital letter: WorkerDataARray.

Thanks for catching this. I'll fix it before I push.

> Ship it!

Thanks again for looking at this!
Bengt

>
> JohnC
>
> On 8/22/2012 4:16 AM, Bengt Rutisson wrote:
>>
>> Hi again,
>>
>> Here is an updated webrev based on comments from John Cuthbertson:
>> http://cr.openjdk.java.net/~brutisso/7178363/webrev.02/
>>
>> Here is a diff compared to the previous webrev:
>> http://cr.openjdk.java.net/~brutisso/7178363/webrev.01-02-diff/
>>
>> Thanks,
>> Bengt
>>
>> On 2012-07-20 14:17, Bengt Rutisson wrote:
>>>
>>> Hi all,
>>>
>>> Here is an updated webrev for this change:
>>> http://cr.openjdk.java.net/~brutisso/7178363/webrev.01/
>>>
>>> It turns out the the earlier change for 7178361 had introduced two 
>>> more issues: the heap transition information for the PrintGC output 
>>> and the output for evacuation failures had both been moved in an 
>>> unintended way. The above webrev corrects both of these chagne too. 
>>> Thanks John Cuthbertson for pointing me to the evacuation failure 
>>> output.
>>>
>>> Bengt
>>>
>>>
>>> On 2012-07-19 11:01, Bengt Rutisson wrote:
>>>>
>>>> Hi again,
>>>>
>>>> Just in case anybody already started looking at this: I have 
>>>> updated the webrev since I had to make some changes to make it 
>>>> compile with the NMT fixes that have just made it into the 
>>>> hotspot-gc repository. Those updates were just to make it compile 
>>>> and not really related to my change, so I just overwrote the 
>>>> existing webrev. Just use the same link as before:
>>>>
>>>> http://cr.openjdk.java.net/~brutisso/7178363/webrev.00/
>>>>
>>>> Also, if you want to see what the new output looks like I am 
>>>> attaching a file called new.txt with an example from running 
>>>> SpecJBB2005 with this command line:
>>>>
>>>> -XX:+UseG1GC -XX:ParallelGCThreads=4 
>>>> -XX:+UnlockExperimentalVMOptions -XX:G1LogLevel=finest 
>>>> -XX:+TraceGen0Time -Xms256m -Xmx2G
>>>>
>>>> I am also attaching a file called old.txt with what the output, 
>>>> using the same command line, looked like before my change. As you 
>>>> can see the differences are what I listed in my earlier email. You 
>>>> will also notice that the "old" version has an entry for the SATB 
>>>> filtering, even though all the entries are 0 (we didn't do a 
>>>> concurrent cycle so there has been no SATB filtering). This was a 
>>>> bug I just introduced with my last change (for 7178361), so the new 
>>>> example is more correct.
>>>>
>>>> Thanks,
>>>> Bengt
>>>>
>>>> On 2012-07-18 15:55, Bengt Rutisson wrote:
>>>>>
>>>>> Hi everyone,
>>>>>
>>>>> I would like some reviews of this change:
>>>>> http://cr.openjdk.java.net/~brutisso/7178363/webrev.00/
>>>>>
>>>>> This removes the special treatment for ParallelGCThreads=0 from 
>>>>> the G1 logging. I did keep the log output unchanged for that case. 
>>>>> Basically it just has one indentation level less and skips some 
>>>>> output. I am not sure this is really necessary since it is really 
>>>>> a special case. I'm open to change that special treatment too and 
>>>>> just have the same output as for ParallelGCThreads=1.
>>>>>
>>>>> The PrintGCDetails log output should be the same as before with 
>>>>> three minor adjustments:
>>>>>
>>>>> - The "Sum" is now not printed for the start and end values for GC 
>>>>> workers. This sum does not really make sense to me.
>>>>>
>>>>> - The "(ms)" unit was removed from output that aren't in 
>>>>> milliseconds (termination attempts for example).
>>>>>
>>>>> - The average value is now printed as a double for all types.
>>>>>
>>>>> I tried to clean up the code a bit and introduced a separate 
>>>>> class, Snippet WorkerDataArray, to keep track of the per thread 
>>>>> logging. I also introduced getters and setters to avoid having to 
>>>>> make G1CollectorPolicy and TraceGen0TimeData friend classes to 
>>>>> G1GCPhaseTimes.
>>>>>
>>>>> Thanks,
>>>>> Bengt
>>>>
>>>
>>