本节确定您可能在GC日志中发现的常见问题以及如何解决这些问题。您还可以使用通用GC日志分析器来分析GC日志。
- Young generation - 太小
以下日志片段显示了年轻一代堆大小太小的问题:
1.813: [GC1.813: [ParNew: 1152K>128K(1152K), 0.0008100 secs] 16620K->15756K(26936K), 0.0008350 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
1.816: [GC1.816: [ParNew: 1152K>128K(1152K), 0.0006430 secs] 16780K->15913K(26936K), 0.0006640 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
1.819: [GC1.819: [ParNew: 1152K>128K(1152K), 0.0005370 secs] 16937K->16038K(26936K), 0.0005570 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
可以看到,一秒钟内发生多个GC。这意味着需要增加年轻代的大小(NewSize和MaxNewSize),并且可能还需要增加堆的总大小来补偿此更改(Xms和Xmx)。或者,可以更改NewRatio选项(默认情况下,该选项设置为2,这意味着长期生成堆的大小是年轻生成堆的两倍,或者年轻生成堆的大小是长期生成堆的1/3)。
- 年轻代-太大/年老代-太小
下面的日志片段显示了一个问题,即年轻代堆大小过大,因此年老代堆大小过小:
276.716: [GC (CMS Initial Mark) [1 CMS-initial-mark: 104176K(135168K)] 2758985K(6741248K), 0.8762860 secs] [Times: user=0.88 sys=0.00, real=0.88 secs]
277.592: [CMS-concurrent-mark-start]
277.657: [CMS-concurrent-mark: 0.063/0.065 secs] [Times: user=0.12 sys=0.00, real=0.06 secs]
277.657: [CMS-concurrent-preclean-start]
277.658: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
277.658: [CMS-concurrent-abortable-preclean-start]
277.658: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
277.658: [GC (CMS Final Remark)[YG occupancy: 2657419 K (6606080 K)]277.658: [Rescan (parallel) , 0.9815460 secs]278.639: [weak refs processing, 0.0000320 secs]278.640: [scrub string table, 0.0011700 secs] [1 CMS-remark: 104176K(135168K)] 2761595K(6741248K), 0.9828250 secs] [Times: user=7.18 sys=0.09, real=0.99 secs]
278.641: [CMS-concurrent-sweep-start]
278.668: [CMS-concurrent-sweep: 0.026/0.027 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
278.668: [CMS-concurrent-reset-start]
278.668: [CMS-concurrent-reset: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
280.673: [GC (CMS Initial Mark) [1 CMS-initial-mark: 104079K(135168K)] 2774091K(6741248K), 0.9033730 secs] [Times: user=0.90 sys=0.00, real=0.90 secs]
281.577: [CMS-concurrent-mark-start]
281.640: [CMS-concurrent-mark: 0.063/0.063 secs] [Times: user=0.13 sys=0.00, real=0.07 secs]
281.640: [CMS-concurrent-preclean-start]
281.641: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
281.641: [CMS-concurrent-abortable-preclean-start]
281.641: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
281.641: [GC (CMS Final Remark)[YG occupancy: 2670011 K (6606080 K)]281.641: [Rescan (parallel) , 0.9914290 secs]282.633: [weak refs processing, 0.0000110 secs]282.633: [scrub string table, 0.0008100 secs] [1 CMS-remark: 104079K(135168K)] 2774091K(6741248K), 0.9923100 secs] [Times: user=7.14 sys=0.11, real=0.99 secs]
282.634: [CMS-concurrent-sweep-start]
282.659: [CMS-concurrent-sweep: 0.024/0.025 secs] [Times: user=0.06 sys=0.01, real=0.02 secs]
282.659: [CMS-concurrent-reset-start]
282.659: [CMS-concurrent-reset: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
可以看到,CMS回收出现的频率太高,中间没有任何ParNew 的回收。这是因为年轻代的堆大小太大,所以每次发生ParNew 回收时,年老代堆大小立即变满,CMS回收开始运行。如果在不增加堆的总大小的情况下增加年轻代堆的大小,就会发生这种情况。如果内存泄漏,也可能发生此日志片段。
- CMS failure
如下日志片段展示了一个 CMS failure (concurrent mode failure):
(concurrent mode failure): 1551948K->1548050K(1572864K), 15.1154540 secs] 1986510K->1548050K(2044736K), [CMS Perm : 78597K->78588K(524288K)], 15.4406700 secs] [Times: user=15.52 sys=0.00, real=15.44 secs]
703240.983: [GC [1 CMS-initial-mark: 1548050K(1572864K)] 1561545K(2044736K), 0.0059690 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
此错误意味着CMS收集器无法跟上生成的垃圾量(老年代堆空间已满约90%),GCs占用的时间更长,这意味着应用程序停止的时间更长。此示例显示应用程序停止超过15秒,这将对性能产生重大影响。
可以添加如下GC参数避免CMS failure:
-XX:CMSInitiatingOccupancyFraction=n
-XX:+UseCMSInitiatingOccupancyOnly
应该将-XX:CMSInitiatingOccupancyFraction设置为70或80%(而不是默认值~90%),这样可以使CMS收集器跟上正在生成的垃圾量。
- Full GC
如下日志片段展示了一个 Full GC:
25.466: [Full GC )25.466: [CMS: 68756K>75361K(1987392K), 0.2548820 secs] 96571K->75361K(2064064K), [CMS Perm : 61069K>60722K(61376K)], 0.2551850 secs] [Times: user=0.25 sys=0.01, real=0.25 secs]
26.185: [Full GC (System.gc())26.185: [CMS: 75361K>73283K(1987392K), 0.2398450 secs] 76136K->73283K(2064064K), [CMS Perm : 60723K>60723K(101204K)], 0.2400120 secs] [Times: user=0.24 sys=0.00, real=0.24 secs]
27.293: [Full GC (System.gc())27.293: [CMS: 73283K>73291K(1987392K), 0.2111960 secs] 74096K>73291K(2064064K), [CMS Perm : 60723K>60723K(101396K)], 0.2112730 secs] [Times: user=0.21 sys=0.00, real=0.22 secs]
68.081: [Full GC (Heap Inspection Initiated GC)68.081: [CMS: 73291K->73187K(1987392K), 0.2172670 secs] 77634K>73187K(2064064K), [CMS Perm : 60742K>60742K(101396K)], 0.2174520 secs] [Times: user=0.22 sys=0.00, real=0.21 secs]
这些日志片段指的是发生的完整gc,这意味着整个堆正在被清除(年轻代和年老代);这通常是由于诸如RMI之类的系统进程造成的,RMI每小时都会执行一次完整的GC。PrintGCCause选项非常有用,可以帮助找出GC发生的原因(上面日志中的最后三行显示了该选项输出的附加信息,明确了哪些信息与系统相关)。还可以设置DisableExplicitGC选项以防止发生与系统相关的完整GCs。
堆优化准则
尽管我们不能给出建议的堆设置,因为它们在环境和应用程序之间有很大的差异,但在进行优化时,您应该遵循以下指导原则:
您应该始终使用支持的最新软件版本。
您应该按照ForgeRock的建议使用cmsgc。
-
堆的总大小不能超过可用的物理RAM的数量。
-
您必须留下一些物理RAM,以便其他应用程序在您的计算机上运行。
-
您应该将Xms和Xmx设置为相同的值以获得最佳性能。这些选项决定了堆的总大小。
-
您应该将NewSize和MaxNewSize设置为相同的值。这些选项决定如何在代之间分配堆。
-
您应该设置DisableExplicitGC选项以防止与系统相关的完整GCs运行。
-
你不能一次添加很多选项或者添加你不理解的选项。
-
不能从其他应用程序复制和粘贴选项。
-
您应该使用GC日志来帮助识别调优中的问题。
总结 -
收集器,应该是CMS。
-
总堆大小,其中Xmx=Xms。
-
使用NewSize或NewRatio,其中NewSize=MaxNewSize,在代之间进行拆分。
翻译自:https://backstage.forgerock.com/knowledge/kb/article/a35746010