许多短期对象的 Java 垃圾收集行为

标签 java scala garbage-collection apache-kafka

我有一个 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 之前堆使用情况的说明: Heap Usage Transient State

这是稳态堆使用情况的说明:Heap Usage Steady State

如您所见,在第一次完整 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/

相关文章:

go - 对结构中字段的外部引用是否会阻止该结构被垃圾收集?

java - 如何选择 datetime mysql 类型作为 java.time.LocalDateTime?

scala - Intellij : Not a valid project ID:

javascript - 如何在 JavaScript 和 Scala 之间进行实时通信

angularjs - 如何在 Zeppelin 的 javascript 中将变量放入 z ZeppelinContext 中?

java - 什么触发了 Java 中的完整垃圾回收?

JavaFX 忽略自定义字体的粗细和样式

java - 为什么 getter 方法不返回任何对象的属性?

java - Android loadLibrary.so调用方法和构造函数

java - jmap中显示的 "From Space"和 "To Space"是什么意思?