JVM SafePointStatistics - can anyone help interpret it

When you turn on +XX:PrintSafePointStatistics I see a dump in stdout in the following format. Can anyone help me interpret the column names or the JVM guide that explains this correctly? The JVM specification guide does not seem to cover the full meaning of the headers and its explanations.

 @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 
+4
source share
2 answers

I found a short explanation in the Java performance book:

Each line contains the time elapsed since the start of the virtual machine during the safepoint operation, such as the operation of the virtual machine, the current number of threads active in the virtual machine, the current number of threads, the current number of threads that were initially started, the current number of threads waiting to be blocked, the amount of time in milliseconds spent on untwisting threads, the amount of time in milliseconds spent on locking, the number of threads spent on synchronizing in milliseconds ndah, the amount of time spent cleaning milliseconds, the amount of time in milliseconds spent on VM operations, and the number of page traps.

A summary is printed at the end of the output, summing up the number of different safepoint operations along with the maximum synchronization time in millise and the safepoint operation, which took the maximum period of time.

Useful for applications that emphasize low latency and want to associate delay events with VMS caused by HotSpot delays resulting from safepoint operations.

See also -XX:+PrintGCApplicationStoppedTime and -XX+PrintGCApplicationConcurrentTime .

+6
source

Try this page at PrintSafepointStatistics . I think that with some further research you will find something useful for this.

+2
source

All Articles