java web应用线上系统偶发宕机问题解决

前言：事情是酱紫的，系统上线两个月后，风平浪静。在一个秋天宁静的下午，老衲正喝着茶听着歌敲着代码，顺便欣赏下妹纸，独享这难得的惬意。突然手机响了，一看来电，心中一沉，项目经理来电，必有蹊跷。匆忙接起电话，没有问候，直奔主题，“赶紧看下系统，个别客户反馈系统不能用了，先恢复系统，再排查问题”。老衲撂下电话，一哆嗦，赶紧连上VPN，直奔服务器主机。

PS：三台服务器（centos、128G内存、32核CPU），tomcat1.7，jdk1.8，通过F5负载

解决步骤：

1、top命令查看CPU占用情况

可以看到11042进程占用了非常多的CPU资源

2、查看F5并发曲线：为什么应用耗费了这么多的线程，难道是用户量突然上来了，调取了F5的访问曲线图，可以看到在15:57左右并发量突然猛涨，当时根据曲线怀疑是请求量徒增导致

3、查看系统请求量：根据应用系统日志、以及localhost_access_log日志 查看此节点用户访问日志，发现使用人数并未徒增，根据请求量绘制的曲线如下：

可以看到曲线并未出现请求量徒增。

4、查看进程内线程运行情况：没有大量请求，为什么CPU会被使用这么多，难道是有线程的死锁，

   执行top -p 11042 -H 查看进程内所有线程的运行情况：

可以看到有很多线程正在执行

5、接着打内存快照执行命令打内存快照 在 jdk1.8.0_131/bin下面执行 ./jstack -l 11042>log01.txt，然后又隔了一分钟再次执行./jstack -l 11042>log02.txt，生产两个文件好对比里面的线程交集

打开日志，并未发现死锁的线程，但是在两个文件里面却发现大量的GC线程在执行如图：

6、分析GC回收情况，在jdk bin目录下执行 ./jstat -gcutil 11042 1000 100

看到了没有，虚拟机正在疯狂的进行full GC 回收，垃圾回收线程占用了非常多的CPU资源，问题已经有了明确的方向了，接下来需要分析到底是什么导致了full GC的频繁触发。

7、分析堆内存：

   打印堆内存 在jdk bin目录下执行 ./jmap -dump:live,format=b,file=problem.bin 11042 ，将日志文件下载到本地使用jprofiler分析，

发现有大量char[]，String ,map 占用，那么是什么业务代码造成了以上大量的数据呢，打开 char[]，String 没有找到与之关联的业务代码， 在map中发现大量的相同的业务对象，但是却无法直接发现出是什么操作造成了大量业务对象的存在，因为此业务对象代码中大量使用一一排除的话工作量极大。一时陷入困境，灵机一动，是不是还有别的内存快照分析工具，一查有个mat，在eclipse装好插件，打开内存快照：

点击leak suspects，如图

在个给出问题中一一查看，这时问题出现了如图：

BaseDatagridRest 的export导出数据方法，突然想到系统中有某个表数据的导出，立即登录系统查看此项导出功能，发现这个导出未对数据量做限制，而且BaseDatagridRest 的export方法实现是将数据库中的表数据抽取到内存中然后回写到excle中，让用户下载。我登录测试环境，用大数据量测试了下导出果然出现了同样的问题，至此问题水落石出，解决方案很简单，导出数据量加上限制，为了防止因为导出过慢时用户多次点击加上和遮罩。

总结：GC不只是用来面试的，更是来解决问题的。