这篇文章分析了为什么Plumbr Agents在某些情况下以及如何延长GC暂停的时间。 对基本问题进行故障诊断揭示了有关在GC暂停期间如何处理JVMTI标记的有趣见解。

发现问题

我们的一位客户抱怨说，附加了Plumbr代理后，应用程序的响应速度明显降低。 通过分析GC日志，我们发现GC时间异常。 这是不带Plumbr的JVM摘录的GC日志：

2015-01-30T17:19:08.965-0200: 182.816: [Full GC (Ergonomics) 
[PSYoungGen: 524800K->0K(611840K)] 
[ParOldGen: 1102620K->1103028K(1398272K)] 1627420K->1103028K(2010112K), 
[Metaspace: 2797K->2797K(1056768K)], 0.9563188 secs] 
[Times: user=7.32 sys=0.01, real=0.96 secs]

这是附加了Plumbr代理的一个：

2015-02-02T17:40:35.872-0200: 333.166: [Full GC (Ergonomics) 
[PSYoungGen: 524800K->0K(611840K)] 
[ParOldGen: 1194734K->1197253K(1398272K)] 1719534K->1197253K(2010112K), 
[Metaspace: 17710K->17710K(1064960K)], 1.9900624 secs] 
[Times: user=7.94 sys=0.01, real=1.99 secs]

异常隐藏在经过的时间中。 实时时间是经过的实际时间。 如果您手里拿着秒表，那么实时将等于该数字。 用户时间 （加上系统时间）是测量过程中消耗的总CPU时间。 如果多个内核上有多个线程，则该时间可能大于实时时间。 因此，对于并行GC，实时时间应大致等于（用户时间/线程数）。 在我的机器上，该比率应该接近7，而没有Plumbr Agent的情况下确实是如此。 但是使用Plumbr时，该比率大大下降。 绝对不行！

初步调查

有了这样的证据，以下是最可能的假设：

1. Plumbr导致JVM在每个GC之后执行一些繁重的单线程操作
2. Plumbr导致JVM使用更少的线程进行垃圾回收

但是，仅查看GC日志中的一行，就无法进行更狭窄的观察，因此我们继续进行可视化上述比率：

图表上的下降恰好发生在Plumbr发现内存泄漏的那一刻。 在根本原因分析过程中，GC可能会给GC带来一些额外负担，但永久影响GC暂停时间绝对不是我们为代理特意设计的功能。 这种行为有利于第一个假设，因为我们不太可能在运行时影响GC线程的数量。

创建隔离的测试用例花费了一段时间，但是在以下约束的帮助下，我们可以钉上它：

1. 应用程序必须泄漏内存以供Plumbr检测
2. 应用程序必须经常暂停以进行垃圾收集
3. …以及作为突破时刻–应用程序必须具有较大的活动集，这意味着在Full GC中幸存的对象数量必须很大。

在编译了足够小的测试用例之后，可以放大根本原因检测范围。 合理的方法是打开和关闭Plumbr代理的各个功能，并查看问题将在哪种配置下重现。

通过这种简单的搜索，我们设法将问题定位到Plumbr Agent执行的单个操作。 关闭JVMTI标签后，问题消失了。 在分析gc根和引用链的路径时 ，我们标记堆上的每个对象。 显然，GC时间在某种程度上受我们生成的标签的影响。

寻找根本原因

不过，尚不清楚为什么GC暂停会延长。 垃圾会被Swift收集，并且大多数带标签的对象都应该符合GC的条件。 但是发现的是，存在大量活动集（这是内存泄漏的症状之一），其中保留了许多带标签的对象。

但是，即使对活动集中的所有对象都进行了标记，这也不应线性影响GC时间。 GC完成后，我们会收到有关所有已收集的标记对象的通知，但活动集不在这些对象之内。 这使人们想知道，HotSpot是否出于某种奇怪的原因在每个GC之后迭代所有标记的对象。

为了验证索赔，可以查看热点源代码。 经过一番挖掘之后，我们最终到达了JvmtiTagMap :: do_weak_oops ，它的确遍历了所有标签，并对所有标签进行了一些不太便宜的操作。 更糟的是，该操作是顺序执行的，并且不并行执行。 在找到每个垃圾回收之后调用此方法的调用链之后，解决了最后一个难题。 （为什么这样做的方式以及它与弱引用的关系完全超出了本文的范围）

在并行GC上运行并具有与串行运行相同的昂贵操作，一开始似乎是设计缺陷。 第二个想法，JVMTI的创建者可能从未期望有人标记所有的堆，因此从来没有费心去优化此操作或并行运行它。 毕竟，您永远无法预测人们将使用您设计的功能的所有方式，因此也许值得检查一下Hotspot中的GC后活动是否也应该有机会使用现代JVM倾向于使用的所有gazillion内核。可使用。

因此，为了解决这个问题，我们需要清理不再需要的标签。 修复它就像在我们的JVMTI回调之一中仅添加三行一样容易：

+  if(isGenerated(*tag_ptr)) {
+    *tag_ptr = 0;
+  }

而且瞧瞧，一旦分析完成，我们几乎和开始时一样出色。 如下面的屏幕快照所示，在发现内存泄漏期间仍然存在暂时的性能波动，并且在完成内存泄漏分析之后会略有恶化：

包起来

现在，补丁已推出，并且解决了Plumbr检测到泄漏后GC暂停时间受到影响的情况。 随意去获取更新的代理以解决性能问题。

作为一个总结，我建议您在使用广泛的标签时要格外小心，因为“便宜”的标签会堆积在角落的箱子上，从而为性能的大幅下降奠定了基石。 为确保您没有滥用标记，请翻转– XX：+ TraceJVMTIObjectTagging的诊断选项。 它将使您能够估计标签映射消耗多少本机内存以及堆遍历花费的时间。

翻译自: https://www.javacodegeeks.com/2015/02/jvmti-tagging-can-affect-gc-pauses.html