工作日志-OOM事件

某项目,年前开始报OOM,频率保持在一月一次,发生OOM的时候,heap free size还有7~800M,比较奇怪,年后系统上集群,系统发生OOM的频率开始变得频繁,基本在4-5天,由于用的是sun jdk 1.4.2_08,无法获取到heap dump,建议用户升级到1.4.2_14(该版本以后sun添加了HeapDumpOnOutOfMemoryError参数,便于获取dump帮助诊断该类问题),4天之后,我们获取到了heapdump文件,通过对dump的分析,基本上排除了对象泄漏。

根据环境(64bit Solaris + 32bit JDK),客户把Heap最大设置为2G,开始怀疑32bit JDK无法分配这么大的Heap,经过验证,不存在这样的问题(sun网站也有相关说明,在solaris 64bit系统上,32bit jdk最大可以设置到4G)

但是从dump看到application classes loader大小已经到了60M以上,有点怀疑Perm区设置太小导致,查了一下sun的文档,Perm区缺省大小为64M,估计是应用加载太多classes导致Perm区溢出,

我们也简单模拟了一下Perm溢出,强制设置max perm大小为32M,并对GC进行了监控,结果和我们预想的一致,看下面的gc log:

151.836: [Full GC 151.836: [Tenured: 25735K->25736K(1048576K), 0.8380858 secs] 25911K->25736K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8382804 secs]
152.676: [Full GC 152.676: [Tenured: 25736K->25722K(1048576K), 0.8464782 secs] 25752K->25722K(1557568K), [Perm : 32767K->32766K(32768K)], 0.8466638 secs]
153.525: [Full GC 153.525: [Tenured: 25722K->25724K(1048576K), 0.8419056 secs] 25738K->25724K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8420986 secs]
154.368: [Full GC 154.368: [Tenured: 25724K->25724K(1048576K), 0.8398816 secs] 25724K->25724K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8400498 secs]
155.212: [Full GC 155.212: [Tenured: 25724K->25725K(1048576K), 0.8365448 secs] 25788K->25725K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8367370 secs]
156.050: [Full GC 156.050: [Tenured: 25725K->25722K(1048576K), 0.8422488 secs] 25725K->25722K(1557568K), [Perm : 32767K->32766K(32768K)], 0.8424328 secs]
156.895: [Full GC 156.895: [Tenured: 25722K->25724K(1048576K), 0.8443532 secs] 25738K->25724K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8445450 secs]
157.740: [Full GC 157.741: [Tenured: 25724K->25724K(1048576K), 0.8427754 secs] 25740K->25724K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8429634 secs]
158.587: [Full GC 158.588: [Tenured: 25724K->25726K(1048576K), 0.8352290 secs] 25820K->25726K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8354212 secs]
159.424: [Full GC 159.424: [Tenured: 25726K->25723K(1048576K), 0.8435336 secs] 25726K->25723K(1557568K), [Perm : 32767K->32766K(32768K)], 0.8437092 secs]
160.270: [Full GC 160.270: [Tenured: 25723K->25725K(1048576K), 0.8477722 secs] 25739K->25725K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8479596 secs]
161.119: [Full GC 161.119: [Tenured: 25725K->25725K(1048576K), 0.8543338 secs] 25725K->25725K(1557568K), [Perm : 32767K->32767K(32768K)], 0.8545040 secs

从日志看,和我们现场的状况非常相似,heap空间充足,但是perm已经到了32M,无法再进一步分配空间,直接导致jvm频繁做Full GC,控制台也开始抛出OOM(Perm引起的回收都是full gc),这样看基本我们判断是Perm太小,导致无法加载classes导致的

和客户沟通之后,我们本来打算进一步验证(在生产环节打开PrintGCDetail,获取详细的GC log),后面仔细检查nohup.out,发现里面已经抛出了 OutOfMemoryError:PermGen Space,至此我们确定是Perm设置不合理导致了本次事故,和客户确认之后,我们在启动参数中加上了MaxPermSize

后面想到中间上了集群之后,eos加载了大量的jboss cache class,这也直接解释了为什么这段时间OOM出现的频率比之前更频繁的原因

这里总结一下,希望对碰到类似问题的tx有借鉴意义,强烈建议用sun jdk 1.4.2的同学升级到>=1.4.2_12,便于对OOM问题的诊断,并加上GC log协助验证。

这里再介绍一下JVM发生OOM的几种情况:

1、java.lang.OutOfMemoryError: Java heap space

这是我们平常理解的OOM,是由于heap space确实没有空间分配,这种一般是由于内存泄漏导致,也有可能是heap space设置太小。需要具体分析

2、java.lang.OutOfMemoryError: PermGen space

jvm规范里面有定义一个method space,这里主要放classes和method list和一个string pool,string有一个intern方法,通过这个方法定义的string都放在这里(好像不常用),这里设置不太小会导致OOM,缺省64M,主要由于现在应用依赖的第三方类越来越多,导致这类问题频繁发生,需要引起重视

3、Requested array size exceeds VM limit
这种是由于申请的array size超出了heap space大小,比如在一个256M的heap space中申请一个512M的array,这种基本都是应用bug导致

4、request <size> bytes for <reason>. Out of swap space?
这种是由于heap size设置相对于系统物理内存太大,导致系统swap space不足,这种的解决办法就是减小heap size大小

5、<reason> <stack trace> (Native method)
这种估计是最麻烦的了,也是最少碰到的,是由于jni或native method导致,如果自己没有写这类的东西,基本可以说是jdk问题

posted on 2008-03-16 22:38 tacy lee 阅读(2579) 评论(2)  编辑  收藏 所属分类: 性能相关

评论

# re: 工作日志-OOM事件[未登录] 2008-03-17 09:33 roy

建议升级1.5以上,更高的性能  回复  更多评论   

# re: 工作日志-OOM事件 2008-03-17 09:41 tacy lee

同意,强烈建议升级到1.5+  回复  更多评论   


只有注册用户登录后才能发表评论。


网站导航: