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.490
indicate heap location of the highwater for marking? - What is the
preclean
phase and what is it doing different than marking? - What is the
reset
phase? Why would that take time to complete if it is not just the end of the sweep? - Finally, what is the
Rescan
,grey
androot
rescans andremark
areas 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,