如何解释Java G1 GC暂停时间的原因

Question

当使用G1收集器时，我们一直在与似乎是长期停止的世界停顿作斗争。我已经通读了Oracle文档，但仍然难以确定如何解释导致长时间停顿的原因以及如何处理。（下面是GC日志）

我们的实例正在被监视，下面的图中包含了信息：

我们有另一个监视工具ping JVM，我让它报告JVM在同一时间内有12秒没有响应。

   wrapper.java.additional.40=-XX:+UseG1GC

   wrapper.java.additional.44=-XX:+ScavengeBeforeFullGC


   wrapper.java.additional.50=-XX:+PrintGCCause
   wrapper.java.additional.51=-XX:+PrintGCDetails
   wrapper.java.additional.52=-XX:+PrintGCTimeStamps
   wrapper.java.additional.53=-XX:+PrintGCApplicationStoppedTime
   wrapper.java.additional.54=-XX:+PrintGCApplicationConcurrentTime
   wrapper.java.additional.55=-verbose:gc
   wrapper.java.additional.56=-Xloggc:../../../logs/gc.log
   wrapper.java.additional.57-XX:+UseGCLogFileRotation
   wrapper.java.additional.58-XX:NumberOfGCLogFiles=10
   wrapper.java.additional.59-XX:GCLogFileSize=100M
   wrapper.java.additional.60=-XX:+PrintHeapAtGC
   wrapper.java.additional.61=-XX:+PrintTenuringDistribution
   wrapper.java.additional.62=-XX:+UseCompressedClassPointers
   wrapper.java.additional.63=-XX:+UseCompressedOops

更新：元空间图

Answer 1

我在GC日志中至少看到两个问题：

>

system.gc()或runtime.getruntme().gc()显式调用了4个完整集合。每一个大约10秒长：

277042.600: [Full GC (System.gc())  12G->1537M(5126M), 11.4203806 secs]

您可能需要添加-xx:+explicitGCInvokesConcurrentJVM标志，以防止System.gc()导致停止世界事件。

另一个问题是与GC无关的非常长的safepoint同步暂停：

5512447.686: Total time for which application threads were stopped: 16.4426008 seconds, Stopping threads took: 16.4414390 seconds

这通常是由MappedByteBuffer I/O或Java进程开始交换到磁盘引起的。关于类似的问题，请看这个和这个答案。