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

Andreas Eriksson andreas.eriksson at oracle.com
Wed May 15 11:41:48 UTC 2013


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
>>>>
>>>
>>
>>
>

-------------- next part --------------
A non-text attachment was scrubbed...
Name: gc.log
Type: text/x-log
Size: 18954 bytes
Desc: not available
URL: <https://mail.openjdk.java.net/pipermail/hotspot-gc-dev/attachments/20130515/757bf35c/gc.log>


More information about the hotspot-gc-dev mailing list