UseConcMarkSweepGC 详细 gc 输出显示内存下降答案

【问题标题】：UseConcMarkSweepGC verbose gc output shows memory dropsUseConcMarkSweepGC 详细 gc 输出显示内存下降
【发布时间】：2012-11-18 03:38:30
【问题描述】：

我有一个启用了 GC 日志记录的应用程序。堆似乎在增长，然后突然下降，但没有记录 Full GC。如果有一些我可以启用的启动参数会告诉我什么 GC 事件正在减少堆大小？

我的环境： Linux 64 位、java 1.6.0_31、Java HotSpot(TM) 64 位服务器 VM（内部版本 20.6-b01，混合模式）

虚拟机参数： -server -Xms2560m -Xmx2560m -XX:+UseConcMarkSweepGC -XX:MaxPermSize=256m -XX:-PrintGC -XX: -PrintGCDetails -XX:-PrintGCTimeStamps -Xloggc:/xxxxx/gc.log -Dsun.rmi.dgc.client.gcInterval=86400000 -Dsun.rmi.dgc.server.gcInterval=86400000

3057.609: [GC 2397254K->2385777K(2619328K), 0.0572310 secs]
3058.898: [GC 2402801K->2391301K(2619328K), 0.0566620 secs]
3059.940: [GC 2408325K->2397156K(2619328K), 0.0534080 secs]
3059.995: [GC 2397265K(2619328K), 0.0069950 secs]
3065.635: [GC 2414180K->2404934K(2619328K), 0.0732700 secs]
3065.849: [GC 2419994K(2619328K), 0.1150630 secs]
3070.248: [GC 1593931K->1591825K(2619328K), 0.1084230 secs]
3072.440: [GC 1608552K->1606431K(2619328K), 0.0533140 secs]
3087.759: [GC 1623455K->1614544K(2619328K), 0.0215850 secs]

什么事件导致堆在 3065.849 和 3070.248 的输出之间收缩？是否有可以记录它的 VM 参数？我尝试添加 -verbose:gc 但这不会改变输出。

【问题讨论】：

你的 vm 参数告诉它关闭这些选项，你想打开它们，所以前缀是 + 而不是 - 即 -XX:+PrintGCTimeStamps 而不是 -XX:-PrintGCTimestamps。这就是为什么您没有得到任何关于正在发生的事情的更多详细信息的原因。
啊，谢谢，干杯，这能让我看到丢失的事件吗？
你肯定会得到更多信息，如果它不是自我解释的，你可以在这里发布。

标签： java garbage-collection

【解决方案1】：

GC 分两步进行

1) Minor 收集（主要清理年轻一代）

2) 主要收藏

我猜你看到的是次要收藏。这个tutorial 可以帮助您理解这些术语。

【讨论】：

【解决方案2】：

马克的评论有正确的答案，我没有正确启用详细信息。现在我看到了事件：

5505.399: [GC 5505.399: [DefNew: 17273K->1942K(19136K), 0.0172730 secs] 2408937K->2393606K(2619328K), 0.0175180 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
5524.922: [GC 5524.922: [DefNew: 18948K->2111K(19136K), 0.0268990 secs] 2410612K->2395349K(2619328K), 0.0271850 secs] [Times: user=0.02 sys=0.01, real=0.03 secs]
5524.950: [GC [1 CMS-initial-mark: 2393237K(2600192K)] 2395413K(2619328K), 0.0088880 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
5524.959: [CMS-concurrent-mark-start]
5527.608: [CMS-concurrent-mark: 2.645/2.650 secs] [Times: user=2.62 sys=0.00, real=2.65 secs]
5527.609: [CMS-concurrent-preclean-start]
5527.624: [CMS-concurrent-preclean: 0.015/0.015 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
5527.625: [GC[YG occupancy: 3557 K (19136 K)]5527.625: [Rescan (non-parallel) 5527.625: [grey object rescan, 0.0065690 secs]5527.632: [root rescan, 0.0088130 secs], 0.0154260 secs]5527.641: [weak refs processing, 0.1026480 secs] [1 CMS-remark: 2393237K(2600192K)] 2396795K(2619328K), 0.1252390 secs] [Times: user=0.13 sys=0.00, real=0.13 secs]
5527.954: [CMS-concurrent-sweep-start]
5531.258: [CMS-concurrent-sweep: 3.304/3.304 secs] [Times: user=3.15 sys=0.02, real=3.30 secs]
5531.258: [CMS-concurrent-reset-start]
5531.264: [CMS-concurrent-reset: 0.006/0.006 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]  
5551.660: [GC 5551.660: [DefNew: 19135K->1234K(19136K), 0.0691830 secs] 1373830K->1357833K(2619328K), 0.0694780 secs] [Times: user=0.07 sys=0.00, real=0.07 secs]
5584.991: [GC 5584.991: [DefNew: 18257K->2111K(19136K), 0.0264920 secs] 1374857K->1360277K(2619328K), 0.0267850 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
5589.794: [GC 5589.794: [DefNew: 19135K->286K(19136K), 0.0189210 secs] 1377301K->1359264K(2619328K), 0.0191450 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
5632.424: [GC 5632.424: [DefNew: 17310K->2111K(19136K), 0.0182480 secs] 1376288K->1361326K(2619328K), 0.0185900 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
5645.086: [GC 5645.087: [DefNew: 19135K->2112K(19136K), 0.0276910 secs] 1378350K->1363056K(2619328K), 0.0279740 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]

谢谢。

【讨论】：