(转)关于施用full gc频繁的分析及解决

标签: full gc 分析 | 发表时间:2016-10-21 13:10 | 作者:wbj0110
出处:http://www.iteye.com

分析

   当频繁full gc时,jstack打印出堆栈信息如下:
   sudo -u admin -H /opt/taobao/java/bin/jstack `pgrep java` > #your file path#
       
   可以看到的确是在跑低价信息
   另外在应用频繁full gc时和应用正常时,也执行了如下2种命令:
   sudo -u admin -H /opt/taobao/java/bin/jmap -histo `pgrep` > #your file path#
   sudo -u admin -H /opt/taobao/java/bin/jmap -histo:live `pgrep` > #your file path#(live会产生full gc)
   目的是确认以下2种信息:
   (1)是否存在某些引用的不正常,造成对象始终可达而无法回收(Java中的内存泄漏)
   (2)是否真是由于在频繁full gc时同时又有大量请求进入分配内存从而处理不过来,
        造成concurrent mode failure?
   下图是在应用正常情况下,jmap不加live,产生的histo信息:
       
   下图是在应用正常情况下,jmap加live,产生的histo信息:
       
   下图是在应用频繁full gc情况下,jmap不加live和加live,产生的histo信息:
       
   从上述几个图中可以看到:
   (1)在应用正常情况下,图中标红的对象是被回收的,因此不是内存泄漏问题
   (2)在应用频繁full gc时,标红的对象即使加live也是未被回收的,因上就是在频繁full gc时,
        同时又有大量请求进入分配内存从而处理不过来的问题

先从解决问题的角度,看怎样造成频繁的full gc?

从分析CMS GC开始
   先给个CMS GC的概况:
   (1)young gc
   可以看到,当eden满时,young gc使用的是ParNew收集器
   ParNew: 2230361K->129028K(2403008K), 0.2363650 secs解释:
   1)2230361K->129028K,指回收前后eden+s1(或s2)大小
   2)2403008K,指可用的young代的大小,即eden+s1(或s2)
   3)0.2363650 secs,指消耗时间
   2324774K->223451K(3975872K), 0.2366810 sec解释:
   1)2335109K->140198K,指整个堆大小的变化
(heap=(young+old)+perm;young=eden+s1+s2;s1=s2=young/(survivor ratio+2))
   2)0.2366810 sec,指消耗时间
   [Times: user=0.60 sys=0.02, real=0.24 secs]解释:指用户时间,系统时间,真实时间
       
   (2)cms gc
   当使用CMS收集器时,当开始进行收集时,old代的收集过程如下所示:
   a)首先jvm根据-XX:CMSInitiatingOccupancyFraction,-XX:+UseCMSInitiatingOccupancyOnly
     来决定什么时间开始垃圾收集
   b)如果设置了-XX:+UseCMSInitiatingOccupancyOnly,那么只有当old代占用确实达到了
     -XX:CMSInitiatingOccupancyFraction参数所设定的比例时才会触发cms gc
   c)如果没有设置-XX:+UseCMSInitiatingOccupancyOnly,那么系统会根据统计数据自行决定什么时候
    触发cms gc;因此有时会遇到设置了80%比例才cms gc,但是50%时就已经触发了,就是因为这个参数
    没有设置的原因
   d)当cms gc开始时,首先的阶段是CMS-initial-mark,此阶段是初始标记阶段,是stop the world阶段,
     因此此阶段标记的对象只是从root集最直接可达的对象
   CMS-initial-mark:961330K(1572864K),指标记时,old代的已用空间和总空间
   e)下一个阶段是CMS-concurrent-mark,此阶段是和应用线程并发执行的,所谓并发收集器指的就是这个,
     主要作用是标记可达的对象
   此阶段会打印2条日志:CMS-concurrent-mark-start,CMS-concurrent-mark
   f)下一个阶段是CMS-concurrent-preclean,此阶段主要是进行一些预清理,因为标记和应用线程是并发执行的,
    因此会有些对象的状态在标记后会改变,此阶段正是解决这个问题
   因为之后的Rescan阶段也会stop the world,为了使暂停的时间尽可能的小,也需要preclean阶段先做一部分
    工作以节省时间
   此阶段会打印2条日志:CMS-concurrent-preclean-start,CMS-concurrent-preclean
   g)下一阶段是CMS-concurrent-abortable-preclean阶段,加入此阶段的目的是使cms gc更加可控一些,
     作用也是执行一些预清理,以减少Rescan阶段造成应用暂停的时间
   此阶段涉及几个参数:
   -XX:CMSMaxAbortablePrecleanTime:当abortable-preclean阶段执行达到这个时间时才会结束
   -XX:CMSScheduleRemarkEdenSizeThreshold(默认2m):控制abortable-preclean阶段什么时候开始执行,
即当eden使用达到此值时,才会开始abortable-preclean阶段
   -XX:CMSScheduleRemarkEdenPenetratio(默认50%):控制abortable-preclean阶段什么时候结束执行
   此阶段会打印一些日志如下:
   CMS-concurrent-abortable-preclean-start,CMS-concurrent-abortable-preclean,
CMS:abort preclean due to time XXX
   h)再下一个阶段是第二个stop the world阶段了,即Rescan阶段,此阶段暂停应用线程,对对象进行重新扫描并
     标记
   YG occupancy:964861K(2403008K),指执行时young代的情况
   CMS remark:961330K(1572864K),指执行时old代的情况
   此外,还打印出了弱引用处理、类卸载等过程的耗时
   i)再下一个阶段是CMS-concurrent-sweep,进行并发的垃圾清理
   j)最后是CMS-concurrent-reset,为下一次cms gc重置相关数据结构
       
   (3)full gc:
   有2种情况会触发full gc,在full gc时,整个应用会暂停
   a)concurrent-mode-failure:当cms gc正进行时,此时有新的对象要进行old代,但是old代空间不足造成的
   b)promotion-failed:当进行young gc时,有部分young代对象仍然可用,但是S1或S2放不下,
    因此需要放到old代,但此时old代空间无法容纳此
       

 

频繁full gc的原因
   从日志中可以看出有大量的concurrent-mode-failure,因此正是当cms gc进行时,有新的对象要进行old代,
但是old代空间不足造成的full gc
   进程的jvm参数如下所示:
       
   影响cms gc时长及触发的参数是以下2个:
   -XX:CMSMaxAbortablePrecleanTime=5000
   -XX:CMSInitiatingOccupancyFraction=80
   解决也是针对这两个参数来的
   根本的原因是每次请求消耗的内存量过大

解决

   (1)针对cms gc的触发阶段,调整-XX:CMSInitiatingOccupancyFraction=50,提早触发cms gc,就可以
        缓解当old代达到80%,cms gc处理不完,从而造成concurrent mode failure引发full gc
   (2)修改-XX:CMSMaxAbortablePrecleanTime=500,缩小CMS-concurrent-abortable-preclean阶段
        的时间
   (3)考虑到cms gc时不会进行compact,因此加入-XX:+UseCMSCompactAtFullCollection
       (cms gc后会进行内存的compact)和-XX:CMSFullGCsBeforeCompaction=4
       (在full gc4次后会进行compact)参数
   但是运行了一段时间后,只不过时间更长了,又会出现频繁full gc
   计算了一下heap各个代的大小(可以用jmap -heap查看):
   total heap=young+old=4096m
   perm:256m
   young=s1+s2+eden=2560m
   young avail=eden+s1=2133.375+213.3125=2346.6875m
   s1=2560/(10+1+1)=213.3125m
   s2=s1
   eden=2133.375m
   old=1536m
   可以看到eden大于old,在极端情况下(young区的所有对象全都要进入到old时,就会触发full gc),
因此在应用频繁full gc时,很有可能old代是不够用的,因此想到将old代加大,young代减小
   改成以下:
   -Xmn1920m
   新的各代大小:
   total heap=young+old=4096m
   perm:256m
   young=s1+s2+eden=1920m
   young avail=eden+s1=2133.375+213.3125=1760m
   s1=1760/(10+1+1)=160m
   s2=s1
   eden=1600m
   old=2176m
   此时的eden小于old,可以缓解一些问题
    

 

   改完之后,运行了2天,问题解决,未频繁报full gc

https://my.oschina.net/goldwave/blog/168516


已有 0 人发表留言,猛击->> 这里<<-参与讨论


ITeye推荐



相关 [full gc 分析] 推荐:

系统频繁Full gc问题分析及解决办法

- - JavaRanger - 专注JAVA高性能程序开发、JVM、Mysql优化、算法
上周开始系统在业务高峰期一直收到Full gc报警,监控显示fgc频繁,下图是监控图,左边红框是优化前效果,右边是优化后,优化后fgc基本为0. 1.查看gc日志,发现old区fgc后大小没有变化,如下图:. 2.去线上dump内存看是什么对象,用memory analyzer分析,Retained Size竟然有2.4G,全是sun.awt.SunToolkit这个对象,其实到这一步已经可以确定是什么问题了,只是自己对系统不是很熟悉,导致定位具体的问题代码花了一些时间.

(转)关于施用full gc频繁的分析及解决

- - Java - 编程语言 - ITeye博客
当频繁full gc时,jstack打印出堆栈信息如下:. 可以看到的确是在跑低价信息. 另外在应用频繁full gc时和应用正常时,也执行了如下2种命令:. sudo -u admin -H /opt/taobao/java/bin/jmap -histo:live `pgrep` > #your file path#(live会产生full gc).

触发Full GC执行的情况

- - Web前端 - ITeye博客
除直接调用System.gc外,触发Full GC执行的情况有如下四种. 旧生代空间只有在新生代对象转入及创建为大对象、大数组时才会出现不足的现象,当执行Full GC后空间仍然不足,则抛出如下错误:. 为避免以上两种状况引起的Full GC,调优时应尽量做到让对象在Minor GC阶段被回收、让对象在新生代多存活一段时间及不要创建过大的对象及数组.

Full GC是否真的存在

- - Java译站
在Plumbr这和GC暂停检测打交道的这段日子里,我查阅了与这个主题相关的大量文章,书籍以及资料. 在这当中,我经常会对新生代GC, 年老代GC以及Full GC的事件的使用(滥用)感到困惑. 于是便有了这篇文章,希望能够清除一些困惑. 本文需要读者对JVM内建的GC相关的常用原理有一定的了解. 像eden区,Survivor区以及年老区空间的划分,分代假设(generational hypothesis)以及不同的GC算法就不在本文的讨论范围之内了.

利用Arena Allocation避免HBase触发Full GC

- Adam - 淘宝JAVA中间件团队博客
Arena Allocation,是一种GC优化技术,它可以有效地减少因内存碎片导致的Full GC,从而提高系统的整体性能. 本文介绍Arena Allocation的原理及其在Hbase中的应用-MSLAB. 假设有1G内存,我顺序创建了1百万个对象,每个对象大小1K,Heap会被渐渐充满且每个对象以创建顺序相邻.

FULL GC有可能导致JVM暂停1分钟以上吗?

- - 高级语言虚拟机
作者: qianhd . 链接: http://hllvm.group.iteye.com/group/topic/28745 . 发表时间: 2011年12月30日. 声明:本文系ITeye网站发布的原创文章,未经作者书面许可,严禁任何网站转载本文,否则必将追究法律责任. 与另外个程序交互有个心跳检测, 15s/次, 31s没有收到心跳检测的返回消息就认为连接断了,.

Tomcat的JreMemoryLeakPreventionListener监听周期性频繁执行full gc

- -
网上还是有蛮多解决方案,还是说说我最比较喜欢且常用的吧,. 1、添加gcDaemonProtection="false"参数禁用JreMemoryLeakPreventionListener监听. 2、直接删除JreMemoryLeakPreventionListener监听. 已有 0 人发表留言,猛击->> 这里<<-参与讨论.

JVM初探——使用堆外内存减少Full GC

- - ImportNew
GCIH可以联想到:  将长期存活的对象(如Local Cache)移入堆外内存(off-heap, 又名. 直接内存/direct-memory), 从而减少CMS管理的对象数量, 以降低Full GC的次数和频率, 达到提高系统响应速度的目的.. 这个idea最初来源于TaobaoJVM对OpenJDK定制开发的GCIH部分(详见 撒迦的分享- JVM定制改进@淘宝), 其中GCIH就是将CMS Old Heap区的一部分划分出来, 这部分内存虽然还在堆内, 但已不被GC所管理.

GC 日志分析

- - 码蜂笔记
不同的JVM及其选项会输出不同的日志. 生成下面日志使用的选项: -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:d:/GClogs/tomcat6-gc.log. 最前面的数字 4.231 和 4.445 代表虚拟机启动以来的秒数.

gc日志分析工具

- - Web前端 - ITeye博客
性能测试排查定位问题,分析调优过程中,会遇到要分析gc日志,人肉分析gc日志有时比较困难,相关图形化或命令行工具可以有效地帮助辅助分析. 通过在tomcat启动脚本中添加相关参数生成gc日志. -verbose.gc开关可显示GC的操作内容. 打开它,可以显示最忙和最空闲收集行为发生的时间、收集前后的内存大小、收集需要的时间等.