当前位置: 代码迷 >> Web前端 >> 垃圾回收-native_stderr.log
  详细解决方案

垃圾回收-native_stderr.log

热度:896   发布时间:2012-09-01 09:33:03.0
垃圾回收--native_stderr.log

使用IBM的JDK的Windows平台AIX平台,我们只要在WebSphere管理控制台的java进程属性里勾选“详细垃圾回收”,那么就会在native_stderr.log中生成如下的信息。

image

这幅图很形象的给出了gc日志的主要关注点:垃圾回收的原因、垃圾回收的间隔、垃圾回收前后的剩余空间、垃圾回收持续的时间……

“nursery”表示这次分配失败(Allocation Failure)发生在新生代(nursery),是第44次(id=44)因为新生代的分配失败而进行垃圾回收了(开启GC日志以来),离上一次发生GC的间隔是12746ms,无法分配的空间大小是8216Byte,而进行垃圾回收前,新生代的可用空间为1776Byte,小于8216Byte,虽然年老区还剩余45%的空间,但是新的内存空间是无法直接在年老区分配的,由此引发了一次清理过程(scavenger)。

GC type表明了这次垃圾回收是一个清理过程,也是第44次scavenger过程,同时恰是第44个gc过程,说明没有发生过诸如<gc type=”global”>的垃圾回收过程。flipped objectcount说明将要把4523143个存活下来的对象被复制到了幸存区(survivor space),而73768个对象则经过多次幸存区的复制,有幸熬出头,被转移到了长存区(tenured space)。我们看到清理的倾斜比率(scavenger tiltratio)为89%,而不是对半开,说明经过多次复制清理,JVM已经意识到每次只有很少的对象能存活下来,于是它自动增大了年轻代中Eden区的大小,以使得为新对象可以腾出更多的内存。

接下来的就比较简单,经过垃圾回收,新生代的空间剩余89%,因为分配失败发生在新生代,进行的是快速的Minor gc,所以长存区的可用空间依然是45%,这次回收的时间为384.469ms。在长存区发生的是Major gc,回收时间一般要长于Minor gc,所以健康的JVM 环境Minor gc:Minor gc=1:10(也不用太在意)。

在垃圾回收准备开始的那一段时间(time exclusiveaccessms),以及回收的过程中,另一个线程发现内存无法分配了,于是也要求一次gc过程,这时候就产生了gc队列(会有<warning details=”exclusive access time includes previous garbage collections” />显示)。一般前一次垃圾回收就会释放出足够这两次分配需要的空间,于是第二次gc过程就终止了,当然要是无法足够分配的话,马上就会再进行一次垃圾回收。不过这种情况下,估计要进行Full GC了。

Full GC的gc type就是global,这是stop the world的最耗费时间的回收方式,所以需要通过尽量调整参数来避免。如果发现不是由AF引起的,而是在开头写着SYS标签,那么就要好好问问开发,有没有使用System.gc()的必要?可以的话使用-Xdisableexplicitgc来禁止。

以上所说的都是IBM JDK下垃圾回收日志的情况。