分析gc日志
我正在使用-XX:+PrintGCApplicationStoppedTime
和-XX:+PrintGCApplicationConcurrentTime
选项来打开gc日志记录。
但是发现只有在4 0r 5 PrintGCApplicationStoppedTime
打印后PrintGCApplicationStoppedTime
通过-XX:+PrintGCDetails
命令打印gc日志的实际细节!
根据定义, PrintGCApplicationStoppedTime
为每个gc打印应用程序停止时间。
但我不清楚为什么它打印如下所示的例子。
是因为
PrintGCApplicationStoppedTime
只需在每个安全点到达后打印
(要么)
日志文件将由不同的gc线程记录。 我使用Concurrent扫描完整的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]
不幸的是, PrintGCApplicationStoppedTime
是这个JVM选项的误导性名称。
实际上,它打印了安全点内部所花费的时间。 安全点暂停不仅仅是由于垃圾收集,还有许多其他原因:
- 去优化
- 有偏见的锁撤销
- 线程转储
- 堆检查
- 类重定义
- 等(见清单)
即使没有请求的VM操作,安全点也可能定期发生,以便对空闲监视器进行放气,执行某些JIT清理等等。 请参阅-XX:GuaranteedSafepointInterval
VM选项(默认为1000毫秒)。
使用-XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1
以转储有关安全点的更多信息。