JVM 调优 —— GC 长时间停顿问题及解决方法
零. 简介
一. 并发模式失败(concurrent mode failure)
并发模式失败日志:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
|
2016-02-21T13:53:07.974+0800: 171467.254: [GC [1 CMS-initial-mark: 1436199K(1560576K)] 1512927K(2504320K), 0.0618140 secs] [Times: user=0.06 sys=0.00, real=0.07 secs]
2016-02-21T13:53:08.036+0800: 171467.316: [CMS-concurrent-mark-start]
2016-02-21T13:53:08.377+0800: 171467.657: [CMS-concurrent-mark: 0.340/0.340 secs] [Times: user=2.11 sys=0.15, real=0.34 secs]
2016-02-21T13:53:08.377+0800: 171467.657: [CMS-concurrent-preclean-start]
2016-02-21T13:53:08.385+0800: 171467.665: [CMS-concurrent-preclean: 0.008/0.008 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2016-02-21T13:53:08.385+0800: 171467.665: [CMS-concurrent-abortable-preclean-start]
{Heap before GC invocations=88667 (full 45):
par new generation total 943744K, used 914399K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)
eden space 838912K, 100% used [0x0000000757000000, 0x000000078a340000, 0x000000078a340000)
from space 104832K, 72% used [0x000000078a340000, 0x000000078ecf7d98, 0x00000007909a0000)
to space 104832K, 0% used [0x00000007909a0000, 0x00000007909a0000, 0x0000000797000000)
concurrent mark-sweep generation total 1560576K, used 1436199K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
2016-02-21T13:53:09.535+0800: 171468.815: [GC2016-02-21T13:53:09.535+0800: 171468.815: [ParNew
Desired survivor size 53673984 bytes, new threshold 6 (max 6)
- age 1: 7100568 bytes, 7100568 total
- age 2: 4676456 bytes, 11777024 total
- age 3: 8773736 bytes, 20550760 total
- age 4: 7709744 bytes, 28260504 total
- age 5: 10891960 bytes, 39152464 total
- age 6: 11735032 bytes, 50887496 total
: 914399K->75616K(943744K), 0.0414860 secs] 2350599K->1517225K(2504320K), 0.0417710 secs] [Times: user=0.32 sys=0.05, real=0.05 secs]
Heap after GC invocations=88668 (full 45):
par new generation total 943744K, used 75616K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)
eden space 838912K, 0% used [0x0000000757000000, 0x0000000757000000, 0x000000078a340000)
from space 104832K, 72% used [0x00000007909a0000, 0x0000000795378128, 0x0000000797000000)
to space 104832K, 0% used [0x000000078a340000, 0x000000078a340000, 0x00000007909a0000)
concurrent mark-sweep generation total 1560576K, used 1441609K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
}
2016-02-21T13:53:10.202+0800: 171469.482: [CMS-concurrent-abortable-preclean: 1.772/1.817 secs] [Times: user=4.94 sys=0.06, real=1.81 secs]
2016-02-21T13:53:10.204+0800: 171469.483: [GC[YG occupancy: 497152 K (943744 K)]2016-02-21T13:53:10.204+0800: 171469.483: [Rescan (parallel) , 1.3691900 secs]2016-02-21T13:53:11.573+0800: 171470.853: [weak refs processing, 0.1009300 secs]2016-02-21T13:53:11.674+0800: 1714
70.954: [class unloading, 0.0153470 secs]2016-02-21T13:53:11.689+0800: 171470.969: [scrub symbol table, 0.0110770 secs]2016-02-21T13:53:11.700+0800: 171470.980: [scrub string table, 0.0016360 secs] [1 CMS-remark: 1441609K(1560576K)] 1938761K(2504320K), 1.5079530 secs] [Ti
mes: user=13.01 sys=0.08, real=1.51 secs]
2016-02-21T13:53:11.712+0800: 171470.992: [CMS-concurrent-sweep-start]
{Heap before GC invocations=88668 (full 45):
par new generation total 943744K, used 914528K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)
eden space 838912K, 100% used [0x0000000757000000, 0x000000078a340000, 0x000000078a340000)
from space 104832K, 72% used [0x00000007909a0000, 0x0000000795378128, 0x0000000797000000)
to space 104832K, 0% used [0x000000078a340000, 0x000000078a340000, 0x00000007909a0000)
concurrent mark-sweep generation total 1560576K, used 1441606K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
2016-02-21T13:53:11.775+0800: 171471.055: [GC2016-02-21T13:53:11.775+0800: 171471.055: [ParNew (promotion failed)
Desired survivor size 53673984 bytes, new threshold 6 (max 6)
- age 1: 4030872 bytes, 4030872 total
- age 2: 5959704 bytes, 9990576 total
- age 3: 4628680 bytes, 14619256 total
- age 4: 8773080 bytes, 23392336 total
- age 5: 7707144 bytes, 31099480 total
- age 6: 10890224 bytes, 41989704 total
: 914528K->907344K(943744K), 1.0312010 secs]2016-02-21T13:53:12.807+0800: 171472.086: [CMS2016-02-21T13:53:14.455+0800: 171473.735: [CMS-concurrent-sweep: 1.684/2.743 secs] [Times: user=3.69 sys=0.36, real=2.74 secs]
(concurrent mode failure): 1451903K->475795K(1560576K), 3.9644230 secs] 2356134K->475795K(2504320K), [CMS Perm : 78413K->78413K(159744K)], 4.9959570 secs] [Times: user=5.65 sys=0.34, real=5.00 secs]
Heap after GC invocations=88669 (full 46):
par new generation total 943744K, used 0K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)
eden space 838912K, 0% used [0x0000000757000000, 0x0000000757000000, 0x000000078a340000)
from space 104832K, 0% used [0x000000078a340000, 0x000000078a340000, 0x00000007909a0000)
to space 104832K, 0% used [0x00000007909a0000, 0x00000007909a0000, 0x0000000797000000)
concurrent mark-sweep generation total 1560576K, used 475795K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
}
|
- 在 CMS 启动过程中,新生代提升速度过快,老年代收集速度赶不上新生代提升速度
- 在 CMS 启动过程中,老年代碎片化严重,无法容纳新生代提升上来的大对象
- 新生代提升过快问题:(1)如果频率太快的话,说明空间不足,首先可以尝试调大新生代空间和晋升阈值。(2)如果内存有限,可以设置 CMS 垃圾收集在老年代占比达到多少时启动来减少问题发生频率(越早启动问题发生频率越低,但是会降低吞吐量,具体得多调整几次找到平衡点),参数如下:如果没有第二个参数,会随着 JVM 动态调节 CMS 启动时间
- 老年代碎片严重问题:(1)如果频率太快或者 Full GC 后空间释放不多的话,说明空间不足,首先可以尝试调大老年代空间(2)如果内存不足,可以设置进行 n 次 CMS 后进行一次压缩式 Full GC,参数如下:
二. 提升失败(promotion failed)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
|
2016-01-07T18:54:26.948+0800: 18782.967: [GC2016-04-07T18:54:26.948+0800: 18782.967: [ParNew (promotion failed)
Desired survivor size 117833728 bytes, new threshold 10 (max 10)
- age 1: 6141680 bytes, 6141680 total
- age 2: 6337936 bytes, 12479616 total
- age 3: 549120 bytes, 13028736 total
- age 4: 87768 bytes, 13116504 total
- age 5: 221384 bytes, 13337888 total
- age 6: 934168 bytes, 14272056 total
- age 7: 146072 bytes, 14418128 total
- age 8: 626064 bytes, 15044192 total
- age 9: 398000 bytes, 15442192 total
- age 10: 429616 bytes, 15871808 total
: 1969227K->1929200K(2071808K), 0.7452140 secs]2016-01-07T18:54:27.693+0800: 18783.713: [CMS: 1394703K->632845K(2097152K), 4.0993640 secs] 3301676K->632845K(4168960K), [CMS Perm : 77485K->77473K(159744K)], 4.8450240 secs] [Times: user=5.18 sys=0.56, real=4.84 secs]
Heap after GC invocations=5847 (full 7):
par new generation total 2071808K, used 0K [0x00000006e9c00000, 0x0000000776400000, 0x0000000776400000)
eden space 1841664K, 0% used [0x00000006e9c00000, 0x00000006e9c00000, 0x000000075a280000)
from space 230144K, 0% used [0x0000000768340000, 0x0000000768340000, 0x0000000776400000)
to space 230144K, 0% used [0x000000075a280000, 0x000000075a280000, 0x0000000768340000)
concurrent mark-sweep generation total 2097152K, used 632845K [0x0000000776400000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 77473K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
}
|
- 新生代提升太快
- 老年代碎片太多,放不下大对象提升(表现为老年代还有很多空间但是,出现了 promotion failed)
三. 在 GC 的时候其他系统活动影响
1
2
3
4
5
6
7
8
|
{Heap before GC invocations=132 (full 0):
par new generation total 2696384K, used 2696384K [0xfffffffc20010000, 0xfffffffce0010000, 0xfffffffce0010000)
eden space 2247040K, 100% used [0xfffffffc20010000, 0xfffffffca9270000, 0xfffffffca9270000)
from space 449344K, 100% used [0xfffffffca9270000, 0xfffffffcc4940000, 0xfffffffcc4940000)
to space 449344K, 0% used [0xfffffffcc4940000, 0xfffffffcc4940000, 0xfffffffce0010000)
concurrent mark-sweep generation total 9437184K, used 1860619K [0xfffffffce0010000, 0xffffffff20010000, 0xffffffff20010000)
concurrent-mark-sweep perm gen total 1310720K, used 511451K [0xffffffff20010000, 0xffffffff70010000, 0xffffffff70010000)
2013-07-17T03:58:06.601-0700: 51522.120: [GC Before GC: : 2696384K->449344K(2696384K), 29.4779282 secs] 4557003K->2326821K(12133568K) ,29.4795222 secs] [Times: user=915.56 sys=6.35, real=29.48 secs]
|
四. JVM 的 bug
五. 总结
- 详细的 GC 日志
- 借助 Linux 平台下的 iostat、vmstat、netstat、mpstat 等命令监控系统情况
- 使用 GCHisto 这个 GC 图形用户界面工具,可以统计出 Minor GC 及 Full GC 频率及时长分布,可参考:http://blog.csdn.net/wenniuwuren/article/details/50760259
- 查看 GC 日志中是否出现了上述的典型内存异常问题(promotion failed, concurrent mode failure),整体来说把上述两个典型内存异常情况控制在可接受的发生频率即可,对 CMS 碎片问题来说杜绝以上问题似乎不太可能,只能靠 G1 来解决了
- 是不是 JVM 本身的 bug 导致的
- 如果程序没问题,参数调了几次还是不能解决,可能说明流量太大,需要加机器把压力分散到更多 JVM 上
六. 参考资料
JVM 调优 —— GC 长时间停顿问题及解决方法相关推荐
- 后台IO高负载造成JVM GC长时间停顿
在我们的生产环境中,我们已经多次看到在JVM (Java虚拟机)中运行的应用程序偶尔会遇到很大的STW (Stop-The-World)应用程序暂停,原因是JVM的GC日志被后台IO通信阻塞(例如,O ...
- JVM调优-GC参数
一.Throughput收集器(吞吐量) -XX:+UseParallelGC -XX:+UseParallelOldGC *参数调整:通过调整堆大小,减少GC停顿时间,增大吞吐量 增强堆大小可以减少 ...
- 几张图可以理解GC JVM调优的内容
public class ApiPurchaseOrderServiceApp {public static void main(String[] args) throws Exception {Ap ...
- JVM从入门到精通(七):GC常用参数,Method Area,JVM调优案例分析
GC常用参数 -Xmn -Xms -Xmx -Xss 年轻代 最小堆 最大堆 栈空间 -XX:+UseTLAB 使用TLAB,默认打开 -XX:+PrintTLAB 打印TLAB的使用情况 -XX:T ...
- java jvm调优_(第2部分,共3部分):有关性能调优,Java中的JVM,GC,Mechanical Sympathy等的文章和视频的摘要...
java jvm调优 这是以前的文章(第3部分,共1部分)的继续:有关性能调优,Java中的JVM,GC,Mechanical Sympathy等的文章和视频的提要 . 事不宜迟,让我们开始使用我们的 ...
- JVM 调优 2:GC 如何判断对象是否为垃圾,三色标记算法应用原理及存在的问题?
文章目录 前言 一.如何判断一个对象是否为垃圾? 1.1.reference count(引用计数) 1.2.reference count(引用计数)存在的问题 二.Root Searching(根 ...
- java gc调优常用参数_常用JVM调优参数
JVM调优有许多参数优化,下面整理了一些我自己能够理解的参数 -XX:AutoBoxCacheMax -XX:+AlwaysPreTouch CMSInitiatingOccupancyFractio ...
- 数据结构与算法+JVM调优和GC常用算法+数据库高级+复杂sql手写
数据结构 双向链表 二叉排序树 红黑树 散列表 双向链表: 什么是双向链表 双向链表是一种数据结构,是由若干个节点构成,每个节点由三部分构成, 分别是前驱节点,元素,后继节点,且双向链表中的节点在内存 ...
- java知识点8——垃圾回收原理和算法、通用的分代垃圾回收机制、 JVM调优和Full GC、开发中容易造成内存泄露的操作
垃圾回收原理和算法 内存管理 Java的内存管理很大程度指的就是对象的管理,其中包括对象空间的分配和释放. 对象空间的分配:使用new关键字创建对象即可 对象空间的释放:将对象赋值null即可 垃圾回 ...
最新文章
- Aliyun Java Initializr 和 Spring 官方的到底有什么区别?
- 【Python教程】用字典推导式将cookie字符串转化为字典的方法
- wxWidgets:exec 示例演示 wxExecute 和相关函数
- php跨域单点登录,SSO单点登录、跨域重定向、跨域设置Cookie、京东单点登录实例分析...
- zabbix安装与使用
- “穿透”与“征兆”:长篇小说《环形女人》(一)
- 小甲鱼python课后题007_[Python]小甲鱼Python视频第007-008课(了不起的分支和循环)课后题及参考解答...
- 汇博工业机器人码垛机怎么写_全自动码垛机器人在企业生产中的地位越来越重要...
- UOJ#450. 【集训队作业2018】复读机 排列组合 生成函数 单位根反演
- 如何评价一个RPC框架的性能
- 学习算法收敛条件的判断
- pta平台用c语言编程答案,C语言PTA平台习题与答案
- 星岚技术 Win7 x64 纯净版 V2021.4【带驱动包】
- 基于ADS软件的Verilog-A建模
- 设计参考之不凡的日本LOGO
- c语言打开文件报错 13,求帮忙看一段打开文件的代码~~真心无力了
- 架构师之路---面向过程和面向对象 王泽宾
- 【新示例】协作云路上的先驱or先烈,思科、TCL合资的科天云这样思考
- 小程序源码:2022虎年春节拜年祝福语-多玩法安装简单
- 360路由器v2刷第三方固件_己亥年网件R6220路由器刷openwrt固件的方法(亲测可用)...