调整GC(CMS)的参数

Junjie

我将CMS用于GC,但是每两个月后CPU使用率会很高。

当情况变得更糟时,会有一条GC日志,您可能会发现很长的STW。

3519696.386: [GC [1 CMS-initial-mark: 8617524K(12582912K)] 17105967K(23907584K), 4.9369140 secs] [Times: user=4.94 sys=0.00, real=4.94 secs]
3519701.324: [CMS-concurrent-mark-start]
3519709.419: [CMS-concurrent-mark: 8.096/8.096 secs] [Times: user=16.17 sys=0.00, real=8.09 secs]
3519709.420: [CMS-concurrent-preclean-start]
3519709.442: [CMS-concurrent-preclean: 0.023/0.023 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
3519709.442: [CMS-concurrent-abortable-preclean-start]
 CMS: abort preclean due to time 3519714.691: [CMS-concurrent-abortable-preclean: 3.345/5.248 secs] [Times: user=3.36 sys=0.00, real=5.25 secs]
3519714.692: [GC[YG occupancy: 8489655 K (11324672 K)]3519714.692: [Rescan (parallel) , 8.4072250 secs]3519723.099: [weak refs processing, 0.0000190 secs]3519723.099: [scrub string table, 0.0008130 secs] [1 CMS-remark: 8617524K(12582912K)] 17107180K(23907584K), 8.4081940 secs] [Times: user=65.71 sys=0.15, real=8.41 secs]
3519723.100: [CMS-concurrent-sweep-start]
3519725.451: [CMS-concurrent-sweep: 2.350/2.350 secs] [Times: user=2.36 sys=0.00, real=2.35 secs]
3519725.451: [CMS-concurrent-reset-start]
3519725.478: [CMS-concurrent-reset: 0.028/0.028 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
3519727.480: [GC [1 CMS-initial-mark: 8617522K(12582912K)] 17107229K(23907584K), 4.9378950 secs] [Times: user=4.94 sys=0.00, real=4.94 secs]
3519732.418: [CMS-concurrent-mark-start]

我的GC参数:

java -server -Xmx24g -Xms24g -XX:NewSize=12g -XX:MaxNewSize=12g -XX:+HeapDumpOnOutOfMemoryError -XX:MaxDirectMemorySize=24g -XX:+UseConcMarkSweepGC -XX:+UseCMSCompactAtFullCollection -XX:ReservedCodeCacheSize=128m  -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:CMSInitiatingOccupancyFraction=68

我的服务器上安装了9个CPU和64G内存。

您能帮忙弄清楚为什么每月变得更糟的关键点吗?

加洛·纳瓦罗(Galo Navarro)

好的,让我们详细了解一下。我首先要指出的是,所有时间似乎都是在用户中,而不是在sys中,因此主要的怀疑对象是JVM和应用程序。

GC是在老一代触发的。容量为8617524K,容量为12582912K。总堆使用量为17105967K,大小为23907584K。

初始标记大约需要5秒。

3519696.386: [GC [1 CMS-initial-mark: 8617524K(12582912K)] 17105967K(23907584K), 4.9369140 secs] [Times: user=4.94 sys=0.00, real=4.94 secs]

AFAIK初始标记仅处理GC根。您可以在这里看到这些,但是花费这么多的事实很奇怪。我的第一个怀疑是,这受到达安全点的时间的影响,因此可以启用:

-XX:+ PrintSafepointStatistics –XX:PrintSafepointStatisticsCount = 1

并发标记阶段需要8秒

3519709.419: [CMS-concurrent-mark: 8.096/8.096 secs] [Times: user=16.17 sys=0.00, real=8.09 secs]

这是扫描活动对象

预清洁相对较快。

可终止的预清除在5s时被取消,AFAIK随附的可通过CMSMaxAbortablePrecleanTime进行配置。深入研究此选项,我发现在此阶段需要较小的收集是理想的,如果不这样做,可能会导致CMS中出现较大的暂停。增加该CMSMaxAbortablePrecleanTime,并激活CMSScavengeBeforeRemark。查看Jon Masamitsu的这篇文章

年轻一代使用8G,重新扫描用时8s,这似乎太多了。再次相同的评论。安全点。

3519714.692:[GC [YG占用率:8484895 K(11324672 K)] 3519714.692:[重新扫描(并行),8.4072250秒] 3519723.099:[弱引用处理,0.0000190秒] 3519723.099:[清理字符串表,0.0008130秒] [1 CMS-备注:8617524K(12582912K)] 17107180K(23907584K),8.4081940秒] [时间:user = 65.71 sys = 0.15,real = 8.41秒]

注意年轻的一代。此期间实际增加的大小:8617524K

并发扫描的最终清理时间为2.35秒,并且堆内容似乎没有实质性变化。您仍然有大致相同的年轻和堆使用情况。

总而言之,我看到两点:

  • 您的堆很大,您到达CMSInitiatingOccupancyFraction并触发CMS,并且似乎在扫描活动对象上花费了很多时间。无论哪种方式,请检查sizepoint时间以查看是否可以改进。
  • GC收集得并不多,因此您可能处于以下情况之一:
    • 您想要保留许多长期存在的对象(例如:缓存)。在这种情况下,您想增加CMSInitiatingOccuppancyFraction(因为您希望老一代变得很满)。但也请注意,您不会宣传任何中度或短暂的对象,因为这些对象最终(一天或两个月内)最终会导致GC较长。那就是:避免老一代的搅动。
    • 您正在生成许多短寿命的对象,因此需要避免晋升。减少分配,增加伊甸园。

有关您的应用程序的更多详细信息,等等,肯定会帮助您更好地确定它。我希望能有所帮助。

本文收集自互联网,转载请注明来源。

如有侵权,请联系[email protected] 删除。

编辑于
0

我来说两句

0条评论
登录后参与评论

相关文章