java - Java GC 日志行之间有什么区别？ ("Total time for which..."与 "[GC")

Question

Java 版本:1.6.0_20

我在我的日志中看到以下内容，我试图找出第一行和后续行之间的区别。据我所知，它们都与次要 GC 相关，但是它们之间并不像我读过的其他 GC 教程中通常那样一对一。我知道如何解释第一行，第二行也很明显，但这两个事件有什么区别？

30171.470: [GC 30171.470: [ParNew: 32704K->64K(32704K), 0.0055740 secs] 1575471K->1545444K(3145664K), 0.0056610 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]
Total time for which application threads were stopped: 0.0060020 seconds
Total time for which application threads were stopped: 0.0003300 seconds
Total time for which application threads were stopped: 0.0000740 seconds
Total time for which application threads were stopped: 0.0002630 seconds
Total time for which application threads were stopped: 0.0002640 seconds
Total time for which application threads were stopped: 0.0000760 seconds
... Snipped 35 similar lines ...
Total time for which application threads were stopped: 0.0006710 seconds
Total time for which application threads were stopped: 0.0000870 seconds
Total time for which application threads were stopped: 0.0002710 seconds
Total time for which application threads were stopped: 0.0000770 seconds
Total time for which application threads were stopped: 0.0002810 seconds
Total time for which application threads were stopped: 0.0002680 seconds
Total time for which application threads were stopped: 0.0000770 seconds
30289.137: [GC 30289.137: [ParNew: 32704K->63K(32704K), 0.0063990 secs] 1578084K->1548229K(3145664K), 0.0064890 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]

感谢您的帮助!

Answer 1

“...application threads..”消息由 PrintGCApplicationStoppedTime 控制。每当 JVM 到达 safepoint 的末尾时操作，它将检查是否应该打印应用程序在该操作期间停止了多长时间。

标志的名称有些误导，因为它与 GC 没有具体关系。例如，如果您还使用 PrintSafepointStatistics 标志运行，您可能会看到大多数 VM 操作都是 RevokeBias。与 GC 相关的操作将被命名为类似于 GenCollectForAllocation。