How do I know how much memory is reclaimed in major GC?

Thu Jun 27 21:32:52 UTC 2019

Hi all,

I know young GC and full GC logs show that information like xxx->yyy. But in the major GC log, I can only see that information in 'initial mark' and 'final mark', but not in 'sweep'.  So do I know in the end of a major GC, how much memory in the old generation is claimed? The logs are copied below.

2019-06-27T17:23:18.139+0000: 4910103.818: [GC (CMS Initial Mark) [1 CMS-initial-mark: 153077851K(192937984K)] 163324888K(208037504K), 0.4523961 secs] [Times: user=9.72 sys=0.00, real=0.45 secs]

2019-06-27T17:23:18.592+0000: 4910104.271: [CMS-concurrent-mark-start]

2019-06-27T17:23:26.129+0000: 4910111.809: [GC (Allocation Failure) 2019-06-27T17:23:26.129+0000: 4910111.809: [ParNew: 14150221K->540552K(15099520K), 0.1156212 secs] 167228072K->153698883K(208037504K), 0.1159003 secs] [Times: user=1.69 sys=0.04, real=0.12 secs]

2019-06-27T17:23:44.311+0000: 4910129.990: [GC (Allocation Failure) 2019-06-27T17:23:44.311+0000: 4910129.991: [ParNew: 13962376K->598403K(15099520K), 0.0935279 secs] 167120707K->153851083K(208037504K), 0.0940204 secs] [Times: user=1.45 sys=0.04, real=0.10 secs]

2019-06-27T17:23:58.935+0000: 4910144.614: [GC (Allocation Failure) 2019-06-27T17:23:58.935+0000: 4910144.615: [ParNew: 14020227K->586078K(15099520K), 0.0788172 secs] 167272907K->153903041K(208037504K), 0.0792265 secs] [Times: user=1.30 sys=0.02, real=0.08 secs]

2019-06-27T17:24:15.395+0000: 4910161.075: [GC (Allocation Failure) 2019-06-27T17:24:15.395+0000: 4910161.075: [ParNew: 14007902K->469610K(15099520K), 0.1240080 secs] 167324865K->153824425K(208037504K), 0.1244094 secs] [Times: user=2.32 sys=0.00, real=0.12 secs]

2019-06-27T17:24:27.544+0000: 4910173.223: [GC (Allocation Failure) 2019-06-27T17:24:27.544+0000: 4910173.223: [ParNew: 13891434K->510929K(15099520K), 0.0909259 secs] 167246249K->153908238K(208037504K), 0.0912949 secs] [Times: user=1.72 sys=0.00, real=0.09 secs]

2019-06-27T17:24:42.046+0000: 4910187.726: [GC (Allocation Failure) 2019-06-27T17:24:42.047+0000: 4910187.726: [ParNew: 13932753K->513954K(15099520K), 0.0769428 secs] 167330062K->153981588K(208037504K), 0.0774068 secs] [Times: user=1.32 sys=0.01, real=0.08 secs]

2019-06-27T17:24:43.881+0000: 4910189.561: [CMS-concurrent-mark: 84.525/85.290 secs] [Times: user=719.00 sys=127.59, real=85.29 secs]

2019-06-27T17:24:43.882+0000: 4910189.561: [CMS-concurrent-preclean-start]

2019-06-27T17:24:46.974+0000: 4910192.654: [CMS-concurrent-preclean: 2.943/3.093 secs] [Times: user=11.39 sys=5.30, real=3.10 secs]

2019-06-27T17:24:46.974+0000: 4910192.654: [CMS-concurrent-abortable-preclean-start]

 CMS: abort preclean due to time 2019-06-27T17:24:52.139+0000: 4910197.818: [CMS-concurrent-abortable-preclean: 5.162/5.164 secs] [Times: user=20.51 sys=9.57, real=5.16 secs]

2019-06-27T17:24:52.150+0000: 4910197.830: [GC (CMS Final Remark) [YG occupancy: 11527850 K (15099520 K)]2019-06-27T17:24:52.150+0000: 4910197.830: [Rescan (parallel) , 0.4904597 secs]2019-06-27T17:24:52.641+0000: 4910198.320: [weak refs processing, 0.0000493 secs]2019-06-27T17:24:52.641+0000: 4910198.320: [class unloading, 0.0275684 secs]2019-06-27T17:24:52.668+0000: 4910198.348: [scrub symbol table, 0.0065112 secs]2019-06-27T17:24:52.675+0000: 4910198.354: [scrub string table, 0.0010931 secs][1 CMS-remark: 153467633K(192937984K)] 164995484K(208037504K), 0.5259280 secs] [Times: user=11.21 sys=0.00, real=0.53 secs]

2019-06-27T17:24:52.676+0000: 4910198.356: [CMS-concurrent-sweep-start]

2019-06-27T17:24:54.357+0000: 4910200.036: [GC (Allocation Failure) 2019-06-27T17:24:54.357+0000: 4910200.036: [ParNew: 13935778K->370580K(15099520K), 0.0994279 secs] 167403411K->153919879K(208037504K), 0.0997809 secs] [Times: user=1.02 sys=0.02, real=0.10 secs]

2019-06-27T17:25:07.586+0000: 4910213.266: [GC (Allocation Failure) 2019-06-27T17:25:07.586+0000: 4910213.266: [ParNew: 13792404K->395870K(15099520K), 0.0708121 secs] 167341667K->153994461K(208037504K), 0.0713124 secs] [Times: user=0.66 sys=0.04, real=0.07 secs]

2019-06-27T17:25:19.434+0000: 4910225.113: [GC (Allocation Failure) 2019-06-27T17:25:19.434+0000: 4910225.113: [ParNew: 13817694K->317097K(15099520K), 0.0555208 secs] 167416220K->153953500K(208037504K), 0.0558582 secs] [Times: user=0.96 sys=0.07, real=0.06 secs]

2019-06-27T17:25:33.079+0000: 4910238.758: [GC (Allocation Failure) 2019-06-27T17:25:33.079+0000: 4910238.759: [ParNew: 13738921K->385539K(15099520K), 0.0562133 secs] 167374552K->154068319K(208037504K), 0.0565427 secs] [Times: user=1.00 sys=0.05, real=0.06 secs]

2019-06-27T17:25:45.898+0000: 4910251.577: [GC (Allocation Failure) 2019-06-27T17:25:45.898+0000: 4910251.578: [ParNew: 13807363K->394530K(15099520K), 0.0607561 secs] 167486290K->154100069K(208037504K), 0.0611687 secs] [Times: user=0.98 sys=0.00, real=0.06 secs]

2019-06-27T17:25:47.152+0000: 4910252.832: [CMS-concurrent-sweep: 53.926/54.476 secs] [Times: user=206.32 sys=87.94, real=54.47 secs]

2019-06-27T17:25:47.153+0000: 4910252.832: [CMS-concurrent-reset-start]

2019-06-27T17:25:48.122+0000: 4910253.802: [CMS-concurrent-reset: 0.970/0.970 secs] [Times: user=3.55 sys=1.44, real=0.98 secs]

Xinli