频繁进行主要垃圾回收,但堆内存未释放?

9

运行几个小时后,我的HTTP服务器经常开始进行大量垃圾回收,但没有堆被释放。

几次主要的垃圾回收之后,出现了“晋升失败”和“并发模式失败”,然后堆被释放。我的垃圾回收日志如下:

{Heap before GC invocations=7172 (full 720):
 par new generation   total 737280K, used 667492K [0x000000076b800000, 0x000000079d800000, 0x000000079d800000)
  eden space 655360K, 100% used [0x000000076b800000, 0x0000000793800000, 0x0000000793800000)
  from space 81920K,  14% used [0x0000000793800000, 0x00000007943d91d0, 0x0000000798800000)
  to   space 81920K,   0% used [0x0000000798800000, 0x0000000798800000, 0x000000079d800000)
 concurrent mark-sweep generation total 1482752K, used 1479471K [0x000000079d800000, 0x00000007f8000000, 0x00000007f8000000)
 concurrent-mark-sweep perm gen total 131072K, used 58091K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
2015-11-19T21:50:02.692+0800: 113963.532: [GC2015-11-19T21:50:02.692+0800: 113963.532: [ParNew (promotion failed)
Desired survivor size 41943040 bytes, new threshold 15 (max 15)
- age   1:    3826144 bytes,    3826144 total
- age   2:     305696 bytes,    4131840 total
- age   3:     181416 bytes,    4313256 total
- age   4:     940632 bytes,    5253888 total
- age   5:      88368 bytes,    5342256 total
- age   6:     159840 bytes,    5502096 total
- age   7:     733856 bytes,    6235952 total
- age   8:      64712 bytes,    6300664 total
- age   9:     314304 bytes,    6614968 total
- age  10:     587160 bytes,    7202128 total
- age  11:      38728 bytes,    7240856 total
- age  12:     221160 bytes,    7462016 total
- age  13:     648376 bytes,    8110392 total
- age  14:      33296 bytes,    8143688 total
- age  15:     380768 bytes,    8524456 total
: 667492K->665908K(737280K), 0.7665810 secs]2015-11-19T21:50:03.459+0800: 113964.299: [CMS2015-11-19T21:50:05.161+0800: 113966.001: [CMS-concurrent-mark: 3.579/4.747 secs] [Times: user=13.41 sys=0.35, rea
l=4.75 secs] 
 (concurrent mode failure): 1479910K->44010K(1482752K), 4.7267420 secs] 2146964K->44010K(2220032K), [CMS Perm : 58091K->57795K(131072K)], 5.4939440 secs] [Times: user=9.07 sys=0.13, real=5.49 secs] 
Heap after GC invocations=7173 (full 721):
 par new generation   total 737280K, used 0K [0x000000076b800000, 0x000000079d800000, 0x000000079d800000)
  eden space 655360K,   0% used [0x000000076b800000, 0x000000076b800000, 0x0000000793800000)
  from space 81920K,   0% used [0x0000000798800000, 0x0000000798800000, 0x000000079d800000)
  to   space 81920K,   0% used [0x0000000793800000, 0x0000000793800000, 0x0000000798800000)
 concurrent mark-sweep generation total 1482752K, used 44010K [0x000000079d800000, 0x00000007f8000000, 0x00000007f8000000)
 concurrent-mark-sweep perm gen total 131072K, used 57795K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000)
}  

看起来CMS GC没有意义。你能解释一下吗?

这是我的gc配置:

/usr/local/jdk1.7.0_79/bin/java 
-server 
-Xms2248m 
-Xmx2248m 
-Xmn800m 
-XX:PermSize=128m 
-XX:MaxPermSize=128m 
-XX:MaxTenuringThreshold=15 
-XX:+UseCMSCompactAtFullCollection 
-XX:CMSFullGCsBeforeCompaction=0 
-XX:+UseConcMarkSweepGC 
-XX:+PrintGCDetails 
-XX:+PrintGCTimeStamps 
-XX:+PrintGCDateStamps 
-Xloggc:gc.log 
-XX:+PrintHeapAtGC 
-XX:+PrintTenuringDistribution 
-XX:+UseFastAccessorMethods

更新

服务器启动后会有一个定期任务,它的工作是从 MySQL 中加载数据并存储在 JVM 堆中。当客户端请求到达时,服务器应该使用这些数据进行计算。任务的代码如下:

private volatile List<ActivityInfo> activityInfos;

public void run () {
    activityInfos = db.loadActivity();
}

public ActivityInfo getActivityByClient() {
    //
    List<ActivityInfo> local = activityInfos; 
    // biz code
    ActivityInfo response = // biz code
    return response;
}

// executor 
executor.scheduleWithFixedDelay(task, 0, 1, TimeUnit.MINUTES);

我最困惑的是为什么堆在full gc之后被释放,而不是在major gc之后?

更新

这里是full gc日志

3个回答

4
为了解决这个问题,您可以使用Eclipse Memory Analyzer。它将详细显示所有这些与内存和线程相关的问题。 您也可以使用jConsole

Memory Analyzer 是一个非常好的工具,可以调查堆内容。但是据我所知,它没有检查 GC 日志或 GC 算法性能的功能。 - Neil Masson

4

这表明您的堆大小非常接近最大值,因此会频繁进行垃圾回收,但释放的内存很少。尝试将其显著增加,例如增加1.5倍或2倍。


我很困惑为什么在进行完全垃圾收集之后,堆才被释放,而不是在进行主要垃圾收集之后? - znlyj
因为全局垃圾回收器释放了主要垃圾回收器无法到达的某些内容? - user207421
主要收集后的堆使用量仅为44MB,因此堆已经非常宽裕,并且增加它将没有帮助。 - Neil Masson

3

您的幼儿园堆设置为800MB,使用-Xmn800m,但是在收集后,幼儿园堆的使用量仅为8MB。

- age 15: 380768 bytes, 8524456 total

因此,您的应用程序可以长时间运行,只需进行垃圾回收幼儿园堆。然而,在某个时候,老年堆将填满。到第7172次收集时,只剩下大约3MB - 即总堆和已使用堆值之间的差异。

concurrent mark-sweep generation total 1482752K, used 1479471K

垃圾收集器已注意到老年堆接近容量,并且在发布日志活动之前会触发并发标记。在并发标记阶段,继续分配对象,并填充幼儿园堆以触发幼儿园收集。

当收集幼儿园时,终身堆中已经没有足够的空间来容纳将要升级到终身堆的对象。这导致了“升级失败”,垃圾收集器被迫处理整个堆,而不仅仅是幼儿园。由于这发生在并发标记阶段完成之前,也记录了“并发模式失败”。完全收集后,终身堆中有1.4GB的数据。
"concurrent mark-sweep generation total 1482752K, used 44010K"
这就是事情应该发生的方式。如果大多数新对象很快超出作用域,则幼儿园收集是廉价的,并且JVM会愉快地只收集幼儿园尽可能长的时间。然而,最终终身堆会填满,并且需要更昂贵的完全GC。
如果您减少幼儿园的大小,例如减少到一半,会发生什么?假设您的应用程序以恒定速率创建对象,则幼儿园将在大约一半的时间内填满。由于应用程序使用的数据量与GC无关,因此与较大的幼儿园相同数量的对象将被保留和提升。因此,终身收集也将更快地填满。

然而,总堆大小相同的情况下,老年代区域比以前更大,因此需要更多的幼儿园收集来填充老年代区域,因此存在权衡。一个好的经验法则是将幼儿园大小设置为老年代区域大小的四分之一。

更新

完整的gc.log来自不同的GC运行,但我想应用程序的行为类似。其中我看到许多“CMS:由于时间原因中止预清理”的消息。这些在Jon Masamitsu's Weblog中有描述。出于效率的原因,CMS收集器依赖于在停止所有可执行线程之前进行幼儿园收集。如果在一定时间内未进行此类收集,则CMS收集将被中止。

当应用程序负载较低,但老年堆使用率较高时,CMS收集器将开始运行并通过其初始标记阶段。当幼儿园收集失败时,CMS收集将被中止。这可能会发生多次。然后发生幼儿园堆,循环重复。这将继续进行,直到CMS和幼儿园收集同时发生或老年堆完全填满。

由于对象只被缓慢地提升到终身堆,这种行为可能会持续一段时间。在此期间,浪费了时间执行初始标记,但操作却被中止,持续时间为2015-11-24T00:28:23.921至2015-11-24T01:55:52.461——长达一个半小时。有许多可能的方法来解决这个问题。
  • 减小幼儿园的大小。这将增加幼儿园收集的速度,使其更频繁地与CMS收集重叠。然而,大型幼儿园似乎运作良好,缩小它将导致更多的CMS收集,在重载下性能更差。
  • 增加CMSMaxAbortablePrecleanTime。这将意味着CMS在放弃收集之前等待更长的时间。然而,等待时间越长,CMS收集的代价就越高。
  • 打开CMSScavengeBeforeRemark。这是我的建议。这将在恰当的时候强制进行幼儿园收集,并且CMS收集将永远不会被中止。备注阶段的暂停时间将更长,因为幼儿园收集也将发生,但由于额外的时间很短,而全面收集如此罕见,所以这不太可能成为一个问题。
请注意,幼儿园堆有时被称为年轻代,而终身聘用堆则被称为老年代。欲了解更多信息,请参阅理解垃圾回收垃圾回收基础知识

也许我应该将“-Xmn”设置得更小一些?让我困惑的是,为什么堆在进行完全垃圾回收后被释放,而不是在进行主要垃圾回收后被释放? - znlyj
我已经通过更新我的答案来回答了第一个问题。至于第二个问题,我不知道“full”和“major” gcs之间有什么区别。是什么告诉你发生了major gcs? - Neil Masson
我可以通过GC日志判断是否发生了主要的垃圾回收。 - znlyj
我可以通过GC日志判断是否发生了主要的垃圾回收。 - znlyj
CMS-concurrent-mark 表示 major gc,而 concurrent mode failure 则意味着会发生 full gc,对吗? - znlyj
显示剩余4条评论

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接