分析gc日志 [英] Analyzing gc logs

问题描述

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

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

但是发现只有在4 0r 5打印 PrintGCApplicationStoppedTime 后才能通过<$ c打印gc日志的实际细节$ c> -XX：+ PrintGCDetails 命令！

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线程记录。
Im使用Concurrent sweep获取完整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

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

My application is web application.

O / p Pattern-我是这样的：

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:

• 去优化


• 有偏见的锁定撤销


• 线程转储


• 堆检查


• 类重定义


• 等。 （请参阅列表）

• Deoptimization
• Biased lock revocation
• Thread dump
• Heap inspection
• Class redifinition
• etc. (see the list)

即使没有请求的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屋！