一次tomcat自动关闭的bug解决
前言
最近一个运行了4年的javaee web项目,经常接到客户反馈系统无法打开。登录服务器查看服务,发现是tomcat自动关闭了。基本是3到4天发生一次。
运维人员开始以为是其他服务杀死了tomcat服务,没放在心上,解决方法就是直接重启tomcat。
最终捅了篓子,运维人员被客户投诉,扣了一个月的绩效。
解决这个bug兜兜转转来到了我这里。既然接到任务,那就开干,没有解决不了的bug。
系统的运行环境如下:
- tomcat6.0
- 32位jdk7.0
- window server2003 32位,32g内存。
查看日志,如果tomcat闪崩,都会在tomcat的bin目录下生成以"hs_err"开头的日志文件。打开最新的日志文件,首先看到的是下面一段话:
# there is insufficient memory for the java runtime environment to continue. # native memory allocation (malloc) failed to allocate 32756 bytes for chunkpool::allocate # possible reasons: # the system is out of physical ram or swap space # in 32 bit mode, the process size limit was hit # possible solutions: # reduce memory load on the system # increase physical memory or swap space # check if swap backing store is full # use 64 bit java on a 64 bit os # decrease java heap size (-xmx/-xms) # decrease number of java threads # decrease java thread stack sizes (-xss) # set larger code cache with -xx:reservedcodecachesize= # this output file may be truncated or incomplete. # # out of memory error (allocation.cpp:211), pid=7864, tid=6556 # # jre version: java(tm) se runtime environment (7.0_79-b15) (build 1.7.0_79-b15) # java vm: java hotspot(tm) server vm (24.79-b02 mixed mode windows-x86 ) # failed to write core dump.
大概意思就是内存不够了,无法分配32756字节的空间。同时给出几个解决方法:
1、减少系统内存负载;
2、增加物理内存或者交换空间;
3、在64位操作系统上使用64位jdk;
4、减少java heap大小;
5、减少java线程数量;
6、减少java线程堆栈大小。
通过上面的内容可以得出,jvm无法分配32756 bytes的内存空间。
从接到任务开始,我一直以为是jvm配置出错,导致内存不够用,只需调整下新生代、老年代的配置即可。
继续往下看日志文件,找到"gc heap history (10 events):"这一行,这个记录jvm最后10次垃圾回收时堆的变化情况。
gc heap history (10 events): event: 572312.299 gc heap before {heap before gc invocations=5046 (full 357): psyounggen total 201472k, used 200685k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 198144k, 100% used [0x573c0000,0x63540000,0x63540000) from space 3328k, 76% used [0x63540000,0x637bb528,0x63880000) to space 3328k, 0% used [0x63880000,0x63880000,0x63bc0000) paroldgen total 843776k, used 422602k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d872b18,0x573c0000) pspermgen total 262144k, used 51848k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e62138,0x13bc0000) event: 572312.305 gc heap after heap after gc invocations=5046 (full 357): psyounggen total 201472k, used 1103k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 198144k, 0% used [0x573c0000,0x573c0000,0x63540000) from space 3328k, 33% used [0x63880000,0x63993c90,0x63bc0000) to space 3328k, 0% used [0x63540000,0x63540000,0x63880000) paroldgen total 843776k, used 423618k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d970b18,0x573c0000) pspermgen total 262144k, used 51848k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e62138,0x13bc0000) } event: 572351.132 gc heap before {heap before gc invocations=5047 (full 357): psyounggen total 201472k, used 199247k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 198144k, 100% used [0x573c0000,0x63540000,0x63540000) from space 3328k, 33% used [0x63880000,0x63993c90,0x63bc0000) to space 3328k, 0% used [0x63540000,0x63540000,0x63880000) paroldgen total 843776k, used 423618k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d970b18,0x573c0000) pspermgen total 262144k, used 51848k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e62138,0x13bc0000) event: 572351.137 gc heap after heap after gc invocations=5047 (full 357): psyounggen total 201472k, used 1615k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 198144k, 0% used [0x573c0000,0x573c0000,0x63540000) from space 3328k, 48% used [0x63540000,0x636d3ec8,0x63880000) to space 3328k, 0% used [0x63880000,0x63880000,0x63bc0000) paroldgen total 843776k, used 423674k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d97eb18,0x573c0000) pspermgen total 262144k, used 51848k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e62138,0x13bc0000) } event: 572398.649 gc heap before {heap before gc invocations=5048 (full 357): psyounggen total 201472k, used 199759k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 198144k, 100% used [0x573c0000,0x63540000,0x63540000) from space 3328k, 48% used [0x63540000,0x636d3ec8,0x63880000) to space 3328k, 0% used [0x63880000,0x63880000,0x63bc0000) paroldgen total 843776k, used 423674k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d97eb18,0x573c0000) pspermgen total 262144k, used 51848k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e62138,0x13bc0000) event: 572398.655 gc heap after heap after gc invocations=5048 (full 357): psyounggen total 201472k, used 1998k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 198144k, 0% used [0x573c0000,0x573c0000,0x63540000) from space 3328k, 60% used [0x63880000,0x63a73830,0x63bc0000) to space 3328k, 0% used [0x63540000,0x63540000,0x63880000) paroldgen total 843776k, used 423703k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d985cc0,0x573c0000) pspermgen total 262144k, used 51848k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e62138,0x13bc0000) } event: 576881.689 gc heap before {heap before gc invocations=5049 (full 357): psyounggen total 201472k, used 200142k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 198144k, 100% used [0x573c0000,0x63540000,0x63540000) from space 3328k, 60% used [0x63880000,0x63a73830,0x63bc0000) to space 3328k, 0% used [0x63540000,0x63540000,0x63880000) paroldgen total 843776k, used 423703k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d985cc0,0x573c0000) pspermgen total 262144k, used 51850k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e62850,0x13bc0000) event: 576881.696 gc heap after heap after gc invocations=5049 (full 357): psyounggen total 201472k, used 3155k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 198144k, 0% used [0x573c0000,0x573c0000,0x63540000) from space 3328k, 94% used [0x63540000,0x63854cb0,0x63880000) to space 3328k, 0% used [0x63880000,0x63880000,0x63bc0000) paroldgen total 843776k, used 423703k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d985cc0,0x573c0000) pspermgen total 262144k, used 51850k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e62850,0x13bc0000) } event: 580535.452 gc heap before {heap before gc invocations=5050 (full 357): psyounggen total 201472k, used 201299k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 198144k, 100% used [0x573c0000,0x63540000,0x63540000) from space 3328k, 94% used [0x63540000,0x63854cb0,0x63880000) to space 3328k, 0% used [0x63880000,0x63880000,0x63bc0000) paroldgen total 843776k, used 423703k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d985cc0,0x573c0000) pspermgen total 262144k, used 51856k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e64228,0x13bc0000) event: 580535.459 gc heap after heap after gc invocations=5050 (full 357): psyounggen total 200960k, used 1858k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 197632k, 0% used [0x573c0000,0x573c0000,0x634c0000) from space 3328k, 55% used [0x63880000,0x63a50be0,0x63bc0000) to space 3584k, 0% used [0x634c0000,0x634c0000,0x63840000) paroldgen total 843776k, used 423703k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d985cc0,0x573c0000) pspermgen total 262144k, used 51856k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e64228,0x13bc0000) }
看了上面的内容,并没有发现tomcat闪崩是由于老年代,持久代,新生代空间不足引起的。有好几次因为eden区空间使用到100%引起的full gc,但是垃圾回收过后eden区的空间都恢复到正常的水平。
日志中还记录了tomcat闪崩时heap堆的使用情况:
heap psyounggen total 200960k, used 95671k [0x573c0000, 0x63bc0000, 0x63bc0000) eden space 197632k, 47% used [0x573c0000,0x5cf5d230,0x634c0000) from space 3328k, 55% used [0x63880000,0x63a50be0,0x63bc0000) to space 3584k, 0% used [0x634c0000,0x634c0000,0x63840000) paroldgen total 843776k, used 423703k [0x23bc0000, 0x573c0000, 0x573c0000) object space 843776k, 50% used [0x23bc0000,0x3d985cc0,0x573c0000) pspermgen total 262144k, used 51856k [0x03bc0000, 0x13bc0000, 0x23bc0000) object space 262144k, 19% used [0x03bc0000,0x06e64228,0x13bc0000)
一切都那么正常,同时又那么诡异。
翻看了之前发生日志,内容都是大同小异。
重新翻看了几遍日志,这次把重点放在日志中建议的解决方案上:
# reduce memory load on the system # increase physical memory or swap space # check if swap backing store is full # use 64 bit java on a 64 bit os # decrease java heap size (-xmx/-xms) # decrease number of java threads # decrease java thread stack sizes (-xss)
其中下面几个解决方案不采用:
- reduce memory load on the system。 系统内存够用,32g的内存,还剩20g没用,无需减少内存。
- increase physical memory or swap space。 系统内存够用,32g的内存,还剩20g没用,无需增加物理内存。
- use 64 bit java on a 64 bit os。 32位操作系统,无法使用64位jdk。
只剩下下面的三个解决方案了:
- decrease java heap size (-xmx/-xms)。 heap堆设置过大,就会影响剩余内存。
- decrease number of java threads
- decrease java thread stack sizes (-xss)
而减少java线程的数量,需要修改代码,这个也不实际。
最后只剩下
- decrease java heap size (-xmx/-xms)
- decrease java thread stack sizes (-xss)
这两个解决方案了,就从这里入手,曙光就在前方。
先看 decrease java thread stack sizes (-xss) 解决方案
java线程运行也是需要内存空间的,-xss参数指定每个线程堆栈的大小,为jvm启动的每个线程分配的内存大小。在jdk1.4版本中是256k,jdk1.5及以上版本是1m。
tomcat jvm的参数设置如下:
java_opts=%java_opts% -server -xms1024m -xmx1024m -xmn200m -xx:permsize=256m -xx:maxpermsize=512m -xx:survivorratio=1 -xss256k
已经通过-xss设置每个java线程堆栈的大小为256k。
在java语言里, 当你创建一个线程的时候,虚拟机会在jvm内存创建一个thread对象同时创建一个操作系统线程,而这个系统线程的内存用的不是jvmmemory,而是系统中剩下的内存(maxprocessmemory - jvmmemory - reservedosmemory)。
当需要创建线程,而操作系统剩余内存不够分配给一个java线程时,就会报out of memory error的错误。
由于已经设置通过-xss设置java线程栈的大小为256k,因此也决定不采用这个解决方案。
现在只剩 下decrease java heap size (-xmx/-xms) 这个解决方案了。通过减少堆的大小,而留出足够的内存空间给java线程堆栈使用。
32位的window操作系统给每个进程分配的内存空间是2g,减去堆的最大容量和permsize的最大容量,剩下的容量就留给java线程栈使用。
经过分析代码和之前错误的日志,发现一般在350个线程这样就出现out of memory error的错误。
在出现错误时,heap空间才用了不到40%。因此决定将java heap的从1g减少到768m。
修改的jvm参数如下:
java_opts=%java_opts% -server -xms768m -xmx768m -xmn200m -xx:permsize=256m -xx:maxpermsize=512m -xx:survivorratio=1 -xss256k
到目前为止,系统已经稳定运行1个月,各个参数指标都在正常范围内。heap使用率最高才70%。
总结:
1、经过这次解决bug,加深了对java虚拟机的了解,特别是线程栈,内存堆,持久代,新生代等概念。
2、一定要仔细阅读日志文件,一步一步排除掉潜在的解决方案。综合系统的运行环境,找出合理的解决方案。
好了,以上就是这篇文章的全部内容了,希望本文的内容对大家的学习或者工作具有一定的参考学习价值,谢谢大家对的支持。
推荐阅读
-
win10热点自动关闭怎么办 win10自带的移动热点经常自动关闭的解决方法
-
PE打开软件出错怎么办?如何解决自动关闭不能打开的情况
-
暴风影音在播放时突然自动关闭的解决办法
-
android支付宝客户端html5网页无法自动关闭问题的解决方法
-
解决android设备断电重启后WIFI不能自动重连的BUG(收藏)
-
Win7系统玩英雄联盟弹出PVP.net断开提示后自动关闭的解决方法图文教程
-
Win8系统硬盘会自动关闭怎么办?Win8系统电脑硬盘会自动关闭的解决方法图文教程
-
Vista系统中 IE 7.0 自动关闭的解决办法
-
win7系统无法自动关机提示正在等待后台程序关闭的解决方法图文教程
-
Win10系统下滚动鼠标时ANSYS会自动关闭的解决方法图文教程