分析gc日志

Question

我正在使用-XX:+PrintGCApplicationStoppedTime和-XX:+PrintGCApplicationConcurrentTime选项打开gc日志记录。

但是发现只有在4 0r
5后才PrintGCApplicationStoppedTime通过-XX:+PrintGCDetails命令打印我的gc日志的实际详细信息！

按照定义，PrintGCApplicationStoppedTime将为每个gc打印应用程序停止时间。

但是我不清楚为什么它会打印如下所示的示例。

是因为

PrintGCApplicationStoppedTime 只需在每个安全点到达后打印

（要么）

该日志文件将由其他gc线程记录。我正在使用并发扫描进行完整GC，并为年轻一代使用ParNew

我的应用程序是Web应用程序。

O / p模式-我变得像这样：

Application time: 0.3847031 seconds
Total time for which application threads were stopped: 0.3135419 seconds
Application time: 0.1520723 seconds
Total time for which application threads were stopped: 0.1993920 seconds
Application time: 0.1188219 seconds
Total time for which application threads were stopped: 0.1993920 seconds
Application time: 0.1188219 seconds
Total time for which application threads were stopped: 0.1993920 seconds
Application time: 0.1188219 seconds
Total time for which application threads were stopped: 0.1993920 seconds
Application time: 0.1188219 seconds
1.229: [GC 1.229: [ParNew: 256000K->51200K(256000K), 0.1509756 secs] 426536K->334728K(997376K), 0.1510198 secs] [Times: user=0.85 sys=0.07, real=0.15 secs]

Answer 1

不幸的PrintGCApplicationStoppedTime是，此JVM选项的名称具有误导性。

实际上，它会打印在安全点内花费的时间。安全点暂停的发生不仅是由于垃圾收集，还有其他许多原因：

• 反优化
• 偏向锁吊销
• 线程转储
• 堆检查
• 类重定义
• 等（请参见列表）

即使没有请求的VM操作以泄放空闲监视器，执行某些JIT清理等操作，安全点也可能定期发生。请参阅-XX:GuaranteedSafepointIntervalVM选项（默认为1000毫秒）。

使用-XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1转储有关safepoints的更多信息。