3

我在我的 java 应用程序中观察到频繁的 GC，包括 Full GC，在 100 个客户端进行 Web 服务调用的情况下，它向客户端返回 21KB（压缩大小）的 JSON。未压缩的 JSON 大约为 200 KB。由于频繁的 GC，我观察到 2.6 秒的巨大延迟。这里是用于负载测试的 JVM 选项

-Xloggc:/mnt/apache-tomcat-7.0.29/logs/gc.log -XX:+UseConcMarkSweepGC -XX:+UseCompressedOops -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintTenuringDistribution -XX:+PrintTenuringDistribution -XX:+UseParNewGC -Xms5048M  -XX:MaxTenuringThreshold=2 -XX:SoftRefLRUPolicyMSPerMB=73 -Djava.net.preferIPv4Stack=true -server -XX:NewRatio=4 -XX:SurvivorRatio=8

我正在使用具有 4vCPU 和 15 MB RAM 的 AWS xLarge 实例。

以下是该过程产生的 GCl 日志

 249.988: [GC 249.988: [ParNew
2163 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2164 - age   1:   83821968 bytes,   83821968 total
2165 - age   2:   20181408 bytes,  104003376 total
2166 : 896337K->103360K(930432K), 0.0409860 secs] 4453729K->3663260K(5065792K), 0.0412220 secs] [Times: user=0.16 sys=0.00, real=0.04 secs]

2167 250.051: [GC 250.051: [ParNew
2168 Desired survivor size 52920320 bytes, new threshold 2 (max 2)
2169 - age   1:   24997144 bytes,   24997144 total

2170 : 185613K->82956K(930432K), 0.0620620 secs] 3745513K->3744426K(5065792K), 0.0622810 secs] [Times: user=0.22 sys=0.00, real=0.06 secs]

2171 250.408: [GC 250.409: [ParNew
2172 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2173 - age   1:   86010184 bytes,   86010184 total
2174 - age   2:   19119656 bytes,  105129840 total


2183 : 930432K->103360K(930432K), 0.0904080 secs] 4767408K->4080180K(5065792K), 0.0906520 secs] [Times: user=0.33 sys=0.01, real=0.09 secs]
2184 251.229: [GC 251.229: [ParNew: 215470K->215470K(930432K), 0.0000370 secs] 4192291K->4192291K(5065792K), 0.0001620 secs] [Times: user=0.00 sys=0.00, real     =0.00 secs]

2185 GC locker: Trying a full collection because scavenge failed
2186 251.229: [Full GC 251.229: [CMS251.495: [CMS-concurrent-mark: 6.443/8.877 secs] [Times: user=30.14 sys=3.55, real=8.87 secs]
2187  (concurrent mode failure): 3976820K->354739K(4135360K), 0.9792960 secs] 4192291K->354739K(5065792K), [CMS Perm : 42722K->42722K(71212K)], 0.9794580 sec     s] [Times: user=0.96 sys=0.02, real=0.98 secs]
2188 252.439: [GC 252.440: [ParNew
2189 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2190 - age   1:  105807496 bytes,  105807496 total
2191 : 837144K->103360K(930432K), 0.0562310 secs] 1191884K->474282K(5065792K), 0.0564520 secs] [Times: user=0.22 sys=0.00, real=0.05 secs]
2192 252.676: [GC 252.676: [ParNew
2193 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2194 - age   1:   95836672 bytes,   95836672 total
2195 : 924377K->103360K(930432K), 0.0772210 secs] 1295299K->575312K(5065792K), 0.0774650 secs] [Times: user=0.28 sys=0.01, real=0.08 secs]
2196 253.001: [GC 253.001: [ParNew
2197 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2198 - age   1:   99903544 bytes,   99903544 total

2199 : 930432K->103360K(930432K), 0.0712130 secs] 1405673K->680963K(5065792K), 0.0714420 secs] [Times: user=0.25 sys=0.01, real=0.07 secs]

2200 253.324: [GC 253.324: [ParNew
2201 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2202 - age   1:  105814880 bytes,  105814880 total

2203 : 930432K->103360K(930432K), 0.0736730 secs] 1513770K->807662K(5065792K), 0.0739490 secs] [Times: user=0.27 sys=0.00, real=0.08 secs]
2204 253.666: [GC 253.667: [ParNew
4

2 回答 2

3

我想知道为什么开车的人只是简单地提出这个问题而没有停下来评论他们为什么会这样做......这让我很烦恼。

关注此消息：

GC locker: Trying a full collection because scavenge failed

我找到了这个线程：

https://blogs.oracle.com/poonam/entry/understanding_cms_gc_logs

有了这些信息：

CMS 也可以在增量模式 (i-cms) 下运行，使用 -XX:+CMSIncrementalMode 启用。

您是否在 (i-cms) 模式下运行 CMS？它似乎对我有帮助，尽管我承认这不是我的专长。刚停下来帮忙。

这里将进一步讨论这个问题和可能的解决方案：

https://forums.oracle.com/thread/1543499

另外，关注消息“并发模式失败”，这是一个主要问题： 如何减少java并发模式失败和过度gc

于 2013-08-15T11:30:45.757 回答
2

让我们总结一下您的内存设置：

我想上面提到的 15 MB 是一个错字。假设您的机器的 RAM 小于 19.7 GB，选项“-Xms5048M”有效地将最小和最大堆大小设置为 5048 MB（默认最大值为机器 RAM 的 25%，因此如果您的内存大于 19.7，则最大值会更高GB 内存）。

与选项 -XX:NewRatio=4 和 -XX:SurvivorRatio=8 一起，您将得到以下内存布局：

  • 总堆大小：5048 MB；根据新的比率，这包括
    • 80%，即 4038.4 MB 终身（老一代）空间
    • 20%，即 1009.6 MB 年轻代空间；根据选择的幸存者比率，这将包括
      • 80%，即 807.68 MB Eden 空间和
      • 10%，即 101.96 MB S0 (Survivor) 空间
      • 10%，即 101.96 MB S1 (Survivor) 空间

现在让我们检查一下 JVM 从中得到了什么：

从您的日志中，您可以看到幸存者空间非常小；例如，在第 2174 行，age 1 和 2 条目的总和为 182 MB，因此远远超过了 S0/S1 大小。较低的最大年龄（1 或 2 代）也是幸存者空间太有限的标志——JVM 将减少最大年龄，因为它试图将幸存者空间利用率削减到目标值（默认为 50%）。

第 2183 行的报告行表明 136.5 MB 从young 空间提升到tenured 空间（GC 后young gen diff 为 930432 KB - 103360 KB = 827072 KB，总堆 diff 为 4767408 KB - 4080180 KB = 687228 KB，因此提升了 139844 KB ）。

在同一行 2183 上，您可以看到老一代的使用量为 4080180 KB - 103360 KB = 3976820 KB = 3883.6 MB。这仅留下 154.8 MB 的最大老一代大小。

我不了解 GC 算法触发器的细节（根据我所学到的，它们确实在 JVM 版本之间发生了变化），但考虑到

  • 上次促销的大小 (136.5 MB) 和
  • 留给下一次促销的老一代空间量 (154.8 MB)

...很明显，迫切需要 Full GC。

作为解决方案，我会尝试增加年轻一代的规模

  • 这将放松极其紧凑的 S0/S1 设置
  • 更多的物体将有机会英年早逝，因此
  • 终身职位的晋升率将降低，并且
  • 在必须触发“Full GC”紧急制动之前，CMS 并发模式有足够的时间完成。

当然，增加总堆大小也会有所帮助，进一步调整 SurvivorRatio 值可能会有所帮助；尤其是后者是高度依赖于应用程序的，如果不深入了解应用程序和 GC 算法，我不会接触它。

于 2016-02-15T14:57:02.733 回答