GC初识

准备知识

  首先GC回收的都是堆内存。 -Xms初始堆大小 ,-Xmx 堆的最大值,-Xmn 新生代大小
  判断对象是否需要被回收使用的是可达性分析法,Reachability Analysis。通过GC Roots开始所搜,可以被引用或者间接引用到的则是可达的。GC Roots有这些

  • 虚拟机栈中的本地变量中引用的对象;
  • 方法区中类静态属性引用的对象;
  • 方法区中常量引用的对象;
  • native方法引用的对象。

  对象在被回收前,会执行finalize()方法,但是执行完后可能并未被回收,比如执行过程中又重新被‘可达’,不过此方法只能执行一次。方法区也是可以被回收的,大量使用了反射、动态代理等框架需要注意此点。java8后,改成了MetaSpace。

收集算法

  • 标记清除,mark-sweep,存活对象留着,可回收对象区域清除。
  • 复制算法,将存活的对象,复制到另一块之前未使用的区域,同时将本次使用的区域清空。下回两个survivor区角色互换。新生代使用此算法,eden + survivor 为使用区域,另一个survivor则为复制后使用的空间。Hotspot默认大小配置 eden:survivor1:survivor2 = 8:1:1
  • 标记整理,mark-compact,将存活的对象集中移动到一端,剩下的空间清理。

收集实现

  • 首先,为了在一个一致性的快照中进行GC,所以就需要停顿所有的java线程,stop the world。
  • OopMap这个数据结构帮忙快速地Reachability Analysis,OopMap只在安全点的位置记录。
  • 安全点的特点是程序长时间执行,如方法调用,循环跳转等。除了安全点,线程挂起时,它就进入了安全区。GC开始工作时,必须等到所有线程都处于安全点或安全区。
  • 为了解决分代整理中跨代引用的问题,需要引入CardTable、RememberSet,相关介绍详见R大的回帖 ,Card Table相关资料

垃圾收集器

Serial/ParNew (mark copy)
  • 两者指的都是新生代收集器,copy算法,后者是前者的多线程版本,都需要全程STW,前者一般只适合桌面程序。
  • 后者可调参数有:SurvivorRatio、PretenureSizeThreshold、HandlePromotionFailure、ParallelGCThreads等。
  • 后者不一定比前这快,因为多线程还存在着线程交互的开销。
  • 只有这两者才能与CMS配合工作,所以老年代用CMS时,新生代一般用ParNew。
  • Serial Old属于老年代使用的手机算法,标记整理,在CMS的Concurrent Mode Failure后,会使用此算法。
Parallel Scavenge(mark copy)
  • 目标不一样,其他服务更关注的是如何缩短GC的STW时间,而他关注的是可控制的吞吐量,Throughput。
  • 可调参数:MaxGCPauseMillis最大停顿时间、GCTimeRatio(0 ~ 100的整数)、UseAdaptiveSizePolicy(开启此参数后,不需要关心新生代的大小,SurvivorRatio、晋升老年代的年龄,一切都可以自动调节)
  • 不能与CMS协同工作,老年代使用Parallel Old,Parallel Old是Parallel Scavenge的老年代版本,使用了多线程,是标记整理算法。
CMS(concrrent mark sweep )
  • Concurrent Mark Sweep,目标是最短回收停顿时间,最短STW时间。CMSInitiatingOccupancyFraction,老年代使用量超过此值时会触发GC。

  • 主要分成以下四步

      initial mark;(STW);标记GC Roots可以直接关联到的对象,速度很快。
      concurrent mark;
      remark;(STW);修正因java线程在并发标记阶段执行所导致的误差,速度比initial mark稍微长一些,但是远比并发标记时间短。
      concurrent sweep;
    
  • 默认的并发数量为 (cpu+3)/4;并发清理阶段的垃圾要等待下一次GC处理;

  • 主要缺陷:内存碎片,STW时间不可预测,特别是对于大的堆。

G1 Garbage-First,G1和其他的都不一样,所以下一篇会结合实践单独说。

分配与回收策略

  • 优先在eden区分配,当eden区不够分配时,进行Minor GC

  • 大对象直接分配在老年代,PretenureSizeThrehold,大于这个数值的将直接分配在老年代。单位是byte

  • 长期存活的对象晋升老年代,没经过一次Minor GC,年龄+1,MaxTenuringThreshold

  • 担保策略:进行minor GC的时候,需要进行担保,担保时逻辑如下

      老年代的连续空间大于新生代总空间?如果大于则直接直接进行minor GC,小于则继续下一个判断。
      是否允许担保失败?如果不允许则直接进行Full GC,允许则进入下一个判断。
      老年代连续空间是否大于历次晋升空间的平均值?如果小于则直接进行Full GC,否则进行Minor GC,失败了再进行Full GC。
    

实践

  说了这么多,还是来看一段线上的GClog吧。此服务此刻的QPS是700。

ParaNew

  这是一段生产环境的ParNew的GC的log,可以看出ParNew GC的频率是一秒一次,STW时间是4ms左右。

2017-03-07T16:13:42.086+0800: 439770.356: [GC2017-03-07T16:13:42.086+0800: 439770.356: [ParNew: 358294K->8279K(436928K), 0.0041210 secs] 833001K->483068K(2009792K), 0.0042070 secs] [Times: user=0.06 sys=0.00, real=0.00 secs]
2017-03-07T16:13:43.199+0800: 439771.469: [GC2017-03-07T16:13:43.199+0800: 439771.469: [ParNew: 357847K->8392K(436928K), 0.0041220 secs] 832636K->483265K(2009792K), 0.0042100 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2017-03-07T16:13:44.295+0800: 439772.565: [GC2017-03-07T16:13:44.295+0800: 439772.565: [ParNew: 357960K->8270K(436928K), 0.0041830 secs] 832833K->483392K(2009792K), 0.0042730 secs] [Times: user=0.05 sys=0.00, real=0.00 secs] 

  看其中第一条可以看出,此次gc发生之前新生代的大小是358294K,gc后新生代大小是8279K,新生代总大小是436928K,耗时是0.0041210s。
  由于ParNew是全程STW的,所以STW时间就是4ms这么长。此次GC发生之前,堆内所有对象的大小是833001K,GC后所有对象大小为483068K,注意此时只有新生代是明确活着的对象,老年代不好说。
  堆的总大小是2009792K。user耗费的时间指的是系统在user空间执行的时间,在这里就是GC线程耗费的时间,sys耗费的时间是在cpu在内核态执行的时间,在这里也就是系统调用或者是等待系统事件所耗费的时间。real是指GC所花费的真实时间,一般前两者的和除以真实时间约等于GC线程数。

CMS

  下面是这台服务器CMS GC的log,频率是一小时一次,可以看到STW时间是3ms + 330ms。

2017-03-07T15:45:17.710+0800: 438065.980: [GC [1 CMS-initial-mark: 629223K(1572864K)] 638540K(2009792K), 0.0032110 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

  第一步,initial-mark,全程STW,这一步需要标记出老年代中所有和GC roots直接引用的,或者直接被新生代中对象直接引用的。因为老年代和新生代是分开GC的,所以第二步也非常重要。
  老年代对象总大小为 629223K,老年代空间大小为1572864K。对内对象总大小为638540K,堆空间大小为2009792K,这一步耗时为0.0032110 secs。

2017-03-07T15:45:17.713+0800: 438065.983: [CMS-concurrent-mark-start]
2017-03-07T15:45:17.738+0800: 438066.009: [CMS-concurrent-mark: 0.025/0.025 secs] [Times: user=0.19 sys=0.00, real=0.02 secs]

  第二步,concurrent mark,这一过程中GC会找出老年代中所有活着的对象,根据initial mark中找出的对象来寻找。由于这一步是和应用线程同步执行的,所以会存在着标记不准确的情况。

2017-03-07T15:45:17.738+0800: 438066.009: [CMS-concurrent-preclean-start]
2017-03-07T15:45:17.745+0800: 438066.016: [CMS-concurrent-preclean: 0.007/0.007 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

  第三步,concurrent-preclean,在刚才的并发标记过程中,会出现一些区域在并发标记的过程中引用发生了变化的情况。
  JVM会将这些区域标记为dirty card,并将dirty card里的对象以及他们引用到的对象标记为可达。同时,这一阶段还为接下来的final remark做一些必要的清理和准备的工作。Card Table

2017-03-07T15:45:17.745+0800: 438066.016: [CMS-concurrent-abortable-preclean-start]
2017-03-07T15:45:18.296+0800: 438066.567: [CMS-concurrent-abortable-preclean: 0.549/0.551 secs] [Times: user=1.75 sys=0.05, real=0.55 secs]

  第四步,concurrent-abortable-preclean主要是为最终的final remark分担尽可能多的工作,因为后者是STW的,这一阶段的持续时间取决于很多因素。
  因为它是不断地遍历去执行同一件事,直到某项终止条件发生为止,比如说遍历次数到了,成功做完多少了,或者是时间到了。
  这一步对于减少接下来的STW时间有很显著的效果,并且它的一堆退出循环的参数设置也是很重要的。

2017-03-07T15:45:18.297+0800: 438066.567: [GC[YG occupancy: 187606 K (436928 K)]//新生代目前的情况
2017-03-07T15:45:18.297+0800: 438066.567: [Rescan (parallel) , 0.0146670 secs]//完成活着的对象的标记
2017-03-07T15:45:18.312+0800: 438066.582: [weak refs processing, 0.3009390 secs]//处理弱引用的对象
2017-03-07T15:45:18.613+0800: 438066.883: [class unloading, 0.0052000 secs]//卸载不使用的class
2017-03-07T15:45:18.618+0800: 438066.888: [scrub symbol table, 0.0045220 secs]
2017-03-07T15:45:18.622+0800: 438066.893: [scrub string table, 0.0006100 secs][1 CMS-remark: 629223K(1572864K)] 816830K(2009792K), 0.3304070 secs] [Times: user=0.56 sys=0.00, real=0.34 secs]

  第五步,remark,这也是一个STW的过程,目的是为了标记出老年代中所有的活着的对象。由于之前的并发标记和预处理过程都是与应用线程并发的,所以一个STW的标记过程还是必要的。
  CMS会尽量保证这个过程在新生代比较空的时候来跑,防止CMS和ParNew的STW连续出现。完成这个过程后,GC就可以放心地Sweep掉已死掉的对象。
  最终可以看到老年代的使用率和总大小,以及整个堆的使用率和大小。这个STW时间是330ms。
  这里可以看到,大多数的STW时间都耗在weak refs processing中,目前还没优化,后续会记录查找和优化过程。

2017-03-07T15:45:18.627+0800: 438066.898: [CMS-concurrent-sweep-start]
2017-03-07T15:45:18.951+0800: 438067.222: [CMS-concurrent-sweep: 0.301/0.324 secs] [Times: user=1.29 sys=0.05, real=0.32 secs]

  第六步,并发清理,清理掉已死亡的对象,与应用线程并行。

2017-03-07T15:45:18.951+0800: 438067.222: [CMS-concurrent-reset-start]
2017-03-07T15:45:18.960+0800: 438067.231: [CMS-concurrent-reset: 0.009/0.009 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

  第七步,重置CMS的一些数据结构,为下一次GC做准备。

调优?

  首先可以看到,我们的GC普遍在Remark的weak refs processing比较慢,占用了绝大多数的时间。
  除去敏感信息后,我们服务的启动参数如下

/usr/lib/jvm/java/bin/java -server   -Xms2048M -Xmx4096M -Xmn512M -XX:PermSize=64M -XX:MaxPermSize=128M -XX:SurvivorRatio=4 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:CMSInitiatingOccupancyFraction=40 -XX:+UseCMSInitiatingOccupancyOnly -XX:+CMSClassUnloadingEnabled -XX:+DisableExplicitGC -XX:+PrintPromotionFailure -XX:+HeapDumpOnOutOfMemoryError

从weak refs processing来看,找了一些资料Jon Masamitsu's Weblog

"weak refs processing" and "scrub string table" are tasks done during the remark. Those tasks took 0.0000143 secs and 0.0000258 secs, respectively. If those numbers dominate the remark pause time, they can explain unexpectedly large pauses. Not that they cannot legitimately be large. Just that generally they are not and when they are, take note. If the weak refs processing is dominate, you might be able to cut that time down by using parallel reference processing (-XX:+ParallelRefProcEnabled). No comment on the case when scrub string table is dominant. I've never had to deal with it.

  尝试在启动参数中加上-XX:+ParallelRefProcEnabled,性能确实有一些提升,从300ms降到了90ms。当然,目前我只在开发环境中对比,线上目前暂未实验,准备下周去申请一下。

  加上-XX:+PrintReferenceGC后,发现主要时间都耗费在PhantomReference中

2017-03-11T15:25:40.204+0800: 189040.496: [weak refs processing
2017-03-11T15:25:40.204+0800: 189040.496: [SoftReference, 0 refs, 0.0000080 secs]
2017-03-11T15:25:40.204+0800: 189040.496: [WeakReference, 0 refs, 0.0000150 secs]
2017-03-11T15:25:40.204+0800: 189040.496: [FinalReference, 8528 refs, 0.0208360 secs]
2017-03-11T15:25:40.225+0800: 189040.517: [PhantomReference, 4303 refs, 0.3813780 secs]
2017-03-11T15:25:40.606+0800: 189040.898: [JNI Weak Reference, 0.0005770 secs],0.4028870 secs]

  关于这个PhantomReference具体是什么,先挖个坑,等有空之后再回来记录。

  我们的服务其实分好几个集群,完全相同的代码与JVM参数,在QPS不同的情况下,GC的表现也不同,情况如下

qps ParNew频率 ParNew STW CMS频率 CMS STW
700 1s 4ms 1h 330ms
10 10min 100ms 1day 330ms
0 24min 300ms 2h 80ms

其中,qps为0的集群在CMS的表现与常识有相关违背之处。先挖个坑,等弄明白了回来记录。

六 参考文档

1、GC Algorithms: Implementations
2、R大在ITEYE的回帖
3、Jon Masamitsu's Weblog
4、深入理解Java虚拟机:JVM高级特性与最佳实践 周志明

posted on 2017-03-11 15:33  flystar32  阅读(640)  评论(0编辑  收藏  举报

导航