[13.842s][info][gc,stats] GC STATISTICS: [13.842s][info][gc,stats] "(G)" (gross) pauses include VM time: time to notify and block threads, do the pre- [13.842s][info][gc,stats] and post-safepoint housekeeping. Use -Xlog:safepoint+stats to dissect. [13.842s][info][gc,stats] "(N)" (net) pauses are the times spent in the actual GC code. [13.842s][info][gc,stats] "a" is average time for each phase, look at levels to see if average makes sense. [13.842s][info][gc,stats] "lvls" are quantiles: 0% (minimum), 25%, 50% (median), 75%, 100% (maximum). [13.842s][info][gc,stats] [13.842s][info][gc,stats] All times are wall-clock times, except per-root-class counters, that are sum over [13.842s][info][gc,stats] all workers. Dividing that over the total root stage time estimates parallelism. [13.842s][info][gc,stats] [13.842s][info][gc,stats] Total Pauses (G) = 1.28 s (a = 262 us) (n = 4876) (lvls, us = 102, 168, 207, 332, 2908) [13.842s][info][gc,stats] Total Pauses (N) = 0.69 s (a = 142 us) (n = 4876) (lvls, us = 10, 48, 92, 205, 2767) [13.842s][info][gc,stats] Pause Init Mark (G) = 0.27 s (a = 220 us) (n = 1219) (lvls, us = 141, 195, 209, 229, 1198) [13.842s][info][gc,stats] Pause Init Mark (N) = 0.12 s (a = 97 us) (n = 1219) (lvls, us = 50, 85, 93, 102, 1022) [13.842s][info][gc,stats] Make Parsable = 0.00 s (a = 3 us) (n = 1219) (lvls, us = 1, 2, 2, 3, 24) [13.842s][info][gc,stats] Clear Liveness = 0.03 s (a = 27 us) (n = 1219) (lvls, us = 13, 22, 25, 29, 763) [13.842s][info][gc,stats] Scan Roots = 0.06 s (a = 46 us) (n = 1219) (lvls, us = 23, 39, 44, 48, 946) [13.842s][info][gc,stats] S: = 0.08 s (a = 68 us) (n = 1219) (lvls, us = 35, 60, 66, 73, 440) [13.842s][info][gc,stats] S: Thread Roots = 0.04 s (a = 36 us) (n = 1219) (lvls, us = 15, 30, 35, 39, 404) [13.842s][info][gc,stats] S: Universe Roots = 0.00 s (a = 2 us) (n = 1219) (lvls, us = 1, 2, 2, 2, 24) [13.842s][info][gc,stats] S: JNI Handles Roots = 0.00 s (a = 3 us) (n = 1219) (lvls, us = 1, 2, 2, 3, 30) [13.842s][info][gc,stats] S: VM Global Roots = 0.00 s (a = 1 us) (n = 1219) (lvls, us = 0, 1, 1, 1, 13) [13.842s][info][gc,stats] S: Synchronizer Roots = 0.00 s (a = 0 us) (n = 1219) (lvls, us = 0, 0, 0, 0, 1) [13.842s][info][gc,stats] S: Management Roots = 0.00 s (a = 1 us) (n = 1219) (lvls, us = 0, 1, 1, 1, 2) [13.842s][info][gc,stats] S: System Dict Roots = 0.00 s (a = 1 us) (n = 1219) (lvls, us = 0, 1, 1, 1, 5) [13.842s][info][gc,stats] S: CLDG Roots = 0.03 s (a = 24 us) (n = 1219) (lvls, us = 10, 19, 24, 28, 55) [13.842s][info][gc,stats] S: JVMTI Roots = 0.00 s (a = 0 us) (n = 1219) (lvls, us = 0, 0, 0, 0, 1) [13.842s][info][gc,stats] Resize TLABs = 0.00 s (a = 1 us) (n = 1219) (lvls, us = 0, 1, 1, 1, 26) [13.842s][info][gc,stats] Pause Final Mark (G) = 0.58 s (a = 473 us) (n = 1219) (lvls, us = 254, 400, 455, 514, 2907) [13.842s][info][gc,stats] Pause Final Mark (N) = 0.43 s (a = 356 us) (n = 1219) (lvls, us = 158, 285, 338, 396, 2767) [13.842s][info][gc,stats] Finish Queues = 0.11 s (a = 90 us) (n = 1219) (lvls, us = 40, 67, 74, 90, 1479) [13.842s][info][gc,stats] Weak References = 0.01 s (a = 18 us) (n = 629) (lvls, us = 6, 16, 18, 20, 44) [13.842s][info][gc,stats] Process = 0.01 s (a = 15 us) (n = 629) (lvls, us = 5, 13, 15, 17, 38) [13.842s][info][gc,stats] System Purge = 0.04 s (a = 29 us) (n = 1219) (lvls, us = 14, 24, 27, 29, 1131) [13.842s][info][gc,stats] Parallel Cleanup = 0.04 s (a = 29 us) (n = 1219) (lvls, us = 14, 24, 26, 29, 1129) [13.842s][info][gc,stats] PC: = 0.00 s (a = 0 us) (n = 1219) (lvls, us = 0, 0, 0, 0, 11) [13.842s][info][gc,stats] PC: JVMTI Weak Roots = 0.00 s (a = 0 us) (n = 1219) (lvls, us = 0, 0, 0, 0, 11) [13.842s][info][gc,stats] PC: JFR Weak Roots = 0.00 s (a = 0 us) (n = 1219) (lvls, us = 0, 0, 0, 0, 1) [13.842s][info][gc,stats] Complete Liveness = 0.03 s (a = 22 us) (n = 1219) (lvls, us = 12, 20, 21, 23, 289) [13.842s][info][gc,stats] Retire TLABs = 0.00 s (a = 2 us) (n = 1219) (lvls, us = 1, 2, 2, 3, 10) [13.842s][info][gc,stats] Sync Pinned = 0.01 s (a = 12 us) (n = 1219) (lvls, us = 4, 9, 11, 13, 26) [13.842s][info][gc,stats] Choose Collection Set = 0.03 s (a = 28 us) (n = 1219) (lvls, us = 13, 26, 28, 31, 54) [13.842s][info][gc,stats] Rebuild Free Set = 0.03 s (a = 24 us) (n = 1219) (lvls, us = 11, 23, 24, 27, 74) [13.842s][info][gc,stats] Initial Evacuation = 0.15 s (a = 119 us) (n = 1219) (lvls, us = 45, 66, 119, 170, 1446) [13.842s][info][gc,stats] E: = 0.17 s (a = 135 us) (n = 1219) (lvls, us = 28, 49, 154, 213, 1611) [13.842s][info][gc,stats] E: Thread Roots = 0.05 s (a = 42 us) (n = 1219) (lvls, us = 20, 35, 39, 44, 1404) [13.842s][info][gc,stats] E: Code Cache Roots = 0.07 s (a = 54 us) (n = 1219) (lvls, us = 0, 0, 69, 111, 192) [13.842s][info][gc,stats] E: Universe Roots = 0.01 s (a = 5 us) (n = 1219) (lvls, us = 2, 4, 5, 6, 52) [13.842s][info][gc,stats] E: JVMTI Weak Roots = 0.00 s (a = 0 us) (n = 1219) (lvls, us = 0, 0, 0, 0, 1) [13.843s][info][gc,stats] E: JFR Weak Roots = 0.00 s (a = 0 us) (n = 1219) (lvls, us = 0, 0, 0, 0, 21) [13.843s][info][gc,stats] E: Synchronizer Roots = 0.00 s (a = 0 us) (n = 1219) (lvls, us = 0, 0, 0, 0, 1) [13.843s][info][gc,stats] E: Management Roots = 0.00 s (a = 1 us) (n = 1219) (lvls, us = 0, 1, 1, 1, 11) [13.843s][info][gc,stats] E: System Dict Roots = 0.00 s (a = 2 us) (n = 1219) (lvls, us = 0, 1, 2, 2, 8) [13.843s][info][gc,stats] E: CLDG Roots = 0.04 s (a = 31 us) (n = 1219) (lvls, us = 0, 0, 39, 62, 115) [13.843s][info][gc,stats] E: JVMTI Roots = 0.00 s (a = 0 us) (n = 1219) (lvls, us = 0, 0, 0, 0, 1) [13.843s][info][gc,stats] Pause Init Update Refs (G) = 0.17 s (a = 140 us) (n = 1219) (lvls, us = 98, 127, 131, 141, 1133) [13.843s][info][gc,stats] Pause Init Update Refs (N) = 0.02 s (a = 20 us) (n = 1219) (lvls, us = 10, 17, 19, 21, 55) [13.843s][info][gc,stats] Retire GCLABs = 0.00 s (a = 2 us) (n = 1219) (lvls, us = 1, 2, 2, 2, 22) [13.843s][info][gc,stats] Prepare = 0.00 s (a = 2 us) (n = 1219) (lvls, us = 1, 2, 2, 2, 25) [13.843s][info][gc,stats] Pause Final Update Refs (G) = 0.26 s (a = 215 us) (n = 1219) (lvls, us = 141, 191, 203, 223, 2682) [13.843s][info][gc,stats] Pause Final Update Refs (N) = 0.11 s (a = 93 us) (n = 1219) (lvls, us = 46, 81, 90, 102, 334) [13.843s][info][gc,stats] Update Roots = 0.04 s (a = 33 us) (n = 1219) (lvls, us = 17, 27, 30, 35, 285) [13.843s][info][gc,stats] UR: = 0.03 s (a = 27 us) (n = 1219) (lvls, us = 9, 22, 26, 30, 280) [13.843s][info][gc,stats] UR: Thread Roots = 0.03 s (a = 27 us) (n = 1219) (lvls, us = 9, 22, 26, 30, 280) [13.843s][info][gc,stats] Sync Pinned = 0.02 s (a = 13 us) (n = 1219) (lvls, us = 4, 10, 12, 16, 44) [13.843s][info][gc,stats] Trash Collection Set = 0.00 s (a = 4 us) (n = 1219) (lvls, us = 2, 4, 4, 4, 36) [13.843s][info][gc,stats] Rebuild Free Set = 0.03 s (a = 24 us) (n = 1219) (lvls, us = 12, 23, 24, 27, 52) [13.843s][info][gc,stats] Concurrent Reset = 0.28 s (a = 229 us) (n = 1219) (lvls, us = 73, 199, 232, 244, 6278) [13.843s][info][gc,stats] Concurrent Marking = 0.55 s (a = 450 us) (n = 1219) (lvls, us = 178, 406, 439, 477, 3665) [13.843s][info][gc,stats] Concurrent Precleaning = 0.19 s (a = 305 us) (n = 629) (lvls, us = 1, 289, 295, 328, 1043) [13.843s][info][gc,stats] Concurrent Roots = 0.24 s (a = 195 us) (n = 1219) (lvls, us = 31, 62, 74, 314, 8650) [13.843s][info][gc,stats] Concurrent Evacuation = 0.63 s (a = 521 us) (n = 1219) (lvls, us = 209, 480, 539, 586, 1477) [13.843s][info][gc,stats] Concurrent Update Refs = 1.46 s (a = 1199 us) (n = 1219) (lvls, us = 498, 1035, 1113, 1191, 109242) [13.843s][info][gc,stats] Concurrent Cleanup = 0.77 s (a = 314 us) (n = 2437) (lvls, us = 150, 318, 324, 332, 1029)