RFR (S): 7176220 'Full GC' events miss date stamp information occasionally

Andreas Eriksson andreas.eriksson at oracle.com
Fri May 17 15:38:56 UTC 2013


Great, thanks for looking at this.
I think this change is ready to be pushed.

Could someone be kind enough to sponsor and push this change?
The changeset can be found at:
http://cr.openjdk.java.net/~aeriksso/7176220/7176220.export

Regards,
Andreas


On 2013-05-16 20:48, Jon Masamitsu wrote:
> Andreas,
>
> That file parsed ok also.  Thanks.
>
> Jon
>
> On 5/16/13 2:38 AM, Andreas Eriksson wrote:
>> Attaching log from running
>> ./hsx24_hotspot-build/bin/java -Xmx2m -verbose:gc 
>> -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:gc.log 
>> -XX:+PrintGCDetails HumongousAlloc
>>
>> /Andreas
>>
>> On 2013-05-15 18:54, Jon Masamitsu wrote:
>>> Andreas,
>>>
>>> Thanks.  That log parse fine.  Please do a second with 
>>> "-XX:+PrintGCDetails"
>>>
>>> Jon
>>>
>>> On 5/15/2013 4:41 AM, Andreas Eriksson wrote:
>>>> Hi,
>>>>
>>>> The format of the regular logs should be the same as before.
>>>>
>>>> A sample of how they look after the change with the default GC is 
>>>> attached (running ./hsx24_hotspot-build/bin/java -Xmx2m -verbose:gc 
>>>> -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:gc.log 
>>>> HumongousAlloc)
>>>>
>>>> Please let me know if you need me to run with any other flags or 
>>>> some other java program.
>>>>
>>>> /Andreas
>>>>
>>>> On 2013-05-15 06:57, Jon Masamitsu wrote:
>>>>> Andreas,
>>>>>
>>>>> Please send a short sample of a new log.  I want to see if
>>>>> our log parsers work on the new log.  If you have not already
>>>>> done so, please do not push this until I've checked that the
>>>>> logs still parse.
>>>>>
>>>>> Jon
>>>>>
>>>>> On 5/14/2013 2:21 AM, Andreas Eriksson wrote:
>>>>>> Hi,
>>>>>>
>>>>>> I changed the date and time stamping calls to use the guarded 
>>>>>> convenience variants.
>>>>>> Both of these calls suffixes a ": " automatically. See 
>>>>>> share/vm/utilities/ostream.hpp line 99 and 105.
>>>>>>
>>>>>> It currently looks like this:
>>>>>> % ./hsx24_hotspot-build/bin/java -Xmx2m -verbose:gc 
>>>>>> -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps HumongousAlloc
>>>>>> 2013-05-14T11:17:28.340+0200: 0.050: [GC 1896K->421K(3136K), 
>>>>>> 0.0011640 secs]
>>>>>> 2013-05-14T11:17:28.341+0200: 0.051: [GC 2329K->437K(3136K), 
>>>>>> 0.0029750 secs]
>>>>>>
>>>>>> This is how it looked before as well:
>>>>>> % ~/builds/linux-amd64/7u25/bin/java -Xmx2m -verbose:gc 
>>>>>> -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps HumongousAlloc
>>>>>> 2013-05-14T11:17:31.603+0200: 0.059: [GC 2025K->417K(3136K), 
>>>>>> 0.0008100 secs]
>>>>>> 2013-05-14T11:17:31.605+0200: 0.060: [GC 2325K->417K(3136K), 
>>>>>> 0.0015140 secs]
>>>>>>
>>>>>> Thanks for looking at this.
>>>>>>
>>>>>> /Andreas
>>>>>>
>>>>>> On 2013-05-14 08:23, Bengt Rutisson wrote:
>>>>>>>
>>>>>>> Hi Andreas,
>>>>>>>
>>>>>>> Looks good.
>>>>>>>
>>>>>>> One question regarding the change in GCTraceTime:
>>>>>>>
>>>>>>> http://cr.openjdk.java.net/~aeriksso/7176220/webrev.00/src/share/vm/gc_implementation/shared/gcTraceTime.cpp.udiff.html 
>>>>>>>
>>>>>>>
>>>>>>> It looks to me like we are missing a ": " in the new version. 
>>>>>>> Maybe it is ok to loose this character in the log format, but a 
>>>>>>> safer change may be:
>>>>>>>
>>>>>>> if (PrintGCTimeStamps || PrintGCDateStamps) {
>>>>>>>   gclog_or_tty->date_stamp(PrintGCDateStamps);
>>>>>>>   gclog_or_tty->stamp(PrintGCTimeStamps);
>>>>>>> gclog_or_tty->print(": ");
>>>>>>> }
>>>>>>>
>>>>>>> This actually still changes the ": " behavior since since you 
>>>>>>> didn't use to get a ": " if you only had PrintGCDateStamps 
>>>>>>> enabled. But I think this is a more expected behavior.
>>>>>>>
>>>>>>> Thanks,
>>>>>>> Bengt
>>>>>>>
>>>>>>> On 5/13/13 6:01 PM, Andreas Eriksson wrote:
>>>>>>>> Hi all,
>>>>>>>>
>>>>>>>> Please take a look at my changes for bug 7176220.
>>>>>>>> The problem is that CMS sometimes misses datestamps for time 
>>>>>>>> trace printouts.
>>>>>>>>
>>>>>>>> The proposed fix is to move the datestamp print logic into the 
>>>>>>>> class that handles time trace printouts, GCTraceTime.
>>>>>>>> This would make it consistent with timestamps, which are 
>>>>>>>> already printed from there.
>>>>>>>>
>>>>>>>> Bugs.sun:
>>>>>>>> http://bugs.sun.com/view_bug.do?bug_id=7176220
>>>>>>>>
>>>>>>>> JIRA:
>>>>>>>> https://jbs.oracle.com/bugs/browse/JDK-7176220
>>>>>>>>
>>>>>>>> Webrev:
>>>>>>>> http://cr.openjdk.java.net/~aeriksso/7176220/webrev.00/
>>>>>>>>
>>>>>>>> Testing:
>>>>>>>> jprt, jtreg
>>>>>>>>
>>>>>>>> Thanks,
>>>>>>>> Andreas
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>




More information about the hotspot-gc-dev mailing list