Can someone please provide some insight into the the following verbosegc lines on a Java runtime with CMS GC enabled? Specifically:
- Does the event at
29.490indicate heap location of the highwater for marking? - What is the
precleanphase and what is it doing different than marking? - What is the
resetphase? Why would that take time to complete if it is not just the end of the sweep? - Finally, what is the
Rescan,greyandrootrescans andremarkareas and metrics on the event at29.653? Shall we assume these are just reported heap metrics for the subsequent sweep? If so why do they consume time?
verbosegc log excerpt:
29.490: [GC [1 CMS-initial-mark: 16225K(17684K)] 16737K(22420K), 0.0030839 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
29.494: [CMS-concurrent-mark-start]
29.652: [CMS-concurrent-mark: 0.158/0.158 secs] [Times: user=0.16 sys=0.00, real=0.16 secs]
29.652: [CMS-concurrent-preclean-start]
29.652: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
29.653: [GC[YG occupancy: 512 K (4736 K)]29.653: [Rescan (non-parallel) 29.654: [grey object rescan, 0.0001517 secs]29.654: [root rescan, 0.0030887 secs], 0.0033817 secs]29.657: [weak refs processing, 0.0000271 secs] [1 CMS-remark: 16225K(17684K)] 16737K(22420K), 0.0035183 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
29.658: [CMS-concurrent-sweep-start]
29.679: [CMS-concurrent-sweep: 0.022/0.022 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
29.680: [CMS-concurrent-reset-start]
29.703: [CMS-concurrent-reset: 0.022/0.022 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
29.797: [GC 29.797: [DefNew: 4736K->512K(4736K), 0.0207183 secs] 20800K->17172K(31512K), 0.0209119 secs] [Times: user=0.01 sys=0.02, real=0.03 secs]
Thanks,