Menu
On enabling the +XX:PrintSafePointStatistics , I see a dump on the stdout in the following format. Can anyone please help me interpret the column names or the JVM guide which explains this properly? The JVM specification guide does not seem to be covering the meaning of the headers and its explanation at all.
@400000005175823c18c9d534 16762.525: GenCollectForAllocation [ 973 0 0 ] [ 0 0 0 5 53 ] 0
@400000005175823c18c9f08c 16762.586: CMS_Initial_Mark [ 973 0 1 ] [ 0 0 0 4 24 ] 0
@400000005175823c18ca0414 16774.619: GenCollectForAllocation [ 975 0 0 ] [ 0 0 0 5 77 ] 0
@400000005175823c18ca0be4 16777.387: CMS_Final_Remark [ 975 0 0 ] [ 0 0 0 5 18 ] 0
@400000005175823c18ca273c 16786.080: GenCollectForAllocation [ 974 0 1 ] [ 0 0 0 5 0 ] 0
@400000005175823c18ca2f0c vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count
@400000005175823c18ca3eac 16786.086: GenCollectFull [ 974 0 2 ] [ 0 0 0 4 89 ] 0
@400000005175823c18ca5a04 16798.393: GenCollectForAllocation [ 974 1 1 ] [ 2 0 3 5 57 ] 1
@400000005175823c18ca69a4 16811.539: GenCollectForAllocation [ 975 2 1 ] [ 1 0 1 5 61 ] 1
@400000005175823c18ca7944 16824.551: GenCollectForAllocation [ 973 5 5 ] [ 14 0 15 5 0 ] 5
@400000005175823c18ca88e4 16824.572: GenCollectForAllocation [ 973 1 0 ] [ 0 0 0 4 60 ] 0
@400000005175823c18ca9884 16824.639: GenCollectFull [ 973 0 4 ] [ 0 0 0 5 49 ] 0
@400000005175823c18caa054 16837.516: GenCollectForAllocation [ 973 2 2 ] [ 3 0 3 5 31 ] 2
@400000005175823c18cab7c4 16840.902: BulkRevokeBias [ 974 0 0 ] [ 0 0 0 5 6 ] 0
@400000005175823c18cacf34 16848.729: GenCollectForAllocation [ 973 3 4 ] [ 4 0 5 4 55 ] 3
@400000005175823c18cad704 16848.795: CMS_Initial_Mark [ 973 0 2 ] [ 0 0 0 4 24 ] 0
@400000005175823c18caf25c 16853.969: GenCollectForAllocation [ 976 1 2 ] [ 2 0 3 5 92 ] 1
@400000005175823c18cafa2c 16863.975: CMS_Final_Remark [ 977 0 0 ] [ 0 0 0 5 352 ] 0
@400000005175823c18cb1584 16867.770: GenCollectForAllocation [ 976 0 0 ] [ 0 0 0 5 114 ] 0
@400000005175823c18cb290c 16881.496: GenCollectForAllocation [ 976 3 2 ] [ 4 0 4 5 60 ] 2
@400000005175823c18cb30dc 16891.580: RevokeBias [ 976 0 0 ] [ 0 0 0 5 0 ] 0
@400000005175823c18cb4c34 16893.035: GenCollectForAllocation [ 976 1 1 ] [ 10 0 11 4 58 ] 1
@400000005175823c18cb5fbc 16904.123: GenCollectForAllocation [ 976 2 2 ] [ 5 0 5 5 65 ] 2
@400000005175823c18cb678c 16911.201: no vm operation [ 975 0 0 ] [ 0 0 0 5 0 ] 0
@400000005175823c18cb82e4 16916.963: GenCollectForAllocation [ 973 0 0 ] [ 0 0 0 5 56 ] 0
@400000005175823c18cb966c 16927.307: GenCollectForAllocation [ 973 0 0 ] [ 0 0 0 4 0 ] 0
@400000005175823c18cba60c 16927.312: GenCollectForAllocation [ 973 1 1 ] [ 0 0 0 4 54 ] 0
@400000005175823c18cbb1c4 16927.373: CMS_Initial_Mark [ 973 0 7 ] [ 0 0 0 5 25 ] 0
@400000005175823c18cbc934 16927.984: BulkRevokeBias [ 975 1 0 ] [ 0 0 0 5 7 ] 0
@400000005175823c18cbe0a4 16938.088: GenCollectForAllocation [ 975 0 0 ] [ 0 0 0 5 0 ] 0
@400000005175823c18cbe874 16938.096: GenCollectForAllocation [ 975 0 1 ] [ 0 0 0 4 77 ] 0
@400000005175823c18cc0f84 16938.178: GenCollectFull [ 975 1 4 ] [ 0 0 0 4 76 ] 0
@400000005175823c18cc136c 16941.404: CMS_Final_Remark [ 975 0 0 ] [ 0 0 0 5 17 ] 0
@400000005175823c18cc230c 16948.600: GenCollectForAllocation [ 975 0 0 ] [ 0 0 0 5 33 ] 0
@400000005175823c18cc2ec4 16959.957: GenCollectForAllocation [ 975 1 1 ] [ 5 0 5 5 56 ] 1
@400000005175823c18cc4a1c 16969.805: GenCollectForAllocation [ 975 1 2 ] [ 11 0 12 5 55 ] 1
@400000005175823c18cc55d4 vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count
@400000005175823c18cc618c 16969.879: CMS_Initial_Mark [ 975 1 3 ] [ 0 0 0 4 22 ] 0
@400000005175823c18cc712c 16981.455: GenCollectForAllocation [ 976 1 1 ] [ 8 0 8 4 76 ] 1
@400000005175823c18cc80cc 16984.811: CMS_Final_Remark [ 976 1 1 ] [ 2 0 3 5 23 ] 1
@400000005175823c18cc983c 16992.365: GenCollectForAllocation [ 975 5 5 ] [ 23 0 23 4 95 ] 5
@400000005175823c18cca3f4 17005.029: GenCollectForAllocation [ 975 0 0 ] [ 0 0 0 5 55 ] 0
@400000005175823c18ccbb64 17013.074: BulkRevokeBias [ 976 0 0 ] [ 0 0 0 4 8 ] 0
@400000005175823c18ccc71c 17015.502: GenCollectForAllocation [ 975 0 0 ] [ 0 0 0 5 57 ] 0
@400000005175823c18ccde8c 17025.293: GenCollectForAllocation [ 975 0 0 ] [ 0 0 0 5 52 ] 0
@400000005175823c18ccf214 17034.678: GenCollectForAllocation [ 973 3 3 ] [ 15 0 16 4 45 ] 3
@400000005175823c18ccfdcc 17045.910: GenCollectForAllocation [ 973 0 0 ] [ 0 0 0 5 54 ] 0
@400000005175823c18cd153c 17056.883: GenCollectForAllocation [ 973 1 2 ] [ 1 0 1 5 0 ] 1
660
I have found a short explanation in the Java Performance book:
Each line contains the time since VM launch of the safepoint operation occurred, type of VM operation, current number of threads active in the VM, current number of threads, current number of threads initially running, current number of threads waiting to block, amount of time in milliseconds threads spent spinning, amount of time in milliseconds threads spent blocked, amount of time threads spent in milliseconds synchronizing, amount of time in millis threads spent cleaning, amount of time in millis spent in VM operations, and number of page traps.
A summary is printed at the end of the output summarizing the number of different safepoint operations along with a maximum synchronization time in millis and the safepoint operation that took the maximum amount of time.
Useful for application emphasizing low latency and wanting to correlate latency events to HotSpot VM induced latencies as the result of safepoint operations.
See also -XX:+PrintGCApplicationStoppedTime and -XX+PrintGCApplicationConcurrentTime.
95
Try this page on PrintSafepointStatistics. I think with some further research you will find something useful for this.
31
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With
