我有一个 Java 进程分配了很多非常短暂的对象(使用 YourKit 测量平均年龄在 10-20 毫秒之间),并且很少有持久的对象,它的功能是接受 TCP 消息,以某种方式对其进行转换,并生成到 Kafka。
大部分对象是由用 Scala 编写的 Kafka 生产者创建的,因此使用了大量不可变对象(immutable对象)。再次使用 YourKit,我测得来自 Kafka 的不可变对象(immutable对象)的大小约为总数的 75%,而来自 Kafka 的对象数量约为总数的 53%。这些对象中的绝大多数不会超过 20 毫秒。
为了针对此用例优化我的应用程序,我尝试调整垃圾收集器,使其将短期对象识别为常见用例,并在到达旧代之前丢弃大部分对象。以下是我到目前为止使用的旋钮:
-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps \
-XX:+PrintHeapAtGC -XX:+DisableExplicitGC -XX:+PrintTenuringDistribution \
-XX:+UseParallelOldGC -XX:NewRatio=1 \
最重要的标志是 -XX:NewRatio
和 -XX:UseParallelOldGC
但我注意到 GC 模式中有一些奇怪的行为。
如您所见,在第一次完整 GC 之前,tenuring 发生得非常缓慢(我也使用每次 gc 后打印的堆信息证实了这一点),但在第一次 full GC 之后,tenuring 开始非常快。
我不明白这样做的原因,我发现 full GC 完全没有必要 - full GC 导致几乎整个堆都被回收,因为绝大多数对象已经失去了它们的强引用。
如果在每次 GC 后包含堆信息会有所帮助,我会这样做,但就目前而言,这应该是足够的信息。
如果有人知道为什么会发生这种情况,请告诉我。对于这样的应用程序,每小时一次完整的 GC 似乎太频繁了。
编辑:
根据要求,这里有一些额外的信息:
- 我使用的是 Java 7,版本 1.7.0_51。
- 我已经为这个进程分配了 1 GB 的内存,并且堆已经固定在这个大小。
- 在第一次完整 GC 之前来自次要 GC 的一些堆输出:
{Heap before GC invocations=395 (full 0): PSYoungGen total 521728K, used 519744K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 518656K, 100% used [0x00000000e0000000,0x00000000ffa80000,0x00000000ffa80000) from space 3072K, 35% used [0x00000000ffd00000,0x00000000ffe10000,0x0000000100000000) to space 2560K, 0% used [0x00000000ffa80000,0x00000000ffa80000,0x00000000ffd00000) ParOldGen total 524288K, used 177521K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 33% used [0x00000000c0000000,0x00000000cad5c560,0x00000000e0000000) PSPermGen total 33280K, used 33132K [0x00000000bae00000, 0x00000000bce80000, 0x00000000c0000000) object space 33280K, 99% used [0x00000000bae00000,0x00000000bce5b3d0,0x00000000bce80000) 35744.334: [GC Desired survivor size 2621440 bytes, new threshold 1 (max 15) [PSYoungGen: 519744K->1184K(521216K)] 697265K->179113K(1045504K), 0.0039310 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] Heap after GC invocations=395 (full 0): PSYoungGen total 521216K, used 1184K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 518656K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000ffa80000) from space 2560K, 46% used [0x00000000ffa80000,0x00000000ffba8000,0x00000000ffd00000) to space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000) ParOldGen total 524288K, used 177929K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 33% used [0x00000000c0000000,0x00000000cadc2560,0x00000000e0000000) PSPermGen total 33280K, used 33132K [0x00000000bae00000, 0x00000000bce80000, 0x00000000c0000000) object space 33280K, 99% used [0x00000000bae00000,0x00000000bce5b3d0,0x00000000bce80000) }
- 第一次Full GC的堆输出:
{Heap before GC invocations=1457 (full 0): PSYoungGen total 521728K, used 520064K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 519168K, 100% used [0x00000000e0000000,0x00000000ffb00000,0x00000000ffb00000) from space 2560K, 35% used [0x00000000ffd80000,0x00000000ffe60000,0x0000000100000000) to space 2560K, 0% used [0x00000000ffb00000,0x00000000ffb00000,0x00000000ffd80000) ParOldGen total 524288K, used 523194K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 99% used [0x00000000c0000000,0x00000000dfeeea68,0x00000000e0000000) PSPermGen total 34304K, used 34213K [0x00000000bae00000, 0x00000000bcf80000, 0x00000000c0000000) object space 34304K, 99% used [0x00000000bae00000,0x00000000bcf695e8,0x00000000bcf80000) 99997.829: [GC Desired survivor size 2621440 bytes, new threshold 1 (max 15) [PSYoungGen: 520064K->1600K(521728K)] 1043258K->525386K(1046016K), 0.0072540 secs] [Times: user=0.04 sys=0.01, real=0.01 secs] Heap after GC invocations=1457 (full 0): PSYoungGen total 521728K, used 1600K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 519168K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000ffb00000) from space 2560K, 62% used [0x00000000ffb00000,0x00000000ffc90000,0x00000000ffd80000) to space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000) ParOldGen total 524288K, used 523786K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 99% used [0x00000000c0000000,0x00000000dff82a68,0x00000000e0000000) PSPermGen total 34304K, used 34213K [0x00000000bae00000, 0x00000000bcf80000, 0x00000000c0000000) object space 34304K, 99% used [0x00000000bae00000,0x00000000bcf695e8,0x00000000bcf80000) } {Heap before GC invocations=1458 (full 1): PSYoungGen total 521728K, used 1600K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 519168K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000ffb00000) from space 2560K, 62% used [0x00000000ffb00000,0x00000000ffc90000,0x00000000ffd80000) to space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000) ParOldGen total 524288K, used 523786K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 99% used [0x00000000c0000000,0x00000000dff82a68,0x00000000e0000000) PSPermGen total 34304K, used 34213K [0x00000000bae00000, 0x00000000bcf80000, 0x00000000c0000000) object space 34304K, 99% used [0x00000000bae00000,0x00000000bcf695e8,0x00000000bcf80000) 99997.837: [Full GC [PSYoungGen: 1600K->0K(521728K)] [ParOldGen: 523786K->17123K(524288K)] 525386K->17123K(1046016K) [PSPermGen: 34213K->33877K(68096K)], 0.1576350 secs] [Times: user=0.53 sys=0.03, real=0.16 secs] Heap after GC invocations=1458 (full 1): PSYoungGen total 521728K, used 0K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 519168K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000ffb00000) from space 2560K, 0% used [0x00000000ffb00000,0x00000000ffb00000,0x00000000ffd80000) to space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000) ParOldGen total 524288K, used 17123K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 3% used [0x00000000c0000000,0x00000000c10b8fc8,0x00000000e0000000) PSPermGen total 68096K, used 33877K [0x00000000bae00000, 0x00000000bf080000, 0x00000000c0000000) object space 68096K, 49% used [0x00000000bae00000,0x00000000bcf156f0,0x00000000bf080000) }
- 第一次 Full GC 发生后 minor collection 的堆输出:
{Heap before GC invocations=1837 (full 9): PSYoungGen total 509440K, used 507104K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 494592K, 100% used [0x00000000e0000000,0x00000000fe300000,0x00000000fe300000) from space 14848K, 84% used [0x00000000fe300000,0x00000000fef38000,0x00000000ff180000) to space 14848K, 0% used [0x00000000ff180000,0x00000000ff180000,0x0000000100000000) ParOldGen total 524288K, used 342941K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 65% used [0x00000000c0000000,0x00000000d4ee7520,0x00000000e0000000) PSPermGen total 54272K, used 33876K [0x00000000bae00000, 0x00000000be300000, 0x00000000c0000000) object space 54272K, 62% used [0x00000000bae00000,0x00000000bcf15378,0x00000000be300000) 133247.303: [GC Desired survivor size 15204352 bytes, new threshold 1 (max 15) [PSYoungGen: 507104K->13696K(509440K)] 850045K->369421K(1033728K), 0.0318090 secs] [Times: user=0.37 sys=0.01, real=0.03 secs] Heap after GC invocations=1837 (full 9): PSYoungGen total 509440K, used 13696K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 494592K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000fe300000) from space 14848K, 92% used [0x00000000ff180000,0x00000000ffee0000,0x0000000100000000) to space 14848K, 0% used [0x00000000fe300000,0x00000000fe300000,0x00000000ff180000) ParOldGen total 524288K, used 355725K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 67% used [0x00000000c0000000,0x00000000d5b63520,0x00000000e0000000) PSPermGen total 54272K, used 33876K [0x00000000bae00000, 0x00000000be300000, 0x00000000c0000000) object space 54272K, 62% used [0x00000000bae00000,0x00000000bcf15378,0x00000000be300000) }
- 第一次完整 GC 后的堆输出:
{Heap before GC invocations=1457 (full 0): PSYoungGen total 521728K, used 520064K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 519168K, 100% used [0x00000000e0000000,0x00000000ffb00000,0x00000000ffb00000) from space 2560K, 35% used [0x00000000ffd80000,0x00000000ffe60000,0x0000000100000000) to space 2560K, 0% used [0x00000000ffb00000,0x00000000ffb00000,0x00000000ffd80000) ParOldGen total 524288K, used 523194K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 99% used [0x00000000c0000000,0x00000000dfeeea68,0x00000000e0000000) PSPermGen total 34304K, used 34213K [0x00000000bae00000, 0x00000000bcf80000, 0x00000000c0000000) object space 34304K, 99% used [0x00000000bae00000,0x00000000bcf695e8,0x00000000bcf80000) 99997.829: [GC Desired survivor size 2621440 bytes, new threshold 1 (max 15) [PSYoungGen: 520064K->1600K(521728K)] 1043258K->525386K(1046016K), 0.0072540 secs] [Times: user=0.04 sys=0.01, real=0.01 secs] Heap after GC invocations=1457 (full 0): PSYoungGen total 521728K, used 1600K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 519168K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000ffb00000) from space 2560K, 62% used [0x00000000ffb00000,0x00000000ffc90000,0x00000000ffd80000) to space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000) ParOldGen total 524288K, used 523786K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 99% used [0x00000000c0000000,0x00000000dff82a68,0x00000000e0000000) PSPermGen total 34304K, used 34213K [0x00000000bae00000, 0x00000000bcf80000, 0x00000000c0000000) object space 34304K, 99% used [0x00000000bae00000,0x00000000bcf695e8,0x00000000bcf80000) } {Heap before GC invocations=1458 (full 1): PSYoungGen total 521728K, used 1600K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 519168K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000ffb00000) from space 2560K, 62% used [0x00000000ffb00000,0x00000000ffc90000,0x00000000ffd80000) to space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000) ParOldGen total 524288K, used 523786K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 99% used [0x00000000c0000000,0x00000000dff82a68,0x00000000e0000000) PSPermGen total 34304K, used 34213K [0x00000000bae00000, 0x00000000bcf80000, 0x00000000c0000000) object space 34304K, 99% used [0x00000000bae00000,0x00000000bcf695e8,0x00000000bcf80000) 99997.837: [Full GC [PSYoungGen: 1600K->0K(521728K)] [ParOldGen: 523786K->17123K(524288K)] 525386K->17123K(1046016K) [PSPermGen: 34213K->33877K(68096K)], 0.1576350 secs] [Times: user=0.53 sys=0.03, real=0.16 secs] Heap after GC invocations=1458 (full 1): PSYoungGen total 521728K, used 0K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000) eden space 519168K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000ffb00000) from space 2560K, 0% used [0x00000000ffb00000,0x00000000ffb00000,0x00000000ffd80000) to space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000) ParOldGen total 524288K, used 17123K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000) object space 524288K, 3% used [0x00000000c0000000,0x00000000c10b8fc8,0x00000000e0000000) PSPermGen total 68096K, used 33877K [0x00000000bae00000, 0x00000000bf080000, 0x00000000c0000000) object space 68096K, 49% used [0x00000000bae00000,0x00000000bcf156f0,0x00000000bf080000) }
最佳答案
您的日志中唯一的 Full GC [说真的,在某个地方发布日志而不删除它是不是太难了?] 大约需要 160 毫秒,次要 GC 需要 30 毫秒或更少。
您没有设置任何暂停时间目标。
完整 GC 之间经过一个或多个小时。
如果您认为完整 GC 在某种程度上是“邪恶的”并且必须不惜一切代价避免,那您就错了。
它们在 CMS 中可能会很麻烦,因为在 CMS 中,Full GC 是一种故障模式单线程回退策略,在大型堆上可能需要很长时间。
但是你在小堆上使用并行老年代收集器,又名吞吐量收集器,其中完整 GC 非常快,尤其是当大部分老年代内容都是垃圾时必须通过mark-sweep算法访问。
考虑到您甚至没有指定暂停时间目标或尝试过 CMS,我认为您甚至没有明确定义的目标。
所以这里没有问题。
关于许多短期对象的 Java 垃圾收集行为,我们在Stack Overflow上找到一个类似的问题: https://stackoverflow.com/questions/31839515/