如何让 G1 打印更多日志详细信息？

Question

我正在测试基于 Jetty 的 API 与基于 Netty 的对比。实验中唯一的区别是我使用的API（相同的应用程序、相同的服务器、相同的内存配置、相同的负载等），我使用基于 Netty 的垃圾回收暂停时间更长。大多数情况下，停顿都在一毫秒以下，但是在运行几天顺利之后，每隔 12-24 小时我就会看到 4-6 秒的停顿，而基于 Jetty 的 API 不会出现.

每当发生这种情况时，关于 G1 正在做什么导致它发出 STW 的信息都非常少，请注意此处的第二条暂停消息：

2016-02-23T05:22:27.709+0000: 66360.282: Total time for which application threads were stopped: 0.0319639 seconds, Stopping threads took: 0.0000716 seconds
2016-02-23T05:22:35.642+0000: 66368.215: Total time for which application threads were stopped: 6.9705594 seconds, Stopping threads took: 0.0000737 seconds
2016-02-23T05:22:35.673+0000: 66368.246: Total time for which application threads were stopped: 0.0048374 seconds, Stopping threads took: 0.0040574 seconds

我的 GC 选项是：

-XX:+UseG1GC 
-XX:+G1SummarizeConcMark 
-XX:+G1SummarizeRSetStats 
-XX:+PrintAdaptiveSizePolicy 
-XX:+PrintGC 
-XX:+PrintGCApplicationStoppedTime 
-XX:+PrintGCDateStamps 
-XX:+PrintGCDetails 
-XX:+PrintGCTimeStamps 
-XX:+DisableExplicitGC 
-XX:InitialHeapSize=12884901888 
-XX:MaxHeapSize=12884901888

而且，作为参考，我的 VM 选项是：

-XX:+AlwaysPreTouch 
-XX:+DebugNonSafepoints 
-XX:+FlightRecorder 
-XX:FlightRecorderOptions=stackdepth=500 
-XX:-OmitStackTraceInFastThrow 
-XX:+TrustFinalNonStaticFields 
-XX:+UnlockCommercialFeatures 
-XX:+UnlockDiagnosticVMOptions 
-XX:+UnlockExperimentalVMOptions 
-XX:+UseCompressedClassPointers 
-XX:+UseCompressedOops

我如何找出为什么 G1 在2016-02-23T05:22:35.642 停止世界？

Answer 1

并非所有 STW 暂停 - 用于触发它们的机制称为 safepoint - 都是由 GC 引起的，请使用 -XX:+PrintSafepointStatistics –XX:PrintSafepointStatisticsCount=1 打印其他安全点原因。

其次，如果暂停是由 GC 引起的，那么您粘贴的行本身不包含原因，但 GC 日志中的相邻块应该包含原因，一些东西喜欢 [GC pause (G1 Evacuation Pause) (young), 0.0200285 secs]

此外，您可能还想监控磁盘 IO 延迟并将时间戳与安全点暂停相匹配。在进入慢速存储的安全点期间发生的任何同步 IO 或分页都可能会使整个安全点停止。将日志文件和 /tmp 放在 tmpfs 或 SSD 上可能会有帮助。

Answer 2

为此添加一些结束语：问题是，从技术上讲，这不是 GC 暂停；这是几个因素的组合：

AWS 将 IO 限制为您已支付的费用
/tmp on Ubuntu 默认情况下结束于我们的（节流）EBS 卷
JVM 在 stop-the-world(!) 期间默认写入 /tmp

我们应用程序的其他部分达到了 EBS 限制阈值，当 JVM 尝试在 STW 期间写入 /tmp 时，JVM 上的所有线程都排在 AWS 限制点后面。

Netty/Jetty 差异似乎是一个转移注意力的问题。

我们需要我们的应用程序在这种环境中生存，因此我们的解决方案是禁用此 JVM 行为，代价是失去我们添加的几个 JVM 工具的支持：

-XX:+PerfDisableSharedMem

来自这个优秀博客 post 的关于此问题的更多信息：http://www.evanjones.ca/jvm-mmap-pause.html

如何让 G1 打印更多日志详细信息？

How do I get G1 to print more log details?

java

garbage-collection

g1gc