文档章节

一次让人难以忘怀的排查频繁Full GC过程

DEC_LIU
 DEC_LIU
发布于 2013/10/13 20:29
字数 919
阅读 1834
收藏 1

 我们的Java应用因频繁FULL GC导致性能降低很多,经过多人的定位也没有结论,于是我自主请命,经过一天的研究终于搞定了,现把经验与大家共享,相关的gc日志如下:

4.758: [Full GC [PSYoungGen: 464K->0K(71936K)] [PSOldGen: 37949K->33994K(68672K)] 38413K->33994K(140608K) [PSPermGen: 33221K->33221K(66560K)], 0.1887540 secs] [Times: user=0.20 sys=0.00, real=0.19 secs]

32.324: [Full GC [PSYoungGen: 12025K->0K(176320K)] [PSOldGen: 57570K->65642K(128256K)] 69595K->65642K(304576K) [PSPermGen: 35548K->35548K(76544K)], 0.2467320 secs] [Times: user=0.22 sys=0.02, real=0.25 secs]

50.133: [Full GC [PSYoungGen: 20999K->0K(437248K)] [PSOldGen: 118647K->114524K(198528K)] 139647K->114524K(635776K) [PSPermGen: 49637K->49637K(84224K)], 0.3302180 secs] [Times: user=0.32 sys=0.00, real=0.33 secs]

149.586: [Full GC [PSYoungGen: 44223K->0K(411712K)] [PSOldGen: 190278K->185382K(296064K)] 234501K->185382K(707776K) [PSPermGen: 50674K->50208K(85248K)], 0.6151800 secs] [Times: user=0.62 sys=0.00, real=0.61 secs]

260446.223: [Full GC [PSYoungGen: 31393K->0K(436032K)] [PSOldGen: 1006486K->396428K(1021312K)] 1037880K->396428K(1457344K) [PSPermGen: 61093K->61093K(61440K)], 1.3636610 secs] [Times: user=1.36 sys=0.00, real=1.52 secs]

260630.161: [Full GC (System) [PSYoungGen: 40410K->0K(424768K)] [PSOldGen: 991397K->721859K(1021312K)] 1031808K->721859K(1446080K) [PSPermGen: 61100K->61100K(61440K)], 2.1272130 secs] [Times: user=2.14 sys=0.00, real=2.13 secs]

260720.146: [Full GC (System) [PSYoungGen: 4949K->0K(439360K)] [PSOldGen: 1004066K->833610K(1021312K)] 1009015K->833610K(1460672K) [PSPermGen: 61108K->61108K(61440K)], 2.8408660 secs] [Times: user=2.72 sys=0.10, real=2.84 secs]

260810.150: [Full GC (System) [PSYoungGen: 33459K->0K(463552K)] [PSOldGen: 949989K->245655K(1021312K)] 983448K->245655K(1484864K) [PSPermGen: 61117K->61088K(61184K)], 1.1344010 secs] [Times: user=1.12 sys=0.02, real=1.14 secs]

03430.144: [Full GC (System) [PSYoungGen: 7390K->0K(489024K)] [PSOldGen: 871871K->393481K(976704K)] 879262K->393481K(1465728K) [PSPermGen: 64306K->64295K(64640K)], 1.3848850 secs] [Times: user=1.34 sys=0.06, real=1.38 secs]

403794.982: [Full GC [PSYoungGen: 9352K->0K(454144K)] [PSOldGen: 963758K->426051K(991744K)] 973110K->426051K(1445888K) [PSPermGen: 64298K->64298K(64640K)], 1.3783510 secs] [Times: user=1.32 sys=0.06, real=1.38 secs]

404120.149: [Full GC (System) [PSYoungGen: 6846K->0K(467648K)] [PSOldGen: 943642K->440168K(991744K)] 950489K->440168K(1459392K) [PSPermGen: 64300K->64300K(64640K)], 1.1605070 secs] [Times: user=1.12 sys=0.04, real=1.16 secs]

404466.698: [Full GC [PSYoungGen: 9719K->0K(472768K)] [PSOldGen: 980355K->442899K(1021312K)] 990074K->442899K(1494080K) [PSPermGen: 64303K->64303K(64640K)], 1.1729280 secs] [Times: user=1.14 sys=0.04, real=1.18 secs]

 

经过日志分析,我找到两个突破点,重点关注红色字体部分的日志,分析过程如下: 

1
FULL GC前后Java堆大小有变化;经研究发现是由于Java应用JVM参数XMS设置为默认值,在我们的系统环境下,HotspotXms默认值为50M(-Xms默认是物理内存的1/64);每次GC时,JVM会根据各种条件调节Java堆的大小,Java堆的取值范围为[Xms, Xmx]。根据以上分析,修改Xms值与Xmx相等,这样就不会因为所使用的Java堆不够用而进行调节,经过测试后发现FULL GC次数从四位数减少至个位数。


2
)关键词“System”让我想到了System.gc调用,System.gc调用只是建议JVM执行年老代GC,而年老代GC触发FULL GCJVM会根据系统条件决定是否执行FULL GC,正因为系统条件不好判断,所以很难构造System.gc调用触发FULL GC,几经周折终于成功,当System.gc触发FULL  GC时都会有关键词System,而 JVM自动触发的FULL GC却不带关键词System,可以断定是Java应用存在“System.gc”代码。经过本次测试我也发现System.gc的真正含义,通俗言之,“System.gc” 就是FULL GC触发的最后一根稻草。 

从本次分析中,我们可以得出如下的经验:
 
1
Java应用的jvm参数XmsXmx保持一致,避免因所使用的Java堆内存不够导致频繁full gc以及full gc中因动态调节Java堆大小而耗费延长其周期。
 

2
)建议不要调用System.gc或者Runtime.getRuntime().gc,否则本次调用可能会成为压死骆驼的最后一根稻草。当然我们可以通过设置jvm参数禁止这种调用生效,但是除非特别有把握该参数有必要添加,否则不推荐这么设置。


本文转载自:

DEC_LIU
粉丝 27
博文 18
码字总数 9469
作品 0
浦东
架构师
私信 提问
GC overhead limt exceed 导致的java进程假死

1.现象 线上后台任务的java进程处于假死状态 2.排查过程 1.查看假死的进程ID 2.将该进程的所有线程信息打印输出至指定文件 3.查看该日志文件前500行的信息 No deadlocks found,代表没有发现...

熊小飞呀
01/11
132
0
一次JVM GC长暂停的排查过程

现象 通过CAT埋点,发现在35~36分钟时候,出现JVM的GC耗时异常 通过跳板机登录机器,找到GC日志进行查看,如下图 在显示的最后一行中,我们看到其中user=0,sys=0,real=4.31s,表示JVM经历了...

占小狼
2018/07/14
0
0
Java开发必须掌握的线上问题排查命令

作为一个合格的开发人员,不仅要能写得一手还代码,还有一项很重要的技能就是排查问题。这里提到的排查问题不仅仅是在coding的过程中debug等,还包括的就是线上问题的排查。由于在生产环境中...

bill_wu
2016/05/16
275
0
Java 开发必须掌握的线上问题排查命令

作为一个合格的开发人员,不仅要能写得一手还代码,还有一项很重要的技能就是排查问题。这里提到的排查问题不仅仅是在coding的过程中debug等,还包括的就是线上问题的排查。由于在生产环境中...

余平的余_余平的平
2017/09/22
0
0
一次FULL GC问题的排查

一、背景 线上一个项目,每次机器重启时项目都会报出大量的Timeout,同时每个集群节点都被监控到较为频繁的Full GC。之后同事虽然尝试过JVM调优并适当调大了老年代空间,但依然不能根本上解决...

许雪里
2016/06/15
2.7K
4

没有更多内容

加载失败,请刷新页面

加载更多

kibana汉化

kibana5 / 6 需要下载补丁包,https://github.com/anbai-inc/Kibana_Hanization 其中 v6 版本原生支持国际化,只需要添加资源文件并且配置即可 kibana7 v7版本官方内置汉化资源,在配置文件 ...

细肉云吞
19分钟前
5
0
spring boot 自定义日志 log4j2

使用默认的日志在实际开发中会存在很多问题,比如备份文件名称无法自动重命名、各个等级的日志被放在一个文件中等,所以实际开发中为了更好满足我们的需求,我们一般都会自定义采用配置的方式...

雷开你的门
23分钟前
7
0
PCB设计-Allegro软件入门系列-设计参数配置(上)

前言 经历了导入网表,和放置器件后,我们就要画板子了,但是必要的设计参数也要先准备好,磨刀不误砍柴工。 《一》显示参数 这里主要设置DRC报错标志大小和飞线显示类型 (1)DRC标志可以适当...

demyar
24分钟前
6
0
js实现微博、微信分享

html <!-- 分享 --><div class="share-box"> <b style="vertical-align: middle;">分享到:</b> <a title="分享到新浪微博" class="shareSina"><span class="share-icon"></span><......

张兴华ZHero
40分钟前
7
0
创龙TMS320DM8168浮点DSP C674x + ARM Cortex-A8的CPU、NAND FLASH、NOR FLASH

TL6678-EasyEVM是广州创龙基于SOM-TL6678核心板而研发的一款多核高性能DSP开发板。开发板采用核心板+底板方式,底板采用沉金无铅工艺的四层板设计,尺寸为200mm*106.65mm,它为用户提供了SOM...

Tronlong创龙
43分钟前
4
0

没有更多内容

加载失败,请刷新页面

加载更多

返回顶部
顶部