遇到tomcat的假死问题,如何排查问题
问题场景
线上,有时候会遇到一种这样的情况:tomcat
没有奔溃退出,输出日志也没有异常,但是界面访问就一直卡着。假如遇到这种情况,没错,你遇到了tomcat
假死问题了。那么,该怎么排查这个问题呢?这个就是本文的重点了。
问题环境
软件 | 版本 |
---|---|
tomcat | 7.0 |
JDK | 1.6 |
Centos | 6 |
问题原因
tomcat假死的原因有多种,这里罗列博主遇到的几种情况:
HashMap死锁
内存泄露
CLOSE_WAIT过多
排查过程
遇到这种tomcat
假死的情况,先不着急重启应用,先排查一下。
以下是博主之前操作的过程:
查看tomcat的gc情况
使用以下命令拿到对应的gc
情况,命令如下:
jmap -heap pid >> jvm_memory.log
这个命令,主要是打印堆摘要,其中包括使用的GC
算法、堆配置和生成堆使用情况等。博主生成的文件当中,关于GC
部分如下:
using thread-local object allocation.
Parallel GC with 16 thread(s)
Heap Configuration:
MinHeapFreeRatio = 40
MaxHeapFreeRatio = 70
MaxHeapSize = 3221225472 (3072.0MB)
NewSize = 2686976 (2.5625MB)
MaxNewSize = -65536 (-0.0625MB)
OldSize = 5439488 (5.1875MB)
NewRatio = 2
SurvivorRatio = 8
PermSize = 134217728 (128.0MB)
MaxPermSize = 268435456 (256.0MB)
Heap Usage:
PS Young Generation
Eden Space:
capacity = 935133184 (891.8125MB)
used = 171217136 (163.28538513183594MB)
free = 763916048 (728.5271148681641MB)
18.309385115350587% used
From Space:
capacity = 68878336 (65.6875MB)
used = 41388552 (39.47119903564453MB)
free = 27489784 (26.21630096435547MB)
60.089361043797574% used
To Space:
capacity = 67174400 (64.0625MB)
used = 0 (0.0MB)
free = 67174400 (64.0625MB)
0.0% used
PS Old Generation
capacity = 2147483648 (2048.0MB)
used = 2142115640 (2042.8806686401367MB)
free = 5368008 (5.119331359863281MB)
99.75003264844418% used
PS Perm Generation
capacity = 161087488 (153.625MB)
used = 159574696 (152.18228912353516MB)
free = 1512792 (1.4427108764648438MB)
99.06088795673566% used
从输出结果,我们可以看到目前是在进行GC操作。
另外,我们也可以使用命令jstat
来查看,命令如下:
jstat -gcutil pid 250 7
说明:
pid:进程号
250:间隔时间,单位为毫秒
7:输出次数,这里指输出7次
因为当时排查的时候,没有使用这个命令。等问题解决了,才发现有这个命令,没办法复现当时的情况。
为了给大家讲解一下,就运行此命令,展示当前应用的情况:
S0 | S1 | E | O | P | YGC | YGCT | FGC | FGCT | GCT |
---|---|---|---|---|---|---|---|---|---|
0.00 | 0.00 | 82.15 | 84.94 | 99.84 | 50388 | 5413.400 | 2870 | 18355.985 | 23769.385 |
0.00 | 0.00 | 86.08 | 84.94 | 99.84 | 50388 | 5413.400 | 2870 | 18355.985 | 23769.385 |
0.00 | 0.00 | 90.86 | 84.94 | 99.84 | 50388 | 5413.400 | 2870 | 18355.985 | 23769.385 |
0.00 | 0.00 | 93.88 | 84.94 | 99.84 | 50388 | 5413.400 | 2870 | 18355.985 | 23769.385 |
0.00 | 0.00 | 97.54 | 84.94 | 99.84 | 50388 | 5413.400 | 2870 | 18355.985 | 23769.385 |
23.60 | 0.00 | 5.96 | 84.94 | 99.84 | 50389 | 5413.476 | 2870 | 18355.985 | 23769.461 |
23.60 | 0.00 | 21.19 | 84.94 | 99.84 | 50389 | 5413.476 | 2870 | 18355.985 | 23769.461 |
说明:下面是各个选项的含义
列 | 说明 |
---|---|
S0 | Heap上的 Survivor space 0 段已使用空间的百分比 |
S1 | Heap上的 Survivor space 1 段已使用空间的百分比 |
E | Heap上的 Eden space 段已使用空间的百分比 |
O | Heap上的 Old space 段已使用空间的百分比 |
P | Perm space 已使用空间的百分比 |
YGC | 从程序启动到采样时发生Young GC的次数 |
YGCT | Young GC所用的时间(单位秒) |
FGC | 从程序启动到采样时发生Full GC的次数 |
FGCT | 完整的垃圾收集时间(单位秒) |
GCT | 总垃圾收集时间(单位秒) |
排查内存泄露问题
一般应用运行了很久,突然才出现问题,可能是有几个原因:
外部原因的变化,如远程服务异常;
内部原因的变化,如升级代码存在问题等。
一般针对内存泄露,除了开发代码的时候,就进行规范之后,等运行之后,要查看该问题,特别是线上环境的话,最好将完整的JVM堆栈信息
给dump
下来。这个时候可以使用以下命令:
jmap -dump,format=b,file=heap-dump.bin <pid>
这个命令的作用为:将hprof
二进制格式的Java
堆转储到filename
。live
子选项是可选的。如果指定,则只转储堆中的活动对象。要浏览堆转储,可以使用jhat(Java堆分析工具)
读取生成的文件。
转换的文件比较大,一般有几个GB。所以要从现场环境拿下来,肯定得先进行压缩,然后再下载。这里我推荐使用JProfiler
来进行JVM分析。关于JProfiler
,请自行搜索使用。
使用JProfiler
打开head-dump.bin
文件,就可以看到一个很明显的东西,截图如下:
在上图可以知道,在Classes
页面,有一个类路径下面,生成了很多对象。我们点击Biggest Objects
,截图如下:
从上图可以知道,有一个对象非常大,占据了1487MB
。而从第一步拿到的堆栈信息,整个堆栈最大是3072.0MB
。所以,初步可以判断是因为这个东西,导致了频繁的GC
,进行导致tomcat
假死。
通过咨询项目运维成员,说该对象属于以前的插件-听云,属于端对端监控的插件。该插件之前要下线的,但是没有执行成功。所以该插件目前还运行着。而最近听云服务器正式下线,所以导致tomcat
连接听云出现问题。暂时锁定该问题,所以先安排运维人员移除该插件,并重启tomcat
。其中也遇到一个问题,并形成博客,有兴趣的小伙伴可以看看。
重启之后,目前运行将近一周了,还未发现tomcat假死
现象。所以,可以肯定,这个插件是造成近期应用假死的元凶。
这个原因是属于近期频繁假死的真凶,但是运维人员反映,该应用在之前是会出现这种tomcat假死
的情况的。只是频率不会像现在一天两次的情况,一般是数周会发生一次。所以,还是得继续排查。
HashMap死锁
在应用运行一段时间之后,使用阿里巴巴开源的arthas来进行问题排查。这个是排查Java
问题的利器。关于arthas
的使用,请自行登录官网查看。
登录机器,使用arthas
连接应用,查看当前的线程情况,发现有意思的一幕,截图如下:
有两个线程一直挂着,没有退出过。通过命令thread
查看该线程具体情况,截图如下:
如果曾经遇到过这个问题的话,应该可以知道,这个就是所谓的HashMap死锁
问题。这个需要去查看具体的代码,查看为什么会发生死锁的问题。
从这个可以得到,假如这个HashMap死锁
发生的频率不高,但是随着时间的推移,这种情况不断发生,就会将全部的连接给占据了,导致了tomcat
没可用连接进行响应,就会导致tomcat假死
的情况发生。这个就是为什么之前应用发生死锁的频率比较低,要数周才可能会发生一次。
CLOSE_WAIT过多情况
在实际场景,我们也会发现一种情况,tomcat假死
的时候,使用以下命令获取TCP
连接情况:
netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
结果如下(命令可能和截图不同,因为这个是进行筛选并定时执行得到的):
可以看到,目前存在很多的CLOSE_WAIT
。这个是因为服务端未及时释放资源。关于这个问题,除了可以修改Linux
配置,我们也可以直接修改tomcat
的配置文件,禁用wait
,让连接在返回后立马关闭,成为一个可用连接。新增选项:
<Connectorport=“11011” protocol=“org.apache.coyote.http11.Http11NioProtocol” connectionTimeout=“20000” maxThreads=“1000” URIEncoding=“UTF-8” keepAliveTimeout=“0” />
其中的keepAliveTimeout="0"
是解决这个问题的关键。这个参数在其中一个应用进行试验,原本经常有CLOSE_WAIT
,新增之后,基本没有,而且也没有报错。
总结
通过实际的现场场景,展示了整个排查的过程,中间涉及jmap
、jstack
、jstat
、arthas
、jprofiler
等命令及软件。熟练地使用这些命令,可以得到很多有用的信息,并加以解决。