你的位置:首页 > Java教程

[Java教程]GC之详解CMS收集过程和日志分析


2016-08-23   关于GC的算法和垃圾收集器的种类就暂且不说了,网上有大把的资料供参考

话题引入

让我们先简单的看下整个堆年轻代和年老代的垃圾收集器组合(以下配合java8完美支持,其他版本可能稍有不同),其中标红线的则是我们今天要着重讲的内容:

ParNew and CMS

"Concurrent Mark and Sweep" 是CMS的全称,官方给予的名称是:“Mostly Concurrent Mark and Sweep Garbage Collector”;

年轻代:采用 stop-the-world mark-copy 算法;

年老代:采用 Mostly Concurrent mark-sweep 算法;

设计目标:年老代收集的时候避免长时间的暂停;

能够达成该目标主要因为以下两个原因:

1  它不会花时间整理压缩年老代,而是维护了一个叫做 free-lists 的数据结构,该数据结构用来管理那些回收再利用的内存空间;

2  mark-sweep分为多个阶段,其中一大部分阶段GC的工作是和Application threads的工作同时进行的(当然,gc线程会和用户线程竞争CPU的时间),默认的GC的工作线程为你服务器物理CPU核数的1/4;

补充:当你的服务器是多核同时你的目标是低延时,那该GC的搭配则是你的不二选择。

日志

GC日志初体验

首先对整个GC日志有一个大概的认知

2016-08-23T02:23:07.219-0200: 64.322: [GC (Allocation Failure) 64.322: [ParNew: 613404K->68068K(613440K), 0.1020465 secs] 10885349K->10880154K(12514816K), 0.1021309 secs] [Times: user=0.78 sys=0.01, real=0.11 secs]

2016-08-23T02:23:07.321-0200: 64.425: [GC (CMS Initial Mark) [1 CMS-initial-mark: 10812086K(11901376K)] 10887844K(12514816K), 0.0001997 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]2016-08-23T02:23:07.321-0200: 64.425: [CMS-concurrent-mark-start]2016-08-23T02:23:07.357-0200: 64.460: [CMS-concurrent-mark: 0.035/0.035 secs] [Times: user=0.07 sys=0.00, real=0.03 secs]2016-08-23T02:23:07.357-0200: 64.460: [CMS-concurrent-preclean-start]2016-08-23T02:23:07.373-0200: 64.476: [CMS-concurrent-preclean: 0.016/0.016 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]2016-08-23T02:23:07.373-0200: 64.476: [CMS-concurrent-abortable-preclean-start]2016-08-23T02:23:08.446-0200: 65.550: [CMS-concurrent-abortable-preclean: 0.167/1.074 secs] [Times: user=0.20 sys=0.00, real=1.07 secs]2016-08-23T02:23:08.447-0200: 65.550: [GC (CMS Final Remark) [YG occupancy: 387920 K (613440 K)]65.550: [Rescan (parallel) , 0.0085125 secs]65.559: [weak refs processing, 0.0000243 secs]65.559: [class unloading, 0.0013120 secs]65.560: [scrub symbol table, 0.0008345 secs]65.561: [scrub string table, 0.0001759 secs][1 CMS-remark: 10812086K(11901376K)] 11200006K(12514816K), 0.0110730 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]2016-08-23T02:23:08.458-0200: 65.561: [CMS-concurrent-sweep-start]2016-08-23T02:23:08.485-0200: 65.588: [CMS-concurrent-sweep: 0.027/0.027 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]2016-08-23T02:23:08.485-0200: 65.589: [CMS-concurrent-reset-start]2016-08-23T02:23:08.497-0200: 65.601: [CMS-concurrent-reset: 0.012/0.012 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

Minor GC

2016-08-23T02:23:07.219-02001: 64.3222:[GC3(Allocation Failure4) 64.322: [ParNew5: 613404K->68068K6(613440K)7, 0.1020465 secs8] 10885349K->10880154K9(12514816K)10, 0.1021309 secs11][Times: user=0.78 sys=0.01, real=0.11 secs]12

 

Full/Major GC 

参考资料

https://plumbr.eu/handbook/garbage-collection-algorithms-implementations#concurrent-mark-and-sweep