GC 调整 - 阻止完整 GC

performance garbage-collection java jvm

2022-09-01 19:15:34

我试图避免完整的GC（来自gc.log下面的示例）在生产环境中的Tomcat中运行Grails应用程序。关于如何更好地配置GC的任何建议？

14359.317： [完整GC 14359.317： [CMS： 3453285K->3099828K（4194304K）， 13.1778420 秒] 4506618K->3099828K（6081792K）， [CMS 彼尔姆： 261951K->181304K（264372K）] icms_dc=0 ， 13.1786310 秒] [次数：用户=13.15 系统=0.04， real=13.18 秒]

我的 VM 参数如下：
-Xms=6G
-Xmx=6G
-XX：MaxPermSize=1G
-XX：NewSize=2G
-XX：MaxTenuringThreshold=8
-XX：SurvivorRatio=7
-XX：+UseConcMarkSweepGC
-XX：+CMSClassUnloadingEnabled
-XX：+CMSPermGenSweepingEnabled
-XX：+CMSIncrementalMode
-XX：CMSInitiatingOccupancyFraction=60
-XX：+UseCMSInitiatingOccupancyOnly
-XX：+HeapDumpOnOutOfMemoryError
-XX：+PrintGCDetails
-XX：+PrintGCTimeStamps
-XX：+PrintTenuringDistribution
-Dsun.reflect.inflationThreshold=0

    14169.764: [GC 14169.764: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   15584312 bytes,   15584312 total
    - age   2:   20053704 bytes,   35638016 total
    - age   3:   13624872 bytes,   49262888 total
    - age   4:   14469608 bytes,   63732496 total
    - age   5:   10553288 bytes,   74285784 total
    - age   6:   11797648 bytes,   86083432 total
    - age   7:   12591328 bytes,   98674760 total
    : 1826161K->130133K(1887488K), 0.1726640 secs] 5216326K->3537160K(6081792K) icms_dc=0 , 0.1733010 secs] [Times: user=0.66 sys=0.03, real=0.17 secs] 
    14218.712: [GC 14218.712: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   25898512 bytes,   25898512 total
    - age   2:   10308160 bytes,   36206672 total
    - age   3:   16927792 bytes,   53134464 total
    - age   4:   13493608 bytes,   66628072 total
    - age   5:   14301832 bytes,   80929904 total
    - age   6:   10448408 bytes,   91378312 total
    - age   7:   11724056 bytes,  103102368 total
    - age   8:   12299528 bytes,  115401896 total
    : 1807957K->147911K(1887488K), 0.1664510 secs] 5214984K->3554938K(6081792K) icms_dc=0 , 0.1671290 secs] [Times: user=0.61 sys=0.00, real=0.17 secs] 
    14251.429: [GC 14251.430: [ParNew
    Desired survivor size 107347968 bytes, new threshold 7 (max 8)
    - age   1:   25749296 bytes,   25749296 total
    - age   2:   20111888 bytes,   45861184 total
    - age   3:    7580776 bytes,   53441960 total
    - age   4:   16819072 bytes,   70261032 total
    - age   5:   13209968 bytes,   83471000 total
    - age   6:   14088856 bytes,   97559856 total
    - age   7:   10371160 bytes,  107931016 total
    - age   8:   11426712 bytes,  119357728 total
    : 1825735K->155304K(1887488K), 0.1888880 secs] 5232762K->3574222K(6081792K) icms_dc=0 , 0.1895340 secs] [Times: user=0.74 sys=0.06, real=0.19 secs] 
    14291.342: [GC 14291.343: [ParNew
    Desired survivor size 107347968 bytes, new threshold 7 (max 8)
    - age   1:   25786480 bytes,   25786480 total
    - age   2:   21991848 bytes,   47778328 total
    - age   3:   16650000 bytes,   64428328 total
    - age   4:    7387368 bytes,   71815696 total
    - age   5:   16777584 bytes,   88593280 total
    - age   6:   13098856 bytes,  101692136 total
    - age   7:   14029704 bytes,  115721840 total
    : 1833128K->151603K(1887488K), 0.1941170 secs] 5252046K->3591384K(6081792K) icms_dc=0 , 0.1947390 secs] [Times: user=0.82 sys=0.04, real=0.20 secs] 
    14334.142: [GC 14334.143: [ParNew
    Desired survivor size 107347968 bytes, new threshold 6 (max 8)
    - age   1:   31541800 bytes,   31541800 total
    - age   2:   20826888 bytes,   52368688 total
    - age   3:   19155264 bytes,   71523952 total
    - age   4:   16422240 bytes,   87946192 total
    - age   5:    7235616 bytes,   95181808 total
    - age   6:   16549000 bytes,  111730808 total
    - age   7:   13026064 bytes,  124756872 total
    : 1829427K->167467K(1887488K), 0.1890190 secs] 5269208K->3620753K(6081792K) icms_dc=0 , 0.1896630 secs] [Times: user=0.80 sys=0.03, real=0.19 secs] 
    14359.317: [Full GC 14359.317: [CMS: 3453285K->3099828K(4194304K), 13.1778420 secs] 4506618K->3099828K(6081792K), [CMS Perm : 261951K->181304K(264372K)] icms_dc=0 , 13.1786310 secs] [Times: user=13.15 sys=0.04, real=13.18 secs]
    14373.287: [GC [1 CMS-initial-mark: 3099828K(4194304K)] 3100094K(6081792K), 0.0107380 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
    14373.298: [CMS-concurrent-mark-start]
    14472.579: [GC 14472.579: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   42849392 bytes,   42849392 total
    : 1677824K->86719K(1887488K), 0.1056680 secs] 4777652K->3186547K(6081792K) icms_dc=0 , 0.1063280 secs] [Times: user=0.61 sys=0.00, real=0.11 secs] 
    14506.980: [GC 14506.980: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   42002904 bytes,   42002904 total
    - age   2:   35733928 bytes,   77736832 total
    : 1764543K->96136K(1887488K), 0.0982790 secs] 4864371K->3195964K(6081792K) icms_dc=0 , 0.0988960 secs] [Times: user=0.53 sys=0.01, real=0.10 secs] 
    14544.285: [GC 14544.286: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   26159736 bytes,   26159736 total
    - age   2:   37842840 bytes,   64002576 total
    - age   3:   33192784 bytes,   97195360 total
    : 1773960K->130799K(1887488K), 0.1208590 secs] 4873788K->3230628K(6081792K) icms_dc=0 , 0.1215900 secs] [Times: user=0.59 sys=0.02, real=0.13 secs] 
    14589.266: [GC 14589.266: [ParNew
    Desired survivor size 107347968 bytes, new threshold 4 (max 8)
    - age   1:   28010360 bytes,   28010360 total
    - age   2:   21136704 bytes,   49147064 total
    - age   3:   35081376 bytes,   84228440 total
    - age   4:   32468056 bytes,  116696496 total
    : 1808623K->148284K(1887488K), 0.1423150 secs] 4908452K->3248112K(6081792K) icms_dc=0 , 0.1429440 secs] [Times: user=0.70 sys=0.02, real=0.14 secs] 
    14630.947: [GC 14630.947: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   28248240 bytes,   28248240 total
    - age   2:   20712320 bytes,   48960560 total
    - age   3:   18217168 bytes,   67177728 total
    - age   4:   34834832 bytes,  102012560 total
    : 1826108K->140347K(1887488K), 0.1784680 secs] 4925936K->3275469K(6081792K) icms_dc=0 , 0.1790920 secs] [Times: user=0.98 sys=0.03, real=0.18 secs] 
    14664.779: [GC 14664.779: [ParNew
    Desired survivor size 107347968 bytes, new threshold 5 (max 8)
    - age   1:   25841000 bytes,   25841000 total
    - age   2:   22264960 bytes,   48105960 total
    - age   3:   17730104 bytes,   65836064 total
    - age   4:   17988048 bytes,   83824112 total
    - age   5:   34739384 bytes,  118563496 total
    : 1818171K->147603K(1887488K), 0.1714160 secs] 4953293K->3282725K(6081792K) icms_dc=0 , 0.1720530 secs] [Times: user=0.82 sys=0.11, real=0.17 secs] 
    14702.488: [GC 14702.489: [ParNew
    Desired survivor size 107347968 bytes, new threshold 8 (max 8)
    - age   1:   26887368 bytes,   26887368 total
    - age   2:   21403352 bytes,   48290720 total
    - age   3:   18732224 bytes,   67022944 total
    - age   4:   17640576 bytes,   84663520 total
    - age   5:   17942952 bytes,  102606472 total
    : 1825427K->142695K(1887488K), 0.2118320 secs] 4960549K->3312168K(6081792K) icms_dc=0 , 0.2124630 secs] [Times: user=1.13 sys=0.14, real=0.21 secs]

我的目标策略是：我想将“永久”限制在最低限度，我正在处理请求，并期望超过一定数量的共享对象，所有其他对象仅对手头的请求有用。因此，通过使用一个大的NewSize和一个增加的TenuringThreshold，并希望这些单一的服务对象都不会留下来。

以下是支持我的策略：
-Xms=6G
-Xmx=6G
-XX：NewSize=2G // 大空间，这样 ParNew 就不会经常出现，并让对象过期
的时间 -XX：MaxTenuringThreshold=8 // 限制更多的
保留 -XX：SurvivorRatio=7 // 基于示例 -XX：CMSInitiatingOccupancyFraction=60
// 防止由升级分配失败导致的完整 GC 失败
-XX：+UseCMSInitiatingOccupancyOnly
// 根据示例与上面的那个一起使用

MaxPermSize=1G和“-Dsun.reflect.inflationThreshold=0”与另一个问题有关，我宁愿分开。

“-XX：+CMSClassUnloadIngEnabled”和“-XX：+CMSPermGenSweepingEnabled”之所以存在，是因为圣杯严重依赖和额外的类进行闭包和反射

-XX：+CMS增量模式是一个没有取得多大成功的实验

答案 1

发布的日志片段显示，您有大量对象的存活时间为 >320s（每个年轻集合大约 40 个，对象在升级前存活了 8 个集合）。然后，剩余的对象渗入永久状态，最终您遇到了一个明显出乎意料的完整gc，它实际上并没有收集太多。

3453285K->3099828K(4194304K)

也就是说，你有一个4G的终身制，当它被触发时，它是~82%的满载（3453285/4194304），并且在13个长秒后~74%的满载。

这意味着收集~350M的总和需要13s，这在6G堆的背景下并不多。

这基本上意味着您的堆不够大，或者更有可能的是，您有内存泄漏。像这样的泄漏对于CMS来说是一件可怕的事情，因为并发的终身制集合是一个非压缩事件，这意味着终身制是免费列表的集合，这意味着碎片对于CMS来说可能是一个大问题，这意味着您对终身制的使用变得越来越低效，这意味着升级失败事件的可能性增加（尽管如果这是这样的事件，那么我希望看到日志消息说），因为它想要提升（或认为它需要提升）X MB到终身制，但它没有（连续的）免费列表>= X MB可用。这将触发意外的定期收集，该集合是非远程并发 STW 事件。如果你实际上没有什么可收集的（就像你一样），那么你坐着摆弄你的拇指也就不足为奇了。

一些一般性的指针，在很大程度上重申了弗拉基米尔·西特尼托夫所说的话......

在多核机器上使用iCMS是没有意义的（除非你有很多JVM或其他进程在该盒子上运行，使得JVM确实缺乏CPU），因此删除此开关
你的年轻收藏是不必要的长，因为在每个收藏的幸存者空间之间复制相对大量的内存的影响，150-200ms是一个非常庞大的收藏ParNew
- 年轻一代问题的正确答案取决于分配行为的真正含义（例如，也许你最好尽早保持并减少碎片化对终身收藏的影响，或者也许你最好拥有一个更大的新一代，并减少年轻一代收藏的频率，这样就会有更少的对象被提升，以便对终身收藏的出血最少）。

一些问题...

它最终会变成OoM还是会恢复？
在此日志片段期间，应用程序是否处于稳定状态（在启动后很长一段时间内受一致负载的影响）还是处于压力之下？

答案 2

我正在处理请求，并期望除了一定数量的共享对象之外，所有其他对象仅对手头的请求有用。这是理论，但任何类型的缓存都可以很容易地使该假设无效，并创建超出请求的对象。

正如其他人所指出的那样，无论是你们庞大的年轻一代，还是延长的紧张关系似乎都不起作用。

您应该分析应用程序并分析对象的年龄分布。我很确定Grails缓存了超出请求范围的各种内容，这就是泄漏到旧一代的内容。

你本质上试图牺牲年轻一代的暂停时间（对于2GB的年轻一代）来推迟不可避免的 - 一个6GB的旧一代集合。这并不是你在那里做的一个很好的权衡。

相反，您可能应该瞄准更好的年轻一代暂停时间，并允许CMS消耗更多的CPU时间：更多的conrrent phase GC线程（不记得那个选项），更高的，>来承担次要集合的压力并允许它们满足暂停目标，而不必调整大小以适应主要集合限制。GCTimeRatioMaxGCPauseMillisMaxGCMinorPauseMillis

为了使主要的GC不那么痛苦，你可能想读一下：http://blog.ragozin.info/2012/03/secret-hotspot-option-improving-gc.html（这个补丁应该在j7u4中）。也应该启用，不确定这是否是默认值。CMSParallelRemarkEnabled

替代方案：使用 G1GC

就我个人而言，由于一些非常大的类似LRU的工作负载，G1GC在角落里工作，然后回落到一个大型的，停止世界的集合，比CMS在相同工作负载上经历的并发模式故障的频率要高得多。

但对于其他工作负载（如您的工作负载），它实际上可能会完成工作并逐步收集旧一代，同时还可以压缩，从而避免任何大的停顿。

如果您还没有尝试过，请尝试一下。同样，在你这样做之前，更新到最新的java7，G1仍然有一些他们试图解决的启发式问题。

编辑：自从我写这个答案以来，Oracle已经改进了G1GC的启发式方法和一些瓶颈。它现在绝对值得一试。

另一种选择：吞吐量收集器

由于您已经为2GB的年轻一代使用了并行收集器，并且获得了200ms的暂停时间......为什么不尝试在您的6G堆上并行的旧一代收集器？它可能需要比您在CMS上看到的10多个主要集合更少的时间。每当 CMS 遇到其故障模式之一时，它就会执行单线程、停止世界收集。