Small change to the -verbosegc output (CMS)

[Tony Printezis]

Kirk,

kirk wrote:
> Hi Tony,
>
> Nice change 
Glad you think so. :-)
> but if we are going to break something can we go a wee bit more whole 
> hog on it? How about GC be changed to CMS? Make the awk parsing even 
> easier.
Right now, we'd rather do very small changes to be as non-intrusive as 
possible.
> And trust me, I've no problems if you broke the entire logging 
> system.. if it were more easily machine readable ;-)
:-) We have been talking about this for some time, it's just not at the 
top of our priority list right now.

Tony, HS GC Group
> Tony Printezis wrote:
>> Hi all,
>>
>> For a while now, the initial-mark / remark pauses were not tagged 
>> correctly on the CMS logs obtained with -verbosegc:
>>
>> 8.012: [ParNew 84832K->79546K(162816K), 0.0293764 secs]
>> 8.043: [GC 79546K(162816K), 0.0004823 secs]
>> 8.140: [ParNew 89658K->84364K(162816K), 0.0271073 secs]
>> 8.673: [ParNew 94476K->86063K(162816K), 0.0254789 secs]
>> 9.276: [GC 93707K(162816K), 0.0369005 secs]
>> 9.426: [ParNew 83265K->74974K(162816K), 0.0217100 secs]
>> 9.830: [ParNew 85086K->76329K(162816K), 0.0062086 secs]
>>
>> Above, the pauses at 8.043 and 9.276 are an initial-mark / remark 
>> respectively, but novice users would never guess that this is the 
>> case. We are proposing a small change to make the CMS -verbosegc 
>> output clearer, which is the following:
>>
>> 8.012: [ParNew 84832K->79546K(162816K), 0.0293764 secs]
>> 8.043: [GC (initial-mark) 79546K(162816K), 0.0004823 secs]
>> 8.140: [ParNew 89658K->84364K(162816K), 0.0271073 secs]
>> 8.673: [ParNew 94476K->86063K(162816K), 0.0254789 secs]
>> 9.276: [GC (remark) 93707K(162816K), 0.0369005 secs]
>> 9.426: [ParNew 83265K->74974K(162816K), 0.0217100 secs]
>> 9.830: [ParNew 85086K->76329K(162816K), 0.0062086 secs]
>>
>> The downside is that your (awk-based?) parser might have to be 
>> slightly modified to deal with the change. The good news are that the 
>> logs will be more readable and your parser will now know what to do 
>> when it comes across such pauses. I opened a CR for this (6916659):
>>
>> http://bugs.sun.com/view_bug.do?bug_id=6916659
>>
>> Are there any major objections to making this change?
>>
>> Yes, we do recommend folks to use -XX:+PrintGCDetails instead of 
>> -verbosegc, as it will produce a much more detailed and helpful 
>> output (and don't forget -XX:+PrintGCTimeStamps!!!). But, given that 
>> -verbosegc is there anyway, might as well fix it.
>>
>> Regards,
>>
>> Tony, HS GC Group
>>
>>
>>
>