JDK-7176220 : 'Full GC' events miss date stamp information occasionally
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 6u31
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • OS: solaris_10
  • CPU: sparc
  • Submitted: 2012-06-12
  • Updated: 2015-09-29
  • Resolved: 2013-05-20
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 6 JDK 7 JDK 8 JDK 9 Other
6u60Fixed 7u40Fixed 8u60Fixed 9Fixed hs24Fixed
Related Reports
Relates :  
Relates :  
'Full GC' events miss date and time stamp information occasionally.

% grep Full * | more
97615.938: [Full GC 1948395K->1737658K(2259136K), 16.4664960 secs]
98012.870: [Full GC 2340711K->1727536K(2528000K), 14.2683270 secs]
98107.575: [Full GC 2136505K->1748729K(2528000K), 13.6718630 secs]
98924.642: [Full GC 2506695K->1970965K(2528000K), 15.2351710 secs]
99339.771: [Full GC 2392788K->2095746K(2528000K), 15.1428000 secs]
2012-02-15T11:10:37.574+0100: 99360.096: [Full GC 2480403K->2137904K(2528000K), 15.5759880 secs]
2012-02-15T11:10:57.657+0100: 99381.371: [Full GC 2460514K->2155095K(2528000K), 15.8424040 secs]
2012-02-15T11:11:18.523+0100: 99402.416: [Full GC 2494126K->2205046K(2528000K), 16.0608940 secs]
99420.437: [Full GC 2524249K->2225820K(2528000K), 15.9992900 secs]
2012-02-15T11:11:55.189+0100: 99438.003: [Full GC 2481820K->2211826K(2528000K), 16.2163920 secs]
99456.979: [Full GC 2524492K->2240067K(2528000K), 16.1425710 secs]
[ ...]

Waiting for go-ahead from GC team to merge fix.

Adding another date_stamp call was not enough. New approach is to add the date-stamp call to a newly created subclass of TraceTime, 'GCTraceTime', and then removing the standalone calls to date-stamp. The time-stamp part of the logging is already present in the TraceTime class, this will be moved to GCTraceTime. This will avoid problems such as the flag PrintGCTimeStamp affecting other parts of HotSpot that are using TraceTime.

SUGGESTED FIX diff --git a/src/share/vm/memory/genCollectedHeap.cpp b/src/share/vm/memory/genCollectedHeap.cpp --- a/src/share/vm/memory/genCollectedHeap.cpp +++ b/src/share/vm/memory/genCollectedHeap.cpp @@ -518,6 +518,7 @@ increment_total_full_collections(); } pre_full_gc_dump(); // do any pre full gc dumps + gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps); } // Timer for individual generations. Last argument is false: no CR TraceTime t1(_gens[i]->short_name(), PrintGCDetails, false, gclog_or_tty);

EVALUATION Missing a call to date_stamp() in GenCollectedHeap::do_collection. Bug has existed since -XX:+PrintGCDateStamps was added in hs10/jdk6u4.