JDK-6933402 : RFE: Improve PrintSafepointStatistics output to track cleanup time
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.
There are some problematic area in today's PrintSafepointStatistics output. The most significant one is the clean up task time is included as part of the vm operation time. This can cause confusion when the customer also looks into the PrintGC data.
I would like to highlight the changes fixed for this CR.
- The most significant change is to exclude the clean up task time from the recorded vm operation time since we found under some situations, the clean up time could be untrivial. From other related CRs, you might find that the GC time, for example, only takes about small portion of the vm operation time we recorded using PrintSafepointStatistics.
- Break down the clean up time into 4 steps and record the time spending in each step when TraceSafepoint is set. This will help narrow down which part of the clean up might take long time. Historically in CBOE case, we noticed that nmethod sweep took a long time (~1-2 seconds) to complete. That area definitely can use some optimizations.
- Fixed long standing issue of last_non_safepoint_interval. The current implementation use the current time minus the begin of the last safepoint which is wrong. We should use the current time minus the end of the last safepoint. Also the current code uses the wrong time unit which will always yields negative interval value. With the fix, the gauaranteed safepoint occurs every other 1 seconds if there is any clean up work needs to be done.
- Print time stamp before each safepoint print out so a graph can be plotted easily. With the time stamp, we can safely drop the "time elasped since last safepoint".
See proposed fix at http://javaweb.sfbay.sun.com/~xl116366/webrev/6933402/