【问题标题】:Java Garbage Collection Log messagesJava 垃圾收集日志消息
【发布时间】:2010-10-28 01:59:32
【问题描述】:

我已将 java 配置为将垃圾收集信息转储到日志中 (verbose GC)。我不确定日志中的垃圾收集条目是什么意思。这些条目的示例发布在下面。我在Google 上进行了搜索,但没有找到可靠的解释。

我有一些合理的猜测,但我正在寻找能够严格定义条目中数字含义的答案,并得到可靠来源的支持。对引用 sun 文档的所有答案自动 +1。我的问题是:

  1. PSYoungGen 指的是什么?我认为这与上一代(年轻?)有关,但究竟是什么?
  2. 第二个三元组和第一个有什么区别?
  3. 为什么为第一个三元组指定了名称 (PSYoungGen) 而不是第二个?
  4. 三元组中的每个数字(内存大小)是什么意思。比如109884K->14201K(139904K),就是GC前的内存109884k,然后降到14201K。第三个数字有什么关系?为什么我们需要第二组数字?

8109.128: [GC [PSYoungGen: 109884K->14201K(139904K)] 691015K->595332K(1119040K), 0.0454530 秒]

8112.111: [GC [PSYoungGen: 126649K->15528K(142336K)] 707780K->605892K(1121472K), 0.0934560 秒]

8112.802: [GC [PSYoungGen: 130344K->3732K(118592K)] 720708K->607895K(1097728K), 0.0682690 秒]

【问题讨论】:

标签: java logging garbage-collection


【解决方案1】:
  1. PSYoungGen 指的是用于次要收集的垃圾收集器。 PS 代表 Parallel Scavenge。
  2. 第一组数字是年轻代的前后大小,第二组数字用于整个堆。 (Diagnosing a Garbage Collection problem 详细说明格式)
  3. 名称表示有问题的生成和收集器,第二组用于整个堆。

一个关联的完整 GC 示例还显示了用于旧代和永久代的收集器:

3.757: [Full GC [PSYoungGen: 2672K->0K(35584K)] 
            [ParOldGen: 3225K->5735K(43712K)] 5898K->5735K(79296K) 
            [PSPermGen: 13533K->13516K(27584K)], 0.0860402 secs]

最后,分解您的示例日志输出的一行:

8109.128: [GC [PSYoungGen: 109884K->14201K(139904K)] 691015K->595332K(1119040K), 0.0454530 secs]
  • 107Mb在GC之前使用,14Mb在GC之后使用,最大年轻代大小137Mb
  • 675Mb GC 之前使用的堆,581Mb GC 之后使用的堆,1Gb 最大堆大小
  • minor GC 自 JVM 启动后发生 8109.128 秒,耗时 0.04

【讨论】:

  • 只是一个小注释,'()'之间的值不是最大尺寸,永远是目前的最大尺寸。如果 GC 无法释放更少的堆,则此限制将需要更多空间用于操作系统,并且此值将增加。当然尊重定义的限制:-Xmx
  • @rafa.ferreira 我认为括号中的值,即 1119040K 是提交的堆大小。我不认为,GC 会在任何地方打印“最大堆”大小。 Reference 1Reference 2
【解决方案2】:

大部分内容都在GC Tuning Guide 中进行了解释(无论如何你都应该好好阅读)。

命令行选项-verbose:gc 导致在每次收集时打印有关堆和垃圾收集的信息。例如,这里是大型服务器应用程序的输出:

[GC 325407K->83000K(776768K), 0.2300771 secs]
[GC 325816K->83372K(776768K), 0.2454258 secs]
[Full GC 267628K->83769K(776768K), 1.8479984 secs]

在这里,我们看到两个次要集合,然后是一个主要集合。箭头前后的数字(例如,第一行的325407K->83000K)分别表示垃圾回收前后活动对象的组合大小。在次要收集之后,大小包括一些垃圾(不再存在)但无法回收的对象。这些对象要么包含在永久代中,要么从永久代或永久代中引用。

括号中的下一个数字(例如,(776768K) 再次从第一行开始)是堆的提交大小:Java 对象可用的空间量,而无需向操作系统请求更多内存。请注意,此数字不包括幸存者空间之一,因为在任何给定时间只能使用一个,也不包括永久代,其中包含虚拟机使用的元数据。

行中的最后一项(例如0.2300771 secs)表示执行收集所花费的时间;在这种情况下,大约是四分之一秒。

第三行主要集合的格式类似。

-verbose:gc 生成的输出格式在未来版本中可能会发生变化。

我不确定为什么你的里面有一个 PSYoungGen;你换了垃圾收集器吗?

【讨论】:

  • 在哪里可以找到 gc 日志文件?
  • 这个答案并没有真正解决最初的问题。我觉得迈克尔约瑟夫的回答更好。它解决了 Ethan 提出的问题,并且在分解原始示例方面做得更好。虽然他的回答中有两个问题(他的链接现在已经失效,而 rafa.ferreria 指出了另一个问题),但它不仅仅是反刍 Oracle 文档。
【解决方案3】:

我只是想提一下,可以通过

获取详细的 GC 日志
-XX:+PrintGCDetails 

参数。然后你会看到答案中的 PSYoungGen 或 PSPermGen 输出。

另外-Xloggc:gc.log 似乎会生成与-verbose:gc 相同的输出,但您可以在第一个指定输出文件。

示例用法:

java -Xloggc:./memory.log -XX:+PrintGCDetails Memory

为了更好地可视化数据,您可以尝试gcviewer(可以在github 上找到更新的版本)。

注意参数写正确,我忘记了“+”,我的JBoss无法启动,没有任何错误信息!

【讨论】:

  • 请注意,当 java 重新启动时 gc.log 将被覆盖(例如,如果您重新启动您的 tomcat,因为它存在内存问题,并且您希望看到 gc.log)。或者至少如果您轮换 GC 日志,它会。还有很多其他选项可以控制 gc 日志记录。见oracle.com/technetwork/articles/java/vmoptions-jsp-140102.html。特别是考虑-XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=<some number of files> -XX:GCLogFileSize=<some size> -XX:+PrintTenuringDistribution