分析gc日志

Question

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

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

根据定义 PrintGCApplicationStoppedTime 打印每次 gc 的应用程序停止时间。

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

是不是因为

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

(或)

日志文件将由不同的gc 线程记录。我对年轻一代使用完整 GC 和 ParNew 的并发扫描

我的应用程序是网络应用程序。

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 选项的误导性名称。

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

取消优化
偏向锁撤销
线程转储
堆检查
Class重新定义
等(see the list)

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

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

分析gc日志

Analyzing gc logs

java

garbage-collection

jvm

jvm-hotspot

verbosegc