分析 gc 日志 [英] Analyzing gc logs

问题描述

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

I am using -XX:+PrintGCApplicationStoppedTime and -XX:+PrintGCApplicationConcurrentTime options to turn on gc logging.

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

But found that only after 4 0r 5 prints of PrintGCApplicationStoppedTime my actual details of gc logs printed through -XX:+PrintGCDetails command!

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

By definition PrintGCApplicationStoppedTime prints application stopped time for every gc.

但我不清楚为什么它会像下面显示的示例那样打印.

But I am not clear why it prints like the example shown below.

是因为

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

PrintGCApplicationStoppedTime just prints after every safe point reach

(或)

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

the log file will be logged by different gc threads. Im using Concurrent sweep for full GC and ParNew for the young generation

我的应用是网络应用.

O/p 模式——我是这样的:

O/p Pattern- Im getting like this:

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]

推荐答案

不幸的是，PrintGCApplicationStoppedTime 是这个 JVM 选项的误导性名称.

Unfortunately PrintGCApplicationStoppedTime is misleading name for this JVM option.

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

In fact it prints the time spent inside safepoints. Safepoint pauses occur not only due to Garbage Collection, but for many other reasons:

• 去优化
• 有偏锁撤销
• 线程转储
• 堆检查
• 类重定义
• 等等.(参见列表)

即使没有请求 VM 操作，安全点也可能会定期发生，以便为空闲监视器放气、执行某些 JIT 清理等.请参阅 -XX:GuaranteedSafepointInterval VM 选项(默认为 1000 毫秒).

Safepoints may happen periodically even without a requested VM operation in order to deflate idle monitors, perform certain JIT cleanup and so on. See -XX:GuaranteedSafepointInterval VM option (1000 milliseconds by default).

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

Use -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1 to dump more information about safepoints.

这篇关于分析 gc 日志的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！