一次JVM引起的服务器load过高问题排查经历

2016-11-08早上9:25分，公司运维的同事给我报警，称我们团队的一台服务器CPU的压力很大，zabbix的图显示：

接到警报后，我在该服务器上使用w和top命令查看服务器的load和CPU情况，1分钟的load average在3-5之间，系统在高负荷运转，查看了我们的线上应用系统发现网页打开正常，但一个別列表的查询缓慢，chrome浏览器的network查看http接口的timing在十几秒。这部分列表走的是搜索引擎，我第一反应是会不会是搜索引擎出问题了？

于是我在服务器上查看tomcat日志，获取我们的应用调用搜索引擎的接口和参数，拼装后使用

1	curl -v '$url'

命令访问，发现访问的速度没有问题。那说明搜索引擎没有问题，那一定是我们的应用从搜索引擎返回值到展示给用户的部分处理有问题。

由于有大量用户反馈系统速度慢，于是我使用jps获取java进程的pid，随后使用：

1	jmap -dump:format=b,file=crm.bin [pid]

命令dump jvm的信息“保留犯罪现场”，然后重启线上应用。

启动应用后检测到服务器的load渐渐越来越高，最后保持在重启前的样子，于是使用

1	jstat -gc [pid] 3000

查看服务器每隔3秒的gc情况，发现3秒钟的full gc能够达到两次，jvm的状况十分异常。在启动服务器的这个时间里我利用eclipse MAT工具分析jmap dump文件信息，未诊断出异常。

后来我把原来jvm的Xms参数配置由1024m提高到3072m，发现双机的full gc次数分别稳定在0和2后再也没有full gc过了，但是young GC却十分频繁，3秒钟young GC次数可以达到15-20次。

到底是什么东西这么占内存？？？我使用jmap -histo pid查看，发现排在第一位的[C对象经常飙升到1个多G然后降到200MB，就是young GC频繁的原因，这通常是String类型的对象存在问题。

随后我使用

1	top -H -p [pid]

看到了如下结果：

这一排的PID都占用了大量的CPU资源，于是随机取了一个PID为1077的进程，使用

1	printf "%x\n" 1077

转换成16进制的数字为435

随后使用jstack工具：

1	jstack [pid] | less

输出当前的堆栈信息，然后搜索435，发现如下内容：

这块代码就是调用搜索引擎的代码，它处于RUNNABLE的状态，一直在执行中，说明这段代码一定是追魁祸首！打开代码看看！原来是这样的一段代码：

1 2 3

while ((line = in.readline()) != null) {     result += line; }

真相就是：循环里每次对String的操作都会生成新的String对象，不仅效率低下，而且大量浪费有限的内存空间。

将String改成StringBuilder，发布上线后load过高的问题解决。这就解释了为什么一般的页面打开速度正常，而搜索客户列表接口速度缓慢以及为什么char类型的数组占用大量内存。