先上日志
[code]
2017-02-25T16:27:41.816+0800: 339244.886: [GC [1 CMS-initial-mark: 7342588K(10485760K)] 7903351K(76546048K), 0.3641640 secs] [Times: user=0.35 sys=0.00, real=0.37 secs]
2017-02-25T16:27:42.181+0800: 339245.251: [CMS-concurrent-mark-start]
2017-02-25T16:27:44.010+0800: 339247.080: [CMS-concurrent-mark: 1.803/1.829 secs] [Times: user=17.12 sys=1.59, real=1.83 secs]
2017-02-25T16:27:44.010+0800: 339247.080: [CMS-concurrent-preclean-start]
2017-02-25T16:27:44.080+0800: 339247.150: [CMS-concurrent-preclean: 0.068/0.070 secs] [Times: user=0.27 sys=0.03, real=0.07 secs]
2017-02-25T16:27:44.080+0800: 339247.151: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2017-02-25T16:27:49.085+0800: 339252.155: [CMS-concurrent-abortable-preclean: 4.989/5.004 secs] [Times: user=18.04 sys=2.46, real=5.00 secs]
2017-02-25T16:27:49.099+0800: 339252.169: [GC[YG occupancy: 4399323 K (66060288 K)]2017-02-25T16:27:49.100+0800: 339252.170: [Rescan (parallel) , 1.1329590 secs]2017-02-25T16:27:50.233+0800: 339253.303: [weak refs processing, 0
.0087210 secs]2017-02-25T16:27:50.241+0800: 339253.311: [scrub string table, 0.0056330 secs] [1 CMS-remark: 7342588K(10485760K)] 11741911K(76546048K), 1.1481420 secs] [Times: user=20.25 sys=0.00, real=1.14 secs]
2017-02-25T16:27:50.248+0800: 339253.318: [CMS-concurrent-sweep-start]
2017-02-25T16:28:00.500+0800: 339263.570: [CMS-concurrent-sweep: 10.036/10.252 secs] [Times: user=42.01 sys=5.90, real=10.25 secs]
2017-02-25T16:28:00.500+0800: 339263.570: [CMS-concurrent-reset-start]
2017-02-25T16:28:00.529+0800: 339263.599: [CMS-concurrent-reset: 0.029/0.029 secs] [Times: user=0.11 sys=0.02, real=0.03 secs]
[/code]

其中initial-mark和remark是STW的,其它阶段是concurrent(并发)的,用户线程可以正常执行。
这次GC的STW时间是0.37(initial-mark) + 1.148(remark) = 1.518秒。
其它的近10多秒是并发的阶段。

标签: CMS, concurrent, gc

添加新评论