United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
Bug ID: JDK-6933402 RFE: Improve PrintSafepointStatistics output to track cleanup time
JDK-6933402 : RFE: Improve PrintSafepointStatistics output to track cleanup time

Details
Type:
Enhancement
Submit Date:
2010-03-09
Status:
Closed
Updated Date:
2010-09-24
Project Name:
JDK
Resolved Date:
2010-04-14
Component:
hotspot
OS:
generic
Sub-Component:
runtime
CPU:
generic
Priority:
P2
Resolution:
Fixed
Affected Versions:
hs17,7
Fixed Versions:
hs18 (b01)

Related Reports
Backport:
Backport:
Backport:
Backport:
Backport:
Backport:
Backport:
Backport:
Backport:
Backport:
Duplicate:
Duplicate:
Relates:
Relates:

Sub Tasks

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

                                    

Comments
EVALUATION

See comments for details.
                                     
2010-03-09
EVALUATION

See proposed fix at http://javaweb.sfbay.sun.com/~xl116366/webrev/6933402/
                                     
2010-03-09
EVALUATION

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".
                                     
2010-03-11
EVALUATION

http://hg.openjdk.java.net/jdk7/hotspot-rt/hotspot/rev/4b0f2f4918ed,ChangeRequest=6933402
                                     
2010-03-11
EVALUATION

http://hg.openjdk.java.net/hsx/hsx17/baseline/rev/1753407b5d19
                                     
2010-04-16
EVALUATION

http://hg.openjdk.java.net/hsx/hsx17/master/rev/1753407b5d19
                                     
2010-04-17



Hardware and Software, Engineered to Work Together