一次堆内存溢出问题分析——虚拟机优化

发布日期:2019-10-21
打开开发环境服务器(我的服务器应用是单独部署的,几乎没有人访问),偶然间看到命令窗口报异常,java.lang.OutOfMemoryError:heap space,还包括一大堆的其他错误——后面发现其他错误都是内存溢出引起的用jconsole和jvisualvm尝试打开服务器,行不通——堆内存溢出,工具无法直连重启服务器,开启jsonsole和jvisualvm监控服务器我喜欢用jconsole查看应用占用的内存变化以及线程的变化,从上午11:00记录到现在已是7:40(晚上继续监控,我想复现内存溢出错误)变化情况:线程从90多个变成现在有600多个,差不多一分钟增加一个线程。而且绝大多数线程处于waiting、time-waited、runnable状态,最多的线程是名字包含nioEventLoopGroup、Thread的两组线程【线程堆栈信息】minor gc(也就是针对eden空间的gc)原来是差不多20秒执行一次,到现在已经是差不多10秒执行一次【高频】永久代到现在已经爆满,故当前的minor gc一次,就会发生full gc一次,这时候问题就比较严重了。原来要1个多小时执行一次full gc,现在只要10秒钟!注意:Copy上的gc,也就是minor gc,在老年代空间满了之后会停止执行; MarkSweepCompact上的gc,在开始每次执行耗时较长的,但是到了后面永久代满了后单次耗时很短(94次总耗时1分钟,到了147次总耗时还是1分钟,此处也可能是因为时间不精确,等到明天早上来看吧……196次的时候2分钟了)问题描述:这么看来,如果应用运行的时间越久,后期full gc就会越频繁,服务器就会越卡,更不用说大量用户访问了,这是很严重的问题!
第二天早上一看,jconsole已失去对应用的连接,堆栈上:老年代、survivor区、Enden空间均已爆满内存变化上看:堆内存使用量在凌晨1:37达到260M左右的峰值已用、已提交、最大值均为253,440 KB,GC时间中copy收集器上的gc仍然停留在2319次,耗时31.109秒,MarkSweepCompact收集器上发生了3974次,耗时53分钟线程数量则达到989的峰值,活动线程达到982,守护线程73个,启动线程总数25272个1:35:20的时候出现断崖cmd命令窗口Exception in thread "RMI TCP Connection(idle)" java.lang.OutOfMemoryError:Java heap space
通过jconsole的“线程”页左下角的线程列表,观察后续大量线程的堆栈信息,发现之前看到的两组线程都指向了一个依赖的jar包;找出该jar包在代码中的影响位置,发现只有三处(暂且记为A、B、C),且注销这些代码不影响应用启动,这就好办了先验证是不是此jar包引起,我把三处都注销了,运行应用,用jconsole监控十多分钟,发现线程不再增长,可以确定就是这个jar包在作祟了分别注销A、B、C三处代码,运行应用,然后通过jconsole监视变化,最终确定是C处代码导致的线程增长
验证堆内存的使用暴涨是否与线程增长有关注销C处代码,在开发环境主机和我本地机器上运行代码,使用jconsole连接进行监控一个晚上第二天早上惊喜地发现,老年代没有爆满,线程也只增加了个位数
jvm配置老年代爆满只是小惊喜,更大的惊喜是:同一个应用,在我本机上跑出来的结果和开发环境主机上跑出来的结果差异较大。
    垃圾收集器:因为我是Eclipse oxygen启动,使用的G1收集器,而开发环境主机用的默认垃圾收集器(开发环境主机JDK版本只比我本地JDK低一个小版本)垃圾收集活动:通过jconsole的"内存"页,我本机的minor GC只有短27次!Full GC只在启动的时候触发过3次!minor gc的频率在1个半小时到2个小时的样子执行1次,远不是20秒一次!但是开发环境主机上minor gc有1432次!而且因为应用在早上九点有一个任务调度而触发了一次full gc。堆内存变化:我本机上的堆内存变化在100M和600M之间的样子,survivor空间长期爆满,但是老年代的占用很低,eden空间变化也很慢(所以minor gc的频率很低);开发环境主机上,堆内存变化在60M~120M之间,多半稳定在100M左右,survivor空间占用较低,永久代空间占用25%(12个小时占用25%,可知应用大概运行2天会有一次full gc),eden空间变化也较慢,但是比我本机的明显要快