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

Andreas Eriksson andreas.eriksson at oracle.com
Fri Sep 28 10:01:33 UTC 2012


Hi,

Can I have some reviews for the following change please:
http://cr.openjdk.java.net/~brutisso/7176220/webrev.00/ 
<http://cr.openjdk.java.net/%7Ebrutisso/7176220/webrev.00/>

This fixes GC logs from genCollectedHeap.cpp where sometimes it would 
not print date-stamps.
The fix moves printing of date-stamps into TraceTime, where time-stamps 
are already printed from.

Bug with flags -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -verbose:gc 
-XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps:
2012-09-28T11:41:38.687+0200: 0.205: [Full GC 8702K->1012K(9920K), 
0.0108630 secs]
1.253: [Full GC 3326K->1012K(9920K), 0.0105750 secs]
2.299: [Full GC 7932K->1012K(9920K), 0.0100470 secs]
2012-09-28T11:41:41.813+0200: 3.331: [Full GC 8702K->1012K(9920K), 
0.0103210 secs]

Another route that was investigated was to add the date-stamp call 
directly in genCollectedHeap.cpp, but because of complex interactions 
when a full GC was initiated from a non-full GC this path was not taken.


This will slightly change the logging output when using -XX:+PrintGCDetails.
Now date-stamps will also be printed inside other lines, as time-stamps 
already are:

Before:
2012-09-28T11:29:16.815+0200: 0.177: [GC0.177: [ParNew: 
2710K->46K(3072K), 0.0053590 secs] 3480K->1835K(9920K), 0.0055500 secs] 
[Times: user=0.01 sys=0.00, real=0.01 secs]

After:
2012-09-28T11:29:33.260+0200: 0.184: [GC2012-09-28T11:29:33.261+0200: 
0.184: [ParNew: 2642K->45K(3072K), 0.0095770 secs] 3412K->1828K(9920K), 
0.0097520 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

Thanks to Bengt Rutisson for helping with the change and webrev.

Regards,
Andreas
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.java.net/pipermail/hotspot-gc-dev/attachments/20120928/1edcc12a/attachment.htm>


More information about the hotspot-gc-dev mailing list